element-x-android icon indicating copy to clipboard operation
element-x-android copied to clipboard
verified publisher icon element-hq

Element Call ringing notification does not arrive in time or does not arrive at all

Open fkwp opened this issue 9 months ago • 9 comments

Steps to reproduce

  1. Another user is starting a call in a DM room with me
  2. All my other devices start ringing -- but the Android device is silent.
  3. (Sometimes those notifications arrive very late -- order of minutes late)

Outcome

What did you expect?

As soon as the other party starts the call I get a notification/ringing on my phone

What happened instead?

silence / nothing

Your phone model

No response

Operating system version

No response

Application version and app store

No response

Homeserver

No response

Will you send logs?

Yes

Are you willing to provide a PR?

Yes

fkwp avatar Mar 11 '25 08:03 fkwp

I have this too

Vitalii-code avatar Mar 28 '25 16:03 Vitalii-code

Looking at the logs it seems like the event could not be decrypted, re-decryption was tried several times but the app was never able to get the event behind the push notification so the ringing never started. May be related to https://github.com/element-hq/crypto-barge/issues/10 , but I can't confirm.

jmartinesp avatar Apr 01 '25 08:04 jmartinesp

I experience a similar behavior. The application displays in the chat that a call is incoming, but it does not ring. How could this problem be debugged to provide some useful logs?

shagall512 avatar Apr 04 '25 11:04 shagall512

I experience a similar behavior. The application displays in the chat that a call is incoming, but it does not ring. How could this problem be debugged to provide some useful logs?

note ringing is only available in DM chats (not group chats)

fkwp avatar Apr 04 '25 12:04 fkwp

@fkwp Yes. I'm calling in 1-1 chat, and also tried to go to user profile, and click the video button from there. The funny thing is that the call appears in the chat screen if I look at it, and I could actually join. But it doesn't ring!

shagall512 avatar Apr 06 '25 05:04 shagall512

I tracked down the issue to ntfy usage. Apparently, when on another device I have an option to use Firebase, the call rings. When I switch on that device to ntfy, the call stops ringing.

The weird thing is that the built-in troubleshooting with the ntfy enabled actually passes all tests.

I did further testing, and it appears that the ntfy.sh delivers sub-second latency consistently on all my devices. In general, the simulated round-trip delay for the Element is just 100-200 ms. Thus, I don't understand why am I not getting rings on Element X when ntfy.sh is being employed.

Could someone please suggest how to debug the matrix.org side of this process? I know I could monitor a channel with ntfy.sh, but I also would like to see if Element X is even trying to register the correct ntfy.sh URL with Matrix server matrix.org, and ideally I would like to see what matrix.org has actually registered.

shagall512 avatar Apr 06 '25 05:04 shagall512

About ringing calls not notifying while the device is locked, I found this after some testing with Firebase:

  • I started a call with EW.
  • The m.call.notify event was received by the locked device 2s later, still in the 10s threshold to notify with a ringing notification.
  • The client asks the SDK to give it the event for the notification.
  • 12s elapse, with the io.element.call.encryption_keys event somehow blocking the event fetching.
  • After all this time is elapsed, the m.call.notify event is finally processed, but > 10s have elapsed so it no longer rings.
### This is the m.call.encryption_keys event ###

12:01:56.044 org.matrix.rust.sdk     io.element.android.x.debug           W  elementx: [Push/VectorFirebaseMessagingService] New Firebase message. Priority: 1/1 | VectorFirebaseMessagingService.kt:41
12:01:58.569 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/PushHandler] ## handling pushData: !doHASiVaRpfQUfZYXq:matrix.org/$encryption-keys-event-id | DefaultPushHandler.kt:62

### This is the m.call.notify event ###

