search

mautrix / whatsapp

A Matrix-WhatsApp puppeting bridge
https://maunium.net/go/mautrix-whatsapp
GNU Affero General Public License v3.0
1.26k stars 172 forks source link

Timeout for creation of new rooms (should maybe be a synapse issue) 504 Gateway Time-out #608

Closed chagai95 closed 1 year ago

chagai95 commented 1 year ago

I'm getting a timeout when new rooms are being created, I think restarting synapse solves the issue, but it's still only happening for the WhatsApp bridge, maybe the bridge is no waiting long enough? I can't see anything suspicious in the synapse logs but I'm no expert...

bridge logs:

Apr 15 08:42:43 localhost.localdomain matrix-mautrix-whatsapp[303]: [Apr 15, 2023 06:42:43] [User/@344722243231krt:matrix.org/Client/Recv/DEBUG] <iq from="s.whatsapp.net" id="27.202-2506" t="1681540963" type="result"/>
Apr 15 08:42:49 localhost.localdomain matrix-mautrix-whatsapp[303]: [Apr 15, 2023 06:42:49] [Matrix/@whatsapp_595981836656:chagai.website/DEBUG] req #8129 (/v3/createRoom) completed in 1m0.010858766s with status 504 and 160 bytes of text/html body
Apr 15 08:42:49 localhost.localdomain matrix-mautrix-whatsapp[303]: [Apr 15, 2023 06:42:49] [Portal/595981836656@s.whatsapp.net-41766524456@s.whatsapp.net/ERROR] Failed to create portal room: failed to POST /_matrix/client/v3/createRoom: 504 Gateway Time-out
Apr 15 08:42:52 localhost.localdomain matrix-mautrix-whatsapp[303]: [Apr 15, 2023 06:42:52] [Matrix/@me:chagai.website/DEBUG] req #8174 (/v3/sync) completed in 30.008439948s with status 200 and 267 bytes of application/json body
Apr 15 08:42:52 localhost.localdomain matrix-mautrix-whatsapp[303]: [Apr 15, 2023 06:42:52] [Matrix/@me:chagai.website/DEBUG] req #8177: GET http://matrix-nginx-proxy:12080/_matrix/client/v3/sync?filter=1&set_presence=offline&since=s4265278_31960596_2034_2688923_553853_1126_109706_14535513_0_16&timeout=30000

Synapse logs:

Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,555 - synapse.access.http.8008 - 415 - DEBUG - POST-145164 - ::ffff:172.18.0.9 - 8008 - Received request: POST /_matrix/client/v3/createRoom?user_id=%40whatsapp_595981836656%3Achagai.website
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,556 - synapse.storage.txn - 692 - DEBUG - POST-145164 - [TXN START] {is_server_admin-13a1f8}
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,556 - synapse.storage.SQL - 416 - DEBUG - POST-145164 - [SQL] {is_server_admin-13a1f8} SELECT admin FROM users WHERE name = ?
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,556 - synapse.storage.SQL - 421 - DEBUG - POST-145164 - [SQL values] {is_server_admin-13a1f8} ['@whatsapp_595981836656:chagai.website']
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,557 - synapse.storage.SQL - 442 - DEBUG - POST-145164 - [SQL time] {is_server_admin-13a1f8} 0.000724 sec
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,557 - synapse.storage.txn - 796 - DEBUG - POST-145164 - [TXN END] {is_server_admin-13a1f8} 0.001294 sec
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,558 - synapse.util.metrics - 163 - DEBUG - POST-145164 - Entering block chagai_location.DemoModule.user_may_create_room
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,558 - synapse.util.metrics - 176 - DEBUG - POST-145164 - Exiting block chagai_location.DemoModule.user_may_create_room
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,559 - synapse.storage.txn - 692 - DEBUG - POST-145164 - [TXN START] {store_room-13a1f9}
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,559 - synapse.storage.SQL - 416 - DEBUG - POST-145164 - [SQL] {store_room-13a1f9} INSERT INTO rooms (room_id, creator, is_public, room_version, has_auth_chain_index) VALUES(?, ?, ?, ?, ?)
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,559 - synapse.storage.SQL - 421 - DEBUG - POST-145164 - [SQL values] {store_room-13a1f9} ('!GjwfMIalSKDlJklPLJ:chagai.website', '@whatsapp_595981836656:chagai.website', False, '9', True)
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,560 - synapse.storage.SQL - 442 - DEBUG - POST-145164 - [SQL time] {store_room-13a1f9} 0.000662 sec
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,562 - synapse.storage.txn - 796 - DEBUG - POST-145164 - [TXN END] {store_room-13a1f9} 0.003155 sec
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,562 - synapse.util.metrics - 163 - DEBUG - POST-145164 - Entering block create_new_client_event
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,563 - synapse.state - 216 - DEBUG - POST-145164 - calling resolve_state_groups from compute_state_after_events
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,563 - synapse.util.metrics - 163 - DEBUG - POST-145164 - Entering block resolve_state_groups_for_events
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,563 - synapse.state - 484 - DEBUG - POST-145164 - resolve_state_groups event_ids []
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,563 - synapse.util.metrics - 176 - DEBUG - POST-145164 - Exiting block resolve_state_groups_for_events
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,564 - synapse.crypto.event_signing - 155 - DEBUG - POST-145164 - Signing event: b'{"auth_events":[],"content":{"creator":"@whatsapp_595981836656:chagai.website"},"depth":1,"hashes":{"sha256":"2B+qE3aJRo0C+L17fDN/dUQyR51nSRrKBR1hp4jxmBA"},"origin":"chagai.website","origin_server_ts":1681540909564,"prev_events":[],"room_id":"!GjwfMIalSKDlJklPLJ:chagai.website","sender":"@whatsapp_595981836656:chagai.website","signatures":{},"state_key":"","type":"m.room.create"}'
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,564 - synapse.crypto.event_signing - 158 - DEBUG - POST-145164 - Signed event: b'{"auth_events":[],"content":{"creator":"@whatsapp_595981836656:chagai.website"},"depth":1,"hashes":{"sha256":"2B+qE3aJRo0C+L17fDN/dUQyR51nSRrKBR1hp4jxmBA"},"origin":"chagai.website","origin_server_ts":1681540909564,"prev_events":[],"room_id":"!GjwfMIalSKDlJklPLJ:chagai.website","sender":"@whatsapp_595981836656:chagai.website","signatures":{"chagai.website":{"ed25519:a_IdqS":"4MlMT6Y5lA3/GrYuV4HsozDvKm0QcWNBM+RoRMnVR6wkdO+K0/QFH6IqORRTSsBnYHC7jA7Uw+1Y9Sf71tZkAg"}},"state_key":"","type":"m.room.create"}'
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,564 - synapse.state - 337 - DEBUG - POST-145164 - calling resolve_state_groups from compute_event_context
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,565 - synapse.util.metrics - 163 - DEBUG - POST-145164 - Entering block resolve_state_groups_for_events
Apr 15 08:41:49 localhost.localdomain matrix-synapse[32144]: 2023-04-15 06:41:49,565 - synapse.state - 484 - DEBUG - POST-145164 - resolve_state_groups event_ids []
tulir commented 1 year ago

Gateway timeout means the gateway decided it took too long, not the bridge.