element-call icon indicating copy to clipboard operation
element-call copied to clipboard
Published 1 month ago • verified publisher icon element-hq

"Sorry, an error occurred" when joining a voip call via EXA

Open richvdh opened this issue 4 months ago • 2 comments

Steps to reproduce

1.Click on matrix.to link in room 2. Click "join call" 3. Wait a second or two. The call starts.

Outcome

What did you expect?

Able to join the call

What happened instead?

"Error

Sorry, an error occurred"

Operating system

Android

Browser information

No response

URL for webapp

No response

Will you send logs?

Yes

richvdh avatar Aug 28 '25 08:08 richvdh

@jmartinesp is that https://github.com/element-hq/element-call/issues/3450 for android ?

fkwp avatar Aug 28 '25 08:08 fkwp

I don't think so, this seems like an internal call in the room. In the logs I see:

2025-08-28T08:15:04.800163Z DEBUG elementx: [WebView] :2 Joined !GMwfWAtoctpRDuPIip:call.ems.host, waiting room to be ready for group calls | 
2025-08-28T08:15:04.927212Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx [638ms 200] | 
2025-08-28T08:15:04.933615Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.936335Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.937299Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.938133Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.939206Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.939968Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.940635Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.941360Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.942066Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.943258Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.944200Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.944879Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.945484Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.946098Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.946982Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.947569Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.948102Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.948677Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.949250Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.949820Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.950369Z ERROR elementx: [WebView] :2 [MatrixRTCSessionManager] Got room state event for unknown room !GMwfWAtoctpRDuPIip:call.ems.host! | 
2025-08-28T08:15:04.951038Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Call memberships in room !GMwfWAtoctpRDuPIip:call.ems.host, in order:  [[1756368636895,"@red-whole-anaconda:call.ems.host"],[1756368774965,"@gray-shared-salmon:call.ems.host"],[1756368831253,"@orange-tame-shark:call.ems.host"],[1756368895110,"@turquoise-thoughtless-orangutan:call.ems.host"]] | 
2025-08-28T08:15:04.951548Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Call memberships in room !GMwfWAtoctpRDuPIip:call.ems.host, in order:  [[1756368636895,"@red-whole-anaconda:call.ems.host"],[1756368774965,"@gray-shared-salmon:call.ems.host"],[1756368831253,"@orange-tame-shark:call.ems.host"],[1756368895110,"@turquoise-thoughtless-orangutan:call.ems.host"]] | 
2025-08-28T08:15:04.951969Z DEBUG elementx: [WebView] :2 !GMwfWAtoctpRDuPIip:call.ems.host, is ready for group calls | 
2025-08-28T08:15:04.953382Z DEBUG elementx: [WebView] :2 Fetched / joined room !GMwfWAtoctpRDuPIip:call.ems.host | 
2025-08-28T08:15:04.953903Z DEBUG elementx: [WebView] :2 TRACE matrix_sdk_crypto::store::caches: Flagging user for key query
    user="@turquoise-amateur-partridge:call.ems.host" sequence_number=0
    at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/matrix-sdk-crypto-0.13.0/src/store/caches.rs:224
    in matrix_sdk_crypto::machine::receive_sync_changes | 
2025-08-28T08:15:05.024660Z DEBUG elementx: [WebView] :2 [Lifecycle] GroupCallView Component mounted | 
2025-08-28T08:15:05.032483Z DEBUG elementx: [WebView] :2 [Lifecycle] GroupCallView Component mounted | 
2025-08-28T08:15:05.033967Z DEBUG elementx: [WebView] :2 Session in room !GMwfWAtoctpRDuPIip:call.ems.host changed to left | 
2025-08-28T08:15:05.189800Z DEBUG elementx: [WebView] :2 DEBUG matrix_sdk_crypto::identities::manager: Created a /keys/query request
    request_id="958169ae716f4d4a89723e4d05a75210" users=["@turquoise-amateur-partridge:call.ems.host"]
    at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/matrix-sdk-crypto-0.13.0/src/identities/manager.rs:877 | 