12:01:58.637 org.matrix.rust.sdk     io.element.android.x.debug           W  elementx: [Push/VectorFirebaseMessagingService] New Firebase message. Priority: 1/1 | VectorFirebaseMessagingService.kt:41
12:01:58.664 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/PushHandler] ## handling pushData: !doHASiVaRpfQUfZYXq:matrix.org/$call-notify-event-id | DefaultPushHandler.kt:62
12:01:59.579 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/PushHandler] ## handleInternal() | DefaultPushHandler.kt:92


### Here it tries to get the encryption_keys event from sliding sync ###

12:01:59.616 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync::cache: Successfully read the `SlidingSync` from the cache | crates/matrix-sdk/src/sliding_sync/cache.rs:225 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync
12:01:59.627 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync::cache: Successfully read the `Sliding Sync` pos from the crypto store cache | crates/matrix-sdk/src/sliding_sync/cache.rs:241 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync
12:01:59.628 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync::cache: loading sliding sync sliding_sync_store::notifications::@jorgem_test:matrix.org state from DB finished in 15ms | crates/matrix-sdk/src/sliding_sync/cache.rs:200 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync
12:01:59.629 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Starting sync stream | crates/matrix-sdk/src/sliding_sync/mod.rs:698 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_stream{conn_id="notifications" with_e2ee=false}
12:01:59.629 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Sync stream is running | crates/matrix-sdk/src/sliding_sync/mod.rs:704 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync
12:01:59.629 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Sending request | crates/matrix-sdk/src/sliding_sync/mod.rs:547 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:01:59.630 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::http_client: Serializing request request_type="ruma_client_api::sync::sync_events::v5::Request" | crates/matrix-sdk/src/http_client/mod.rs:109 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > send{request_id="REQ-39"}
12:01:59.631 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:78 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > send{request_id="REQ-39" method=POST uri="https://matrix-client.matrix.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="653B"}
12:01:59.665 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/PushHandler] ## handleInternal() | DefaultPushHandler.kt:92
12:02:01.210 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:214 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > send{request_id="REQ-39" method=POST uri="https://matrix-client.matrix.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="653B" status=200 response_size="31.1k"}
12:02:01.210 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Received response | crates/matrix-sdk/src/sliding_sync/mod.rs:613 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:01.210 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Start handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:629 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:01.210 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync: Must process rooms response? yes=true | crates/matrix-sdk/src/sliding_sync/mod.rs:275 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response
12:02:01.210 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk_base::sliding_sync: Processing sliding sync room events rooms=1 lists=1 has_extensions=true | crates/matrix-sdk-base/src/sliding_sync.rs:145 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:01.211 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::response_processors::account_data::global: Failed to deserialize a global account data event: data did not match any variant of untagged enum SecretStorageEncryptionAlgorithmDeHelper at line 1 column 2 event_type="m.secret_storage.key.BwwuYY9zBx7ooT5Re6ZdMxGEfnAfjBvA" | crates/matrix-sdk-base/src/response_processors/account_data/global.rs:54 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:01.211 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::response_processors::account_data::global: Failed to deserialize a global account data event: data did not match any variant of untagged enum SecretStorageEncryptionAlgorithmDeHelper at line 1 column 2 event_type="m.secret_storage.key.d7VgbNhQjsMfFRZDgS7DvCvDUzgNZnFK" | crates/matrix-sdk-base/src/response_processors/account_data/global.rs:54 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:01.212 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::response_processors::account_data::global: Failed to deserialize a global account data event: data did not match any variant of untagged enum SecretStorageEncryptionAlgorithmDeHelper at line 1 column 2 event_type="m.secret_storage.key.RncgX953p59VVq9ulSqA2h2qC8nvkgoK" | crates/matrix-sdk-base/src/response_processors/account_data/global.rs:54 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:01.249 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:01.249 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:01.250 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:01.250 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:01.290 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Sliding Sync response has been handled by the client sync_response=SyncResponse { rooms: RoomUpdates { leave: {}, join: {"!doHASiVaRpfQUfZYXq:matrix.org": JoinedRoomUpdate { unread_notifications: UnreadNotificationsCount { highlight_count: 0, notification_count: 0 }, timeline: Timeline { limited: true, prev_batch: ,,, | crates/matrix-sdk/src/sliding_sync/mod.rs:309 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response
12:02:01.290 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Update lists lists={"invites": List { count: 0 }} | crates/matrix-sdk/src/sliding_sync/mod.rs:373 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response
12:02:01.290 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync::cache: Saving a `SlidingSync` to the state store storage_key="sliding_sync_store::notifications::@jorgem_test:matrix.org" | crates/matrix-sdk/src/sliding_sync/cache.rs:83 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:01.298 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Done handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:646 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$encryption-keys-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }

### Suddenly, 12s have elapsed, maybe it's waiting until the next sync? ###

12:02:14.505 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync::cache: Successfully read the `SlidingSync` from the cache | crates/matrix-sdk/src/sliding_sync/cache.rs:225 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync
12:02:14.507 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync::cache: Successfully read the `Sliding Sync` pos from the crypto store cache | crates/matrix-sdk/src/sliding_sync/cache.rs:241 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync
12:02:14.507 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync::cache: loading sliding sync sliding_sync_store::notifications::@jorgem_test:matrix.org state from DB finished in 8ms | crates/matrix-sdk/src/sliding_sync/cache.rs:200 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync
12:02:14.507 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Starting sync stream | crates/matrix-sdk/src/sliding_sync/mod.rs:698 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_stream{conn_id="notifications" with_e2ee=false}
12:02:14.507 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Sync stream is running | crates/matrix-sdk/src/sliding_sync/mod.rs:704 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync
12:02:14.507 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Sending request | crates/matrix-sdk/src/sliding_sync/mod.rs:547 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:14.508 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::http_client: Serializing request request_type="ruma_client_api::sync::sync_events::v5::Request" | crates/matrix-sdk/src/http_client/mod.rs:109 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > send{request_id="REQ-40"}
12:02:14.508 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:78 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > send{request_id="REQ-40" method=POST uri="https://matrix-client.matrix.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="653B"}
12:02:14.542 org.matrix.rust.sdk     io.element.android.x.debug           V  elementx: Update rooms from postUpdates (with 1 items) on Thread[DefaultDispatcher-worker-7,5,main] | RoomSummaryListProcessor.kt:32
12:02:14.564 org.matrix.rust.sdk     io.element.android.x.debug           V  elementx: Update rooms from postUpdates (with 1 items) on Thread[DefaultDispatcher-worker-3,5,main] | RoomSummaryListProcessor.kt:32

### The encryption_keys event couldn't be found after all this time ###

12:02:14.578 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/Notification/DefaultNotifiableEventResolver] No notification data found for event $encryption-keys-event-id | DefaultNotifiableEventResolver.kt:94
12:02:14.623 org.matrix.rust.sdk     io.element.android.x.debug           W  elementx: [Push/PushHandler] Unable to get a notification data
                                                                             io.element.android.libraries.push.impl.notifications.ResolvingException: Unable to resolve event $encryption-keys-event-id
                                                                             	at io.element.android.libraries.push.impl.notifications.DefaultNotifiableEventResolver.resolveEvent-1_PhezE(DefaultNotifiableEventResolver.kt:95)
                                                                             	at io.element.android.libraries.push.impl.notifications.DefaultNotifiableEventResolver$resolveEvent$1.invokeSuspend(Unknown Source:15)
                                                                             	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
                                                                             	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:100)
                                                                             	at android.os.Handler.handleCallback(Handler.java:958)
                                                                             	at android.os.Handler.dispatchMessage(Handler.java:99)
                                                                             	at android.os.Looper.loopOnce(Looper.java:205)
                                                                             	at android.os.Looper.loop(Looper.java:294)
                                                                             	at android.app.ActivityThread.main(ActivityThread.java:8282)
                                                                             	at java.lang.reflect.Method.invoke(Native Method)
                                                                             	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:554)
                                                                             	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:885)
                                                                              | DefaultPushHandler.kt:159
12:02:14.678 org.matrix.rust.sdk     io.element.android.x.debug           V  elementx: Time to apply diff on new list of 40 items: 6 ms | DiffCacheUpdater.kt:58

### And then finally we start retrieving the notify event, but we're already 14s in the process and the timeout is 10s ###

12:02:15.080 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:214 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > send{request_id="REQ-40" method=POST uri="https://matrix-client.matrix.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="653B" status=200 response_size="31.0k"}
12:02:15.080 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Received response | crates/matrix-sdk/src/sliding_sync/mod.rs:613 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:15.080 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Start handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:629 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:15.080 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync: Must process rooms response? yes=true | crates/matrix-sdk/src/sliding_sync/mod.rs:275 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response
12:02:15.080 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk_base::sliding_sync: Processing sliding sync room events rooms=1 lists=1 has_extensions=true | crates/matrix-sdk-base/src/sliding_sync.rs:145 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:15.081 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::response_processors::account_data::global: Failed to deserialize a global account data event: data did not match any variant of untagged enum SecretStorageEncryptionAlgorithmDeHelper at line 1 column 2 event_type="m.secret_storage.key.BwwuYY9zBx7ooT5Re6ZdMxGEfnAfjBvA" | crates/matrix-sdk-base/src/response_processors/account_data/global.rs:54 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:15.081 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::response_processors::account_data::global: Failed to deserialize a global account data event: data did not match any variant of untagged enum SecretStorageEncryptionAlgorithmDeHelper at line 1 column 2 event_type="m.secret_storage.key.d7VgbNhQjsMfFRZDgS7DvCvDUzgNZnFK" | crates/matrix-sdk-base/src/response_processors/account_data/global.rs:54 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:15.081 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::response_processors::account_data::global: Failed to deserialize a global account data event: data did not match any variant of untagged enum SecretStorageEncryptionAlgorithmDeHelper at line 1 column 2 event_type="m.secret_storage.key.RncgX953p59VVq9ulSqA2h2qC8nvkgoK" | crates/matrix-sdk-base/src/response_processors/account_data/global.rs:54 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync
12:02:15.170 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:15.171 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:15.171 org.matrix.rust.sdk     io.element.android.x.debug           W  matrix_sdk_base::read_receipts: unhandled timeline event type: io.element.call.encryption_keys | crates/matrix-sdk-base/src/read_receipts.rs:611 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response > process_sliding_sync > compute_unread_counts{room_id=!doHASiVaRpfQUfZYXq:matrix.org}
12:02:15.182 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Sliding Sync response has been handled by the client sync_response=SyncResponse { rooms: RoomUpdates { leave: {}, join: ... | crates/matrix-sdk/src/sliding_sync/mod.rs:309 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response
12:02:15.183 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Update lists lists={"invites": List { count: 0 }} | crates/matrix-sdk/src/sliding_sync/mod.rs:373 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" } > handle_response
12:02:15.183 org.matrix.rust.sdk     io.element.android.x.debug           V  matrix_sdk::sliding_sync::cache: Saving a `SlidingSync` to the state store storage_key="sliding_sync_store::notifications::@jorgem_test:matrix.org" | crates/matrix-sdk/src/sliding_sync/cache.rs:83 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:15.204 org.matrix.rust.sdk     io.element.android.x.debug           D  matrix_sdk::sliding_sync: Done handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:646 | spans: get_notification{room_id="!doHASiVaRpfQUfZYXq:matrix.org" event_id="$call-notify-event-id"} > try_sliding_sync > sync_once{conn_id="notifications" }
12:02:15.262 org.matrix.rust.sdk     io.element.android.x.debug           V  elementx: Update rooms from postUpdates (with 1 items) on Thread[DefaultDispatcher-worker-2,5,main] | RoomSummaryListProcessor.kt:32
12:02:15.264 org.matrix.rust.sdk     io.element.android.x.debug           V  elementx: Update rooms from postUpdates (with 1 items) on Thread[DefaultDispatcher-worker-7,5,main] | RoomSummaryListProcessor.kt:32

### We got the notify event, but it's way too late now ###

12:02:15.333 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/Notification/DefaultNotifiableEventResolver] Found notification item for $call-notify-event-id | DefaultNotifiableEventResolver.kt:97
12:02:15.353 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: Event $call-notify-event-id is call but should not ring: 1745229716882 vs 1745229735334, notify: RING | CallNotificationEventResolver.kt:73
12:02:15.391 org.matrix.rust.sdk     io.element.android.x.debug           D  elementx: [Push/PushHandler] Notifiable event $call-notify-event-id is normal event: NotifiableMessageEvent(sessionId=@jorgem_test:matrix.org, roomId=!doHASiVaRpfQUfZYXq:matrix.org, eventId=$call-notify-event-id, editedEventId=null, canBeReplaced=false, senderId=@jorgem_test2:matrix.org, noisy=true, timestamp=1745229716882, senderDisambiguatedDisplayName=Jorge Test the II, body=📹 Incoming call, imageUriString=null, imageMimeType=null, threadId=null, roomName=Jorge Test the II, roomIsDm=true, roomAvatarPath=mxc://matrix.org/JTRRklvqVlagLjPAEeeqxGwF, senderAvatarPath=mxc://matrix.org/JTRRklvqVlagLjPAEeeqxGwF, soundName=null, outGoingMessage=false, outGoingMessageFailed=false, isRedacted=false, isUpdated=false, type=m.call.notify, hasMentionOrReply=false) | DefaultPushHandler.kt:142

So I think we need to solve this in the SDK somehow.

jmartinesp avatar Apr 21 '25 11:04 jmartinesp

Note that EXI seems to be impacted by this latency too. If you /discardsession before making a call or sending a simple text message, the notifcation on the other will be significantly delayed by 10-15s.

manuroe avatar Apr 22 '25 12:04 manuroe

i have finally gotten around to deploying my own matrixRTC stack, and immediately tested calling my wife only to experience this issue on her phone 😢 waiting several minutes and no notification ever arrived, but if the app is open, you can see that the call has been started in the DM room.

notifications work perfectly fine on my device, which is using schildiNext and a self-hosted ntfy server for unified push. her phone uses regular element x android from the google play store, and default firebase notifications.

i see similar issues in the "push notification history" section of her app, indicating that the app was unable to retrieve the event which the notification is referencing. i see many other failed push events in the history as well, but i haven't dug into those.

williamkray avatar May 03 '25 00:05 williamkray

@jmartinesp https://github.com/element-hq/element-x-android/issues/4720 might be related?

fkwp avatar May 15 '25 06:05 fkwp

We have the same issue with my family, when trying to call eacother nothing happens, no ringing, no notification

xKeiro avatar Jun 15 '25 14:06 xKeiro

@xKeiro @williamkray @shagall512 @Vitalii-code this issue should be fixed with https://github.com/element-hq/element-x-android/releases/tag/v25.08.2

Can you confirm?

fkwp avatar Aug 21 '25 13:08 fkwp

@xKeiro @williamkray @shagall512 @Vitalii-code this issue should be fixed with https://github.com/element-hq/element-x-android/releases/tag/v25.08.2

Can you confirm?

I just tried it today (checked the version number), on my fathers phone it rang,got the notification, but on my tablet still no ringing, no notification. Both using the latest playstore release.

xKeiro avatar Aug 23 '25 10:08 xKeiro

I just tried it today (checked the version number), on my fathers phone it rang,got the notification, but on my tablet still no ringing, no notification. Both using the latest playstore release.

Do you have any unverified sessions on your account? This would make the call notification to silently fail at the moment, you can check that on Element Web -> Settings -> Sessions. If not, could you please upload a rageshake? Thank you.

jmartinesp avatar Aug 25 '25 09:08 jmartinesp