User reports that "key storage out of sync" flow does not accept a known-good recovery key

[richvdh]

Reporter says:

Everytime I open an app I see a nag screen asking me to enter recovery key, because "key storage out of sync". Then I enter the key and the app says its incorrect. The problem is that the key is 100% correct and I even tested it one more time to make sure, in the classic Element app.

Initially I suspected that this would be #4343; however, I worked with the reporter to check their account data, and it all looks fine.

The client-side logs aren't terribly helpful; they look like this:

2025-02-20T19:57:09.346026Z DEBUG matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:55 | spans: recover > send{server_versions=[V1_0, V1_1, V1_2, V1_3, V1_4, V1_5, V1_6, V1_7, V1_8, V1_9, V1_10, V1_11] config=RequestConfig { timeout: 30s } request_id="REQ-29" method=GET uri="https://matrix.<redacted>/_matrix/client/v3/user/<redacted>/account_data/m.secret_storage.default_key"}
2025-02-20T19:57:09.490794Z DEBUG matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:221 | spans: recover > send{server_versions=[V1_0, V1_1, V1_2, V1_3, V1_4, V1_5, V1_6, V1_7, V1_8, V1_9, V1_10, V1_11] config=RequestConfig { timeout: 30s } request_id="REQ-29" method=GET uri="https://matrix.<redacted>/_matrix/client/v3/user/<redacted>/account_data/m.secret_storage.default_key" status=200 response_size="46 B"}
2025-02-20T19:57:09.490928Z DEBUG matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:55 | spans: recover > send{server_versions=[V1_0, V1_1, V1_2, V1_3, V1_4, V1_5, V1_6, V1_7, V1_8, V1_9, V1_10, V1_11] config=RequestConfig { timeout: 30s } request_id="REQ-30" method=GET uri="https://matrix.<redacted>/_matrix/client/v3/user/<redacted>/account_data/m.secret_storage.key.9c8e366f-ccae-46a3-bb66-5d6d219b52ec"}
2025-02-20T19:57:09.610697Z DEBUG matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:221 | spans: recover > send{server_versions=[V1_0, V1_1, V1_2, V1_3, V1_4, V1_5, V1_6, V1_7, V1_8, V1_9, V1_10, V1_11] config=RequestConfig { timeout: 30s } request_id="REQ-30" method=GET uri="https://matrix.<redacted>/_matrix/client/v3/user/<redacted>/account_data/m.secret_storage.key.9c8e366f-ccae-46a3-bb66-5d6d219b52ec" status=200 response_size="149 B"}
2025-02-20T19:57:09.929603Z  INFO matrix_sdk::encryption::secret_storage::secret_store: Fetching the private cross-signing keys from the secret store | crates/matrix-sdk/src/encryption/secret_storage/secret_store.rs:373 | spans: recover > import_secrets{self=SecretStore { key: SecretStorageKey { storage_key_info: SecretStorageKeyEventContent { key_id: "9c8e366f-ccae-46a3-bb66-5d6d219b52ec", name: None, algorithm: V1AesHmacSha2(SecretStorageV1AesHmacSha2Properties { iv: None, mac: None }), passphrase: Some(PassPhrase { algorithm: "m.pbkdf2", salt: "d82da8d8-5250-42a7-8ef4-37a44aa9", iterations: 500000, bits: 256 }) }, .. }, .. } user_id=<redacted> device_id=WODFZNUXZL}
2025-02-20T19:57:09.929683Z DEBUG matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:55 | spans: recover > import_secrets{self=SecretStore { key: SecretStorageKey { storage_key_info: SecretStorageKeyEventContent { key_id: "9c8e366f-ccae-46a3-bb66-5d6d219b52ec", name: None, algorithm: V1AesHmacSha2(SecretStorageV1AesHmacSha2Properties { iv: None, mac: None }), passphrase: Some(PassPhrase { algorithm: "m.pbkdf2", salt: "d82da8d8-5250-42a7-8ef4-37a44aa9", iterations: 500000, bits: 256 }) }, .. }, .. } user_id=<redacted> device_id=WODFZNUXZL} > send{server_versions=[V1_0, V1_1, V1_2, V1_3, V1_4, V1_5, V1_6, V1_7, V1_8, V1_9, V1_10, V1_11] config=RequestConfig { timeout: 30s } request_id="REQ-31" method=GET uri="https://matrix.<redacted>/_matrix/client/v3/user/<redacted>/account_data/m.cross_signing.master"}
2025-02-20T19:57:10.060803Z DEBUG matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:221 | spans: recover > import_secrets{self=SecretStore { key: SecretStorageKey { storage_key_info: SecretStorageKeyEventContent { key_id: "9c8e366f-ccae-46a3-bb66-5d6d219b52ec", name: None, algorithm: V1AesHmacSha2(SecretStorageV1AesHmacSha2Properties { iv: None, mac: None }), passphrase: Some(PassPhrase { algorithm: "m.pbkdf2", salt: "d82da8d8-5250-42a7-8ef4-37a44aa9", iterations: 500000, bits: 256 }) }, .. }, .. } user_id=<redacted> device_id=WODFZNUXZL} > send{server_versions=[V1_0, V1_1, V1_2, V1_3, V1_4, V1_5, V1_6, V1_7, V1_8, V1_9, V1_10, V1_11] config=RequestConfig { timeout: 30s } request_id="REQ-31" method=GET uri="https://matrix.<redacted>/_matrix/client/v3/user/<redacted>/account_data/m.cross_signing.master" status=200 response_size="212 B"}

... and that's it. It fetches the encrypted master key from the server, and then gives up.

I think we should improve the logging to diagnose what is going on here.

[richvdh]

Reporter has now fixed the problem by resetting their cross-signing identity from Element Web.