2025-08-28T08:15:05.190216Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx | 
2025-08-28T08:15:05.190923Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> POST https://call.ems.host/_matrix/client/v3/keys/query | 
2025-08-28T08:15:05.371650Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- POST https://call.ems.host/_matrix/client/v3/keys/query [239ms 200] | 
2025-08-28T08:15:05.372478Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx [240ms 200] | 
2025-08-28T08:15:05.374879Z DEBUG elementx: [WebView] :2 DEBUG matrix_sdk_crypto::identities::manager: Handling a `/keys/query` response
    request_id="958169ae716f4d4a89723e4d05a75210" users={"@turquoise-amateur-partridge:call.ems.host"} failures={}
    at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/matrix-sdk-crypto-0.13.0/src/identities/manager.rs:135 | 
2025-08-28T08:15:05.384115Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Call memberships in room !GMwfWAtoctpRDuPIip:call.ems.host, in order:  [[1756368636895,"@red-whole-anaconda:call.ems.host"],[1756368774965,"@gray-shared-salmon:call.ems.host"],[1756368831253,"@orange-tame-shark:call.ems.host"],[1756368895110,"@turquoise-thoughtless-orangutan:call.ems.host"]] | 
2025-08-28T08:15:05.413646Z DEBUG elementx: [WebView] :2 TRACE matrix_sdk_crypto::store::caches: User now up-to-date
    at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/matrix-sdk-crypto-0.13.0/src/store/caches.rs:289
    in matrix_sdk_crypto::store::caches::maybe_remove_user with user="@turquoise-amateur-partridge:call.ems.host" query_sequence=SequenceNumber(0) invalidation_sequence=0 | 
2025-08-28T08:15:05.415358Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx | 
2025-08-28T08:15:05.420146Z DEBUG elementx: [WebView] :2 DEBUG matrix_sdk_crypto::identities::manager: Finished handling of the `/keys/query` response
    request_id="958169ae716f4d4a89723e4d05a75210" new_devices={} changed_devices={} deleted_devices={} new_identities={} changed_identities={}
    at /home/runner/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/matrix-sdk-crypto-0.13.0/src/identities/manager.rs:1205 | 
2025-08-28T08:15:05.420813Z DEBUG elementx: [WebView] :2 [Perf]: Mark Request as sent 1 took 44ms | 
2025-08-28T08:15:05.421298Z DEBUG elementx: [WebView] :2 [Perf]: Make outgoing request 1 took 285ms | 
2025-08-28T08:15:06.195992Z  WARN elementx: [WebView] :2 silence detected on local audio track {"source":"microphone","muted":false,"enabled":true,"kind":"audio","streamID":"6d795432-fa16-412a-83ae-ec552e56c120","streamTrackID":"6d795432-fa16-412a-83ae-ec552e56c120"} | 
2025-08-28T08:15:06.196068Z DEBUG matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:228 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > send{request_id="REQ-82" method=POST uri="https://matrix.sw1v.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="154B" status=200 response_size="317B" request_duration=8.740863867s}
2025-08-28T08:15:06.196664Z DEBUG matrix_sdk::sliding_sync: Received response | crates/matrix-sdk/src/sliding_sync/mod.rs:579 | spans: next_sync_with_lock > sync_once{conn_id="encryption"}
2025-08-28T08:15:06.196862Z DEBUG matrix_sdk::sliding_sync: Start handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:595 | spans: next_sync_with_lock > sync_once{conn_id="encryption"}
2025-08-28T08:15:06.196948Z DEBUG matrix_sdk::sliding_sync: _acquiring the `sync_lock`_ finished in 1.328µs | crates/matrix-sdk/src/sliding_sync/mod.rs:267 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > handle_response
2025-08-28T08:15:06.216312Z DEBUG matrix_sdk::sliding_sync: _response processor_ finished in 19.353555ms | crates/matrix-sdk/src/sliding_sync/mod.rs:261 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > handle_response
2025-08-28T08:15:06.216518Z DEBUG matrix_sdk::sliding_sync: Sliding Sync response has been handled by the client | crates/matrix-sdk/src/sliding_sync/mod.rs:295 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > handle_response
2025-08-28T08:15:06.216560Z DEBUG matrix_sdk::sliding_sync: Update lists lists={} | crates/matrix-sdk/src/sliding_sync/mod.rs:329 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > handle_response
2025-08-28T08:15:06.216597Z DEBUG matrix_sdk::sliding_sync: Updating `pos` previous_pos="0/s2153518783_191063136_20993_27744892_671342_881_2200481_21084761_0_175" new_pos="0/s2153518783_191063136_20993_27744893_671342_881_2200481_21084761_0_175" | crates/matrix-sdk/src/sliding_sync/mod.rs:368 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > handle_response
2025-08-28T08:15:06.216775Z DEBUG matrix_sdk::event_cache: _Taking the `multiple_room_updates_lock`_ finished in 3.203µs | crates/matrix-sdk/src/event_cache/mod.rs:524 | spans: listen_task > handle_room_updates
2025-08-28T08:15:06.219015Z DEBUG matrix_sdk::sliding_sync: Done handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:612 | spans: next_sync_with_lock > sync_once{conn_id="encryption"}
2025-08-28T08:15:06.219201Z DEBUG matrix_sdk::sliding_sync: Sync stream is running | crates/matrix-sdk/src/sliding_sync/mod.rs:670 | spans: next_sync_with_lock
2025-08-28T08:15:06.219266Z DEBUG matrix_sdk::sliding_sync: Waiting to acquire the `position` lock | crates/matrix-sdk/src/sliding_sync/mod.rs:405 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > generate_sync_request
2025-08-28T08:15:06.219309Z DEBUG matrix_sdk::sliding_sync: _acquiring the `position` lock_ finished in 1.29µs | crates/matrix-sdk/src/sliding_sync/mod.rs:407 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > generate_sync_request
2025-08-28T08:15:06.219347Z DEBUG matrix_sdk::sliding_sync: Got a position pos=Some("0/s2153518783_191063136_20993_27744893_671342_881_2200481_21084761_0_175") | crates/matrix-sdk/src/sliding_sync/mod.rs:412 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > generate_sync_request
2025-08-28T08:15:06.225509Z DEBUG matrix_sdk::sliding_sync::cache: _loading sliding sync sliding_sync_store::encryption::@richvdh:sw1v.org state from DB_ finished in 6.100039ms | crates/matrix-sdk/src/sliding_sync/cache.rs:162 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > generate_sync_request
2025-08-28T08:15:06.225765Z DEBUG matrix_sdk::sliding_sync: Sending request | crates/matrix-sdk/src/sliding_sync/mod.rs:513 | spans: next_sync_with_lock > sync_once{conn_id="encryption"}
2025-08-28T08:15:06.225977Z DEBUG matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:78 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > send{request_id="REQ-84" method=POST uri="https://matrix.sw1v.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="154B"}
2025-08-28T08:15:06.227139Z DEBUG matrix_sdk_crypto::session_manager::sessions: Collected user/device pairs that are missing an Olm session missing_session_devices_by_user={} timed_out_devices_by_user={} | crates/matrix-sdk-crypto/src/session_manager/sessions.rs:287 | spans: next_sync_with_lock > sync_once{conn_id="encryption"} > send_outgoing_requests > get_missing_sessions
2025-08-28T08:15:06.243206Z DEBUG matrix_sdk::http_client: Got response | crates/matrix-sdk/src/http_client/mod.rs:228 | spans: sync_once{conn_id="room-list"} > send{request_id="REQ-83" method=POST uri="https://matrix.sw1v.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="14.4k" status=200 response_size="30.6k" request_duration=8.026781796s}
2025-08-28T08:15:06.244027Z DEBUG matrix_sdk::sliding_sync: Received response | crates/matrix-sdk/src/sliding_sync/mod.rs:579 | spans: sync_once{conn_id="room-list"}
2025-08-28T08:15:06.244204Z DEBUG matrix_sdk::sliding_sync: Start handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:595 | spans: sync_once{conn_id="room-list"}
2025-08-28T08:15:06.244276Z DEBUG matrix_sdk::sliding_sync: _acquiring the `sync_lock`_ finished in 3.204µs | crates/matrix-sdk/src/sliding_sync/mod.rs:267 | spans: sync_once{conn_id="room-list"} > handle_response
2025-08-28T08:15:06.262916Z DEBUG matrix_sdk::sliding_sync: _response processor_ finished in 18.637422ms | crates/matrix-sdk/src/sliding_sync/mod.rs:261 | spans: sync_once{conn_id="room-list"} > handle_response
2025-08-28T08:15:06.263097Z DEBUG matrix_sdk::sliding_sync: Sliding Sync response has been handled by the client | crates/matrix-sdk/src/sliding_sync/mod.rs:295 | spans: sync_once{conn_id="room-list"} > handle_response
2025-08-28T08:15:06.263128Z DEBUG matrix_sdk::sliding_sync: Update lists lists={"all_rooms": List { count: 916 }} | crates/matrix-sdk/src/sliding_sync/mod.rs:329 | spans: sync_once{conn_id="room-list"} > handle_response
2025-08-28T08:15:06.263179Z DEBUG matrix_sdk::sliding_sync: Updating `pos` previous_pos="276139/s2153518783_191063136_20993_27744892_671342_881_2200481_21084761_0_175" new_pos="276139/s2153518783_191063136_20993_27744893_671342_881_2200481_21084761_0_175" | crates/matrix-sdk/src/sliding_sync/mod.rs:368 | spans: sync_once{conn_id="room-list"} > handle_response
2025-08-28T08:15:06.263344Z DEBUG matrix_sdk::event_cache: _Taking the `multiple_room_updates_lock`_ finished in 1.445µs | crates/matrix-sdk/src/event_cache/mod.rs:524 | spans: listen_task > handle_room_updates
2025-08-28T08:15:06.263526Z DEBUG matrix_sdk_sqlite::event_cache_store: _connection_ finished in 93.282µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:202 | spans: listen_task > handle_room_updates > handle_joined_room_update{room_id=!MrjRpwxJTEOwtyNaBs:matrix.org} > try_take_leased_lock{lease_duration_ms=500 key="default" holder="main"} > write
2025-08-28T08:15:06.266756Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 3.313828ms | crates/matrix-sdk-sqlite/src/event_cache_store.rs:468 | spans: listen_task > handle_room_updates > handle_joined_room_update{room_id=!MrjRpwxJTEOwtyNaBs:matrix.org} > try_take_leased_lock{lease_duration_ms=500 key="default" holder="main"}
2025-08-28T08:15:06.266954Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 664ns | crates/matrix-sdk-sqlite/src/event_cache_store.rs:1142 | spans: listen_task > handle_room_updates > handle_joined_room_update{room_id=!MrjRpwxJTEOwtyNaBs:matrix.org} > filter_duplicated_events{linked_chunk_id=Room("!MrjRpwxJTEOwtyNaBs:matrix.org")}
2025-08-28T08:15:06.268753Z DEBUG matrix_sdk_sqlite::event_cache_store: _connection_ finished in 479.922µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:202 | spans: try_take_leased_lock{lease_duration_ms=0 key="default" holder="main"} > write
2025-08-28T08:15:06.273597Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 5.322813ms | crates/matrix-sdk-sqlite/src/event_cache_store.rs:468 | spans: try_take_leased_lock{lease_duration_ms=0 key="default" holder="main"}
2025-08-28T08:15:06.273953Z DEBUG matrix_sdk::sliding_sync: Done handling response | crates/matrix-sdk/src/sliding_sync/mod.rs:612 | spans: sync_once{conn_id="room-list"}
2025-08-28T08:15:06.274073Z DEBUG matrix_sdk::sliding_sync: Sync stream is running | crates/matrix-sdk/src/sliding_sync/mod.rs:670
2025-08-28T08:15:06.274170Z DEBUG matrix_sdk::sliding_sync: Waiting to acquire the `position` lock | crates/matrix-sdk/src/sliding_sync/mod.rs:405 | spans: sync_once{conn_id="room-list"} > generate_sync_request
2025-08-28T08:15:06.274201Z DEBUG matrix_sdk::sliding_sync: _acquiring the `position` lock_ finished in 1.523µs | crates/matrix-sdk/src/sliding_sync/mod.rs:407 | spans: sync_once{conn_id="room-list"} > generate_sync_request
2025-08-28T08:15:06.274218Z DEBUG matrix_sdk::sliding_sync: Got a position pos=Some("276139/s2153518783_191063136_20993_27744893_671342_881_2200481_21084761_0_175") | crates/matrix-sdk/src/sliding_sync/mod.rs:412 | spans: sync_once{conn_id="room-list"} > generate_sync_request
2025-08-28T08:15:06.274324Z DEBUG matrix_sdk::sliding_sync: Sending request | crates/matrix-sdk/src/sliding_sync/mod.rs:513 | spans: sync_once{conn_id="room-list"}
2025-08-28T08:15:06.274969Z DEBUG matrix_sdk::http_client::native: Sending request num_attempt=1 | crates/matrix-sdk/src/http_client/native.rs:78 | spans: sync_once{conn_id="room-list"} > send{request_id="REQ-85" method=POST uri="https://matrix.sw1v.org/_matrix/client/unstable/org.matrix.simplified_msc3575/sync" request_size="14.4k"}
2025-08-28T08:15:06.276002Z DEBUG elementx: SyncIndicator = Hide | 
2025-08-28T08:15:06.276357Z DEBUG elementx: RoomList state=Running | 
2025-08-28T08:15:06.288261Z DEBUG elementx: process 15 items | 
2025-08-28T08:15:06.303077Z DEBUG matrix_sdk_sqlite::event_cache_store: _connection_ finished in 587.5µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:202 | spans: try_take_leased_lock{lease_duration_ms=500 key="default" holder="main"} > write
2025-08-28T08:15:06.305094Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 2.610273ms | crates/matrix-sdk-sqlite/src/event_cache_store.rs:468 | spans: try_take_leased_lock{lease_duration_ms=500 key="default" holder="main"}
2025-08-28T08:15:06.305561Z DEBUG matrix_sdk_sqlite::event_cache_store: _connection_ finished in 265.664µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:202 | spans: get_media_content > write
2025-08-28T08:15:06.310666Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 5.38168ms | crates/matrix-sdk-sqlite/src/event_cache_store.rs:1346 | spans: get_media_content
2025-08-28T08:15:06.358155Z DEBUG matrix_sdk_sqlite::event_cache_store: _connection_ finished in 272.656µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:202 | spans: try_take_leased_lock{lease_duration_ms=500 key="default" holder="main"} > write
2025-08-28T08:15:06.359816Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 1.966329ms | crates/matrix-sdk-sqlite/src/event_cache_store.rs:468 | spans: try_take_leased_lock{lease_duration_ms=500 key="default" holder="main"}
2025-08-28T08:15:06.360061Z DEBUG matrix_sdk_sqlite::event_cache_store: _connection_ finished in 117.696µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:202 | spans: try_take_leased_lock{lease_duration_ms=0 key="default" holder="main"} > write
2025-08-28T08:15:06.360521Z DEBUG matrix_sdk_sqlite::event_cache_store: _method_ finished in 579.571µs | crates/matrix-sdk-sqlite/src/event_cache_store.rs:468 | spans: try_take_leased_lock{lease_duration_ms=0 key="default" holder="main"}
2025-08-28T08:15:07.130928Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx [1711ms 200] | 
2025-08-28T08:15:07.134112Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Call memberships in room !GMwfWAtoctpRDuPIip:call.ems.host, in order:  [[1756368636895,"@red-whole-anaconda:call.ems.host"],[1756368774965,"@gray-shared-salmon:call.ems.host"],[1756368831253,"@orange-tame-shark:call.ems.host"],[1756368895110,"@turquoise-thoughtless-orangutan:call.ems.host"]] | 
2025-08-28T08:15:07.167735Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx | 
2025-08-28T08:15:08.410771Z  WARN elementx: [WebView] :2 silence detected on local audio track {"source":"microphone","muted":false,"enabled":true,"kind":"audio","streamID":"9f4f7c3f-6a63-4b62-bce1-3fdb7bf45e05","streamTrackID":"9f4f7c3f-6a63-4b62-bce1-3fdb7bf45e05"} | 
2025-08-28T08:15:09.167990Z DEBUG elementx: [WebView] :2 Start building foci_preferred list:  !GMwfWAtoctpRDuPIip:call.ems.host | 
2025-08-28T08:15:09.168944Z DEBUG elementx: [WebView] :2 Adding livekit focus from oldest member:  {"livekit_alias":"!GMwfWAtoctpRDuPIip:call.ems.host","livekit_service_url":"https://jwt.call.element.io","type":"livekit"} | 
2025-08-28T08:15:09.211738Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx [2044ms 200] | 
2025-08-28T08:15:09.217412Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Call memberships in room !GMwfWAtoctpRDuPIip:call.ems.host, in order:  [[1756368636895,"@red-whole-anaconda:call.ems.host"],[1756368774965,"@gray-shared-salmon:call.ems.host"],[1756368831253,"@orange-tame-shark:call.ems.host"],[1756368895110,"@turquoise-thoughtless-orangutan:call.ems.host"],[1756368913742,"@maroon-hurt-herring:call.ems.host"]] | 
2025-08-28T08:15:09.217957Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Memberships for call in room !GMwfWAtoctpRDuPIip:call.ems.host have changed: emitting (5 members) | 
2025-08-28T08:15:09.218444Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] [Perf]: emit MatrixRTCSessionEvent.MembershipsChanged took 0ms | 
2025-08-28T08:15:09.235152Z DEBUG elementx: [WebView] :2 Adding livekit focus from well known:  {"livekit_service_url":"https://jwt.call.element.io","type":"livekit"} | 
2025-08-28T08:15:09.235517Z DEBUG elementx: [WebView] :2 Adding livekit focus from config:  {"type":"livekit","livekit_service_url":"https://livekit-jwt.call.element.io","livekit_alias":"!GMwfWAtoctpRDuPIip:call.ems.host"} | 
2025-08-28T08:15:09.235807Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> POST https://call.ems.host/_matrix/client/v3/user/%40turquoise-amateur-partridge%3Acall.ems.host/openid/request_token | 
2025-08-28T08:15:09.243182Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> GET https://call.ems.host/_matrix/client/v3/sync?filter=xxx&timeout=xxx&org.matrix.msc4222.use_state_after=xxx&since=xxx | 
2025-08-28T08:15:09.343202Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- POST https://call.ems.host/_matrix/client/v3/user/%40turquoise-amateur-partridge%3Acall.ems.host/openid/request_token [104ms 200] | 
2025-08-28T08:15:09.343741Z DEBUG elementx: [WebView] :2 Got openID token {"access_token":"zjJYJCfeBuaYXKjIOQsDhhNd","token_type":"Bearer","matrix_server_name":"call.ems.host","expires_in":3600} | 
2025-08-28T08:15:09.345206Z DEBUG elementx: [WebView] :2 Trying to get JWT from call's active focus URL of https://jwt.call.element.io... | 
2025-08-28T08:15:09.635581Z DEBUG elementx: [WebView] :2 Got JWT from call's active focus URL. | 
2025-08-28T08:15:09.637735Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Using experimental to-device transport for encryption keys | 
2025-08-28T08:15:09.638290Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host] Using to-device with room fallback transport for encryption keys | 
2025-08-28T08:15:09.644390Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][MembershipManager][NewMembershipActionScheduler] Current MembershipManager processing: SendDelayedEvent
Queue: [{"ts":1756368909643,"type":"SendDelayedEvent"}] 
Date.now: "1756368909643 | 
2025-08-28T08:15:09.645219Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][MembershipManager] MembershipManager applied action changes. Status: Disconnected -> Connecting | 
2025-08-28T08:15:09.645584Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][MembershipManager] MembershipManager before processing action. status=Connecting | 
2025-08-28T08:15:09.645882Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][EncryptionManager] Joining room | 
2025-08-28T08:15:09.646836Z DEBUG elementx: [WebView] :2 Got new active focus from membership: @red-whole-anaconda:call.ems.host/VHVOBJUBCX.
          Updated focus (focus switch) from undefined to {"livekit_alias":"!GMwfWAtoctpRDuPIip:call.ems.host","livekit_service_url":"https://jwt.call.element.io","type":"livekit"} | 
2025-08-28T08:15:09.647475Z DEBUG elementx: [WebView] :2 [LivekitRoom] Create LiveKit room | 
2025-08-28T08:15:09.647793Z DEBUG elementx: [WebView] :2 Created ExternalE2EEKeyProvider (shared key) | 
2025-08-28T08:15:09.651298Z DEBUG elementx: [WebView] :2 setting up e2ee | 
2025-08-28T08:15:09.651805Z DEBUG elementx: [WebView] :2 initializing worker {"worker":{}} | 
2025-08-28T08:15:09.655848Z DEBUG elementx: [WebView] :2 [Lifecycle] GroupCallView Component unmounted | 
2025-08-28T08:15:09.660279Z DEBUG elementx: [WebView] :2 [Lifecycle] InCallView Component mounted, livekit room state disconnected | 
2025-08-28T08:15:09.670364Z DEBUG elementx: [WebView] :2 Session in room !GMwfWAtoctpRDuPIip:call.ems.host changed to joined | 
2025-08-28T08:15:09.693415Z DEBUG elementx: [WebView] :2 [MatrixAudioRenderer] All audio tracks have a matching matrix call member identity. | 
2025-08-28T08:15:09.723528Z DEBUG elementx: [WebView] :2 [MatrixAudioRenderer] All audio tracks have a matching matrix call member identity. | 
2025-08-28T08:15:09.745699Z  WARN elementx: [WebView] :2 Could not set audio output: cannot switch audio output, the current browser does not support it {"room":"","participant":"","pID":""} | 
2025-08-28T08:15:09.748197Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> POST https://call.ems.host/_matrix/client/v3/user/%40turquoise-amateur-partridge%3Acall.ems.host/openid/request_token | 
2025-08-28T08:15:09.756395Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> PUT https://call.ems.host/_matrix/client/v3/rooms/!GMwfWAtoctpRDuPIip%3Acall.ems.host/state/org.matrix.msc3401.call.member/_%40turquoise-amateur-partridge%3Acall.ems.host_MUBPGOOTKX_m.call?org.matrix.msc4140.delay=xxx | 
2025-08-28T08:15:09.778080Z DEBUG elementx: [WebView] :2 [MatrixAudioRenderer] All audio tracks have a matching matrix call member identity. | 
2025-08-28T08:15:09.822819Z DEBUG elementx: [WebView] :2 [MatrixAudioRenderer] All audio tracks have a matching matrix call member identity. | 
2025-08-28T08:15:10.497576Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- POST https://call.ems.host/_matrix/client/v3/user/%40turquoise-amateur-partridge%3Acall.ems.host/openid/request_token [751ms 200] | 
2025-08-28T08:15:10.498125Z DEBUG elementx: [WebView] :2 FetchHttpApi: <-- PUT https://call.ems.host/_matrix/client/v3/rooms/!GMwfWAtoctpRDuPIip%3Acall.ems.host/state/org.matrix.msc3401.call.member/_%40turquoise-amateur-partridge%3Acall.ems.host_MUBPGOOTKX_m.call?org.matrix.msc4140.delay=xxx [740ms 200] | 
2025-08-28T08:15:10.508936Z DEBUG elementx: [WebView] https://call.element.io/assets/livekit-client.e2ee.worker-A85U9y1_.js:1 worker initialized | 
2025-08-28T08:15:10.514228Z DEBUG elementx: [WebView] https://call.element.io/assets/livekit-client.e2ee.worker-A85U9y1_.js:1 set shared key [object Object] | 
2025-08-28T08:15:10.515871Z DEBUG elementx: [WebView] :2 Got openID token {"access_token":"BlTCjSvRFrwxiCPkWNwhMPVj","token_type":"Bearer","matrix_server_name":"call.ems.host","expires_in":3600} | 
2025-08-28T08:15:10.516492Z DEBUG elementx: [WebView] :2 Trying to get JWT from call's active focus URL of https://jwt.call.element.io... | 
2025-08-28T08:15:10.523658Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][MembershipManager][NewMembershipActionScheduler] Current MembershipManager processing: SendJoinEvent
Queue: [{"ts":1756368910517,"type":"SendJoinEvent"}] 
Date.now: "1756368910517 | 
2025-08-28T08:15:10.525586Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][MembershipManager] MembershipManager applied action changes. Status: Connecting -> Connecting | 
2025-08-28T08:15:10.533206Z DEBUG elementx: [WebView] :2 [MatrixRTCSession !GMwfWAtoctpRDuPIip:call.ems.host][MembershipManager] MembershipManager before processing action. status=Connecting | 
2025-08-28T08:15:10.535030Z DEBUG elementx: [WebView] :2 FetchHttpApi: --> PUT https://call.ems.host/_matrix/client/v3/rooms/!GMwfWAtoctpRDuPIip%3Acall.ems.host/state/org.matrix.msc3401.call.member/_%40turquoise-amateur-partridge%3Acall.ems.host_MUBPGOOTKX_m.call | 
2025-08-28T08:15:10.589066Z  WARN elementx: The call took too long to be joined. Displaying an error before exiting. |

jmartinesp avatar Aug 28 '25 08:08 jmartinesp