This repository has been archived by the owner on Apr 26, 2024. It is now read-only.
Sync requests immediately return with empty payload (v2) #15082
Labels
A-Sync
defects related to /sync
O-Frequent
Affects or can be seen by most users regularly or impacts most users' first experience
S-Minor
Blocks non-critical functionality, workarounds exist.
T-Defect
Bugs, crashes, hangs, security vulnerabilities, or other reported issues.
Comments
MatMaul
added
A-Sync
|
@dbkr Can you enable debug logging and try to reproduce again? |
erikjohnston
added
the
X-Needs-Info
|
Ah, yes. Quite surprised I didn't have debug logging on already. |
|
From where that's returning it sounds like it might be due to #14973 😢 Are you using any filters? |
|
This is a fairly boring element sync request, so the filter is |
|
Is this consistently reproducible on your dev setup? |
|
Just tried again but I can't repro it now. I'm not sure what changed. |
|
Shame, I'm struggling to make sense of the logs but was hoping we might have a reproducible case available in a test environment that could be passed around, guess not though |
H-Shay
removed
the
X-Needs-Info
|
I'm facing the same problem. Dockerized Synapse v1.78.0 on my dev machine, completely idle. My sync code went crazy so I tried to reproduce the issue using curl: same problem: ## first request
2023-03-07 13:27:58,319 - synapse.access.http.8008 - 415 - DEBUG - GET-27 - ::ffff:172.17.0.1 - 8008 - Received request: GET /_matrix/client/v3/sync?timeout=30000&since=s20535_72983_0_62_800_1_10_553_0_1
2023-03-07 13:27:58,319 - synapse.rest.client.sync - 131 - DEBUG - GET-27 - /sync: user=@sylvester:thomass-macbook-pro.local, timeout=30000, since='s20535_72983_0_62_800_1_10_553_0_1', set_presence='online', filter_id=None, device_id='LAPTOP'
2023-03-07 13:27:58,319 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block presence_update_states
2023-03-07 13:27:58,319 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block presence_update_states
2023-03-07 13:27:58,320 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block presence_update_states
2023-03-07 13:27:58,320 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block presence_update_states
2023-03-07 13:27:58,320 - synapse.util.caches.response_cache - 236 - DEBUG - GET-27 - [sync]: no cached result for [(@sylvester:thomass-macbook-pro.local, 30000, 's20535_72983_0_62_800_1_10_553_0_1', None, False, 'LAPTOP')], calculating new one
2023-03-07 13:27:58,320 - synapse.storage.txn - 692 - DEBUG - GET-27 - [TXN START] {delete_messages_for_device-ea}
2023-03-07 13:27:58,321 - synapse.storage.txn - 796 - DEBUG - GET-27 - [TXN END] {delete_messages_for_device-ea} 0.000186 sec
2023-03-07 13:27:58,321 - synapse.handlers.sync - 366 - DEBUG - GET-27 - Deleted 0 to-device messages up to 10
2023-03-07 13:27:58,322 - synapse.handlers.sync - 1440 - DEBUG - GET-27 - Calculating sync response for @sylvester:thomass-macbook-pro.local between StreamToken(room_key=RoomStreamToken(topological=None, stream=20535, instance_map=frozendict.frozendict({})), presence_key=72983, typing_key=0, receipt_key=62, account_data_key=800, push_rules_key=1, to_device_key=10, device_list_key=553, groups_key=0, un_partial_stated_rooms_key=1) and StreamToken(room_key=RoomStreamToken(topological=None, stream=20535, instance_map=frozendict.frozendict({})), presence_key=72983, typing_key=0, receipt_key=62, account_data_key=800, push_rules_key=1, to_device_key=10, device_list_key=553, groups_key=0, un_partial_stated_rooms_key=1)
2023-03-07 13:27:58,322 - synapse.handlers.sync - 1458 - DEBUG - GET-27 - Fetching account data
2023-03-07 13:27:58,322 - synapse.storage.txn - 692 - DEBUG - GET-27 - [TXN START] {get_updated_global_account_data_for_user-eb}
2023-03-07 13:27:58,322 - synapse.storage.txn - 796 - DEBUG - GET-27 - [TXN END] {get_updated_global_account_data_for_user-eb} 0.000255 sec
2023-03-07 13:27:58,323 - synapse.storage.txn - 692 - DEBUG - GET-27 - [TXN START] {have_push_rules_changed-ec}
2023-03-07 13:27:58,323 - synapse.storage.txn - 796 - DEBUG - GET-27 - [TXN END] {have_push_rules_changed-ec} 0.000171 sec
2023-03-07 13:27:58,323 - synapse.handlers.sync - 1481 - DEBUG - GET-27 - Fetching room data
2023-03-07 13:27:58,324 - synapse.storage.txn - 692 - DEBUG - GET-27 - [TXN START] {get_updated_room_account_data_for_user-ed}
2023-03-07 13:27:58,324 - synapse.storage.txn - 796 - DEBUG - GET-27 - [TXN END] {get_updated_room_account_data_for_user-ed} 0.000161 sec
2023-03-07 13:27:58,324 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block ephemeral_by_room
2023-03-07 13:27:58,324 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block typing.get_new_events
2023-03-07 13:27:58,324 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block typing.get_new_events
2023-03-07 13:27:58,324 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block ephemeral_by_room
2023-03-07 13:27:58,325 - synapse.storage.txn - 692 - DEBUG - GET-27 - [TXN START] {get_updated_tags-ee}
2023-03-07 13:27:58,325 - synapse.storage.txn - 796 - DEBUG - GET-27 - [TXN END] {get_updated_tags-ee} 0.000200 sec
2023-03-07 13:27:58,325 - synapse.handlers.sync - 1915 - DEBUG - GET-27 - no-oping sync
2023-03-07 13:27:58,325 - synapse.handlers.sync - 1504 - DEBUG - GET-27 - Fetching presence data
2023-03-07 13:27:58,325 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block presence.get_new_events
2023-03-07 13:27:58,326 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block presence.get_new_events
2023-03-07 13:27:58,326 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block _generate_sync_entry_for_device_list
2023-03-07 13:27:58,326 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block _generate_sync_entry_for_device_list
2023-03-07 13:27:58,326 - synapse.handlers.sync - 1520 - DEBUG - GET-27 - Fetching to-device data
2023-03-07 13:27:58,326 - synapse.handlers.sync - 1523 - DEBUG - GET-27 - Fetching OTK data
2023-03-07 13:27:58,326 - synapse.handlers.sync - 1552 - DEBUG - GET-27 - Sync response calculation complete
2023-03-07 13:27:58,326 - synapse.handlers.sync - 324 - DEBUG - GET-27 - Returning sync response for @sylvester:thomass-macbook-pro.local
2023-03-07 13:27:58,326 - synapse.util.metrics - 163 - DEBUG - GET-27 - Entering block presence_update_states
2023-03-07 13:27:58,327 - synapse.util.metrics - 176 - DEBUG - GET-27 - Exiting block presence_update_states
2023-03-07 13:27:58,327 - synapse.rest.client.sync - 222 - DEBUG - GET-27 - Formatting events in sync response
2023-03-07 13:27:58,327 - synapse.rest.client.sync - 257 - DEBUG - GET-27 - building sync response dict
2023-03-07 13:27:58,327 - synapse.rest.client.sync - 211 - DEBUG - GET-27 - Event formatting complete
2023-03-07 13:27:58,328 - synapse.access.http.8008 - 460 - INFO - GET-27 - ::ffff:172.17.0.1 - 8008 - {@sylvester:thomass-macbook-pro.local} Processed request: 0.008sec/0.000sec (0.002sec, 0.002sec) (0.001sec/0.001sec/5) 1170B 200 "GET /_matrix/client/v3/sync?timeout=30000&since=s20535_72983_0_62_800_1_10_553_0_1 HTTP/1.1" "curl/7.86.0" [0 dbevts]
2023-03-07 13:27:58,404 - synapse.metrics._gc - 118 - DEBUG - sentinel - Collecting gc 0
2023-03-07 13:28:02,901 - synapse.storage.txn - 692 - DEBUG - prune_old_user_ips-58 - [TXN START] {_prune_old_user_ips-ef}
2023-03-07 13:28:02,901 - synapse.storage.txn - 796 - DEBUG - prune_old_user_ips-58 - [TXN END] {_prune_old_user_ips-ef} 0.000396 sec
2023-03-07 13:28:03,097 - synapse.handlers.typing - 100 - DEBUG - typing._handle_timeouts-58 - Checking for typing timeouts
2023-03-07 13:28:03,098 - synapse.handlers.presence - 909 - DEBUG - handle_presence_timeouts-52 - Handling presence timeouts
2023-03-07 13:28:03,098 - synapse.util.metrics - 163 - DEBUG - handle_presence_timeouts-52 - Entering block presence_update_states
2023-03-07 13:28:03,098 - synapse.util.metrics - 176 - DEBUG - handle_presence_timeouts-52 - Exiting block presence_update_states
2023-03-07 13:28:07,625 - synapse.access.http.8008 - 415 - DEBUG - GET-28 - ::ffff:127.0.0.1 - 8008 - Received request: GET /health
2023-03-07 13:28:07,625 - synapse.access.http.8008 - 460 - DEBUG - GET-28 - ::ffff:127.0.0.1 - 8008 - {None} Processed request: 0.000sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 2B 200 "GET /health HTTP/1.1" "curl/7.74.0" [0 dbevts]
2023-03-07 13:28:07,897 - synapse.storage.txn - 692 - DEBUG - _cleanup_old_transaction_ids-0 - [TXN START] {_cleanup_old_transaction_ids-f0}
2023-03-07 13:28:07,898 - synapse.storage.txn - 796 - DEBUG - _cleanup_old_transaction_ids-0 - [TXN END] {_cleanup_old_transaction_ids-f0} 0.000929 sec
2023-03-07 13:28:07,899 - synapse.storage.txn - 692 - DEBUG - _get_stats_for_federation_staging-9 - [TXN START] {_get_stats_for_federation_staging-f1}
2023-03-07 13:28:07,899 - synapse.storage.txn - 796 - DEBUG - _get_stats_for_federation_staging-9 - [TXN END] {_get_stats_for_federation_staging-f1} 0.000373 sec
2023-03-07 13:28:07,899 - synapse.storage.txn - 692 - DEBUG - _censor_redactions-0 - [TXN START] {_censor_redactions_fetch-f2}
2023-03-07 13:28:07,900 - synapse.storage.txn - 796 - DEBUG - _censor_redactions-0 - [TXN END] {_censor_redactions_fetch-f2} 0.001172 sec
2023-03-07 13:28:07,901 - synapse.storage.txn - 692 - DEBUG - prune_old_user_ips-59 - [TXN START] {_prune_old_user_ips-f3}
2023-03-07 13:28:07,901 - synapse.storage.txn - 796 - DEBUG - prune_old_user_ips-59 - [TXN END] {_prune_old_user_ips-f3} 0.000696 sec
2023-03-07 13:28:07,902 - synapse.storage.txn - 692 - DEBUG - _censor_redactions-0 - [TXN START] {_update_censor_txn-f4}
2023-03-07 13:28:07,902 - synapse.storage.txn - 796 - DEBUG - _censor_redactions-0 - [TXN END] {_update_censor_txn-f4} 0.000555 sec
2023-03-07 13:28:08,031 - synapse.storage.txn - 692 - DEBUG - rotate_notifs-9 - [TXN START] {_handle_new_receipts_for_notifs_txn-f5}
2023-03-07 13:28:08,031 - synapse.storage.txn - 796 - DEBUG - rotate_notifs-9 - [TXN END] {_handle_new_receipts_for_notifs_txn-f5} 0.000446 sec
2023-03-07 13:28:08,032 - synapse.storage.txn - 692 - DEBUG - rotate_notifs-9 - [TXN START] {_rotate_notifs-f6}
2023-03-07 13:28:08,032 - synapse.storage.txn - 796 - DEBUG - rotate_notifs-9 - [TXN END] {_rotate_notifs-f6} 0.000333 sec
2023-03-07 13:28:08,033 - synapse.storage.txn - 692 - DEBUG - rotate_notifs-9 - [TXN START] {simple_select_one_onecol-f7}
2023-03-07 13:28:08,033 - synapse.storage.txn - 796 - DEBUG - rotate_notifs-9 - [TXN END] {simple_select_one_onecol-f7} 0.000191 sec
2023-03-07 13:28:08,034 - synapse.storage.txn - 692 - DEBUG - rotate_notifs-9 - [TXN START] {_remove_old_push_actions_that_have_rotated-f8}
2023-03-07 13:28:08,034 - synapse.storage.txn - 796 - DEBUG - rotate_notifs-9 - [TXN END] {_remove_old_push_actions_that_have_rotated-f8} 0.000205 sec
2023-03-07 13:28:08,071 - synapse.storage.txn - 692 - DEBUG - expire_old_sessions-0 - [TXN START] {delete_old_ui_auth_sessions-f9}
2023-03-07 13:28:08,071 - synapse.storage.txn - 796 - DEBUG - expire_old_sessions-0 - [TXN END] {delete_old_ui_auth_sessions-f9} 0.000425 sec
2023-03-07 13:28:08,096 - synapse.util.caches.expiringcache - 189 - DEBUG - prune_cache_get_pdu_cache-4 - [get_pdu_cache] _prune_cache before: 0, after len: 0
2023-03-07 13:28:08,096 - synapse.util.caches.expiringcache - 189 - DEBUG - prune_cache_get_room_hierarchy_cache-1 - [get_room_hierarchy_cache] _prune_cache before: 0, after len: 0
2023-03-07 13:28:08,097 - synapse.handlers.typing - 100 - DEBUG - typing._handle_timeouts-59 - Checking for typing timeouts
2023-03-07 13:28:08,097 - synapse.storage.txn - 692 - DEBUG - _maybe_retry_device_resync-9 - [TXN START] {get_user_ids_requiring_device_list_resync-fa}
2023-03-07 13:28:08,097 - synapse.handlers.presence - 797 - INFO - persist_presence_changes-3 - Persisting 1 unpersisted presence updates
2023-03-07 13:28:08,097 - synapse.storage.txn - 796 - DEBUG - _maybe_retry_device_resync-9 - [TXN END] {get_user_ids_requiring_device_list_resync-fa} 0.000476 sec
2023-03-07 13:28:08,098 - synapse.handlers.presence - 909 - DEBUG - handle_presence_timeouts-53 - Handling presence timeouts
2023-03-07 13:28:08,098 - synapse.storage.txn - 692 - DEBUG - send_dummy_events_to_fill_extremities-0 - [TXN START] {get_rooms_with_many_extremities-fb}
2023-03-07 13:28:08,099 - synapse.util.metrics - 163 - DEBUG - handle_presence_timeouts-53 - Entering block presence_update_states
2023-03-07 13:28:08,099 - synapse.util.metrics - 176 - DEBUG - handle_presence_timeouts-53 - Exiting block presence_update_states
2023-03-07 13:28:08,102 - synapse.storage.txn - 796 - DEBUG - send_dummy_events_to_fill_extremities-0 - [TXN END] {get_rooms_with_many_extremities-fb} 0.003897 sec
2023-03-07 13:28:08,102 - synapse.storage.txn - 692 - DEBUG - persist_presence_changes-3 - [TXN START] {update_presence-fc}
2023-03-07 13:28:08,104 - synapse.metrics._gc - 118 - DEBUG - sentinel - Collecting gc 0
2023-03-07 13:28:08,106 - synapse.storage.txn - 796 - DEBUG - persist_presence_changes-3 - [TXN END] {update_presence-fc} 0.003619 sec
2023-03-07 13:28:08,107 - synapse.util.metrics - 163 - DEBUG - user_directory.notify_new_event-12 - Entering block user_dir_delta
2023-03-07 13:28:08,107 - synapse.util.metrics - 176 - DEBUG - user_directory.notify_new_event-12 - Exiting block user_dir_delta
2023-03-07 13:28:08,107 - synapse.util.metrics - 163 - DEBUG - presence.notify_new_event-11 - Entering block presence_delta
2023-03-07 13:28:08,107 - synapse.util.metrics - 176 - DEBUG - presence.notify_new_event-11 - Exiting block presence_delta
2023-03-07 13:28:08,108 - synapse.util.caches.lrucache - 134 - DEBUG - LruCache._expire_old_entries-9 - Searching for stale caches
2023-03-07 13:28:08,109 - synapse.util.caches.lrucache - 212 - INFO - LruCache._expire_old_entries-9 - Dropped 0 items from caches
2023-03-07 13:28:08,121 - synapse.storage.txn - 692 - DEBUG - update_recently_accessed_media-4 - [TXN START] {update_cached_last_access_time-fd}
2023-03-07 13:28:08,121 - synapse.storage.txn - 796 - DEBUG - update_recently_accessed_media-4 - [TXN END] {update_cached_last_access_time-fd} 0.000204 sec
2023-03-07 13:28:08,152 - synapse.storage.TIME - 606 - DEBUG - sentinel - Total database time: 0.149% {get_rooms_with_many_extremities(1): 0.039%, update_presence(1): 0.036%, _censor_redactions_fetch(1): 0.012%}
2023-03-07 13:28:08,154 - synapse.storage.txn - 692 - DEBUG - common_usage_metrics_update_gauges-1 - [TXN START] {count_daily_users-fe}
2023-03-07 13:28:08,154 - synapse.storage.txn - 796 - DEBUG - common_usage_metrics_update_gauges-1 - [TXN END] {count_daily_users-fe} 0.000187 sec
2023-03-07 13:28:08,154 - synapse.storage.txn - 692 - DEBUG - generate_user_daily_visits-0 - [TXN START] {generate_user_daily_visits-ff}
2023-03-07 13:28:08,156 - synapse.storage.txn - 796 - DEBUG - generate_user_daily_visits-0 - [TXN END] {generate_user_daily_visits-ff} 0.001374 sec
## call returns immediately
## making second request with the same streamToken
2023-03-07 13:28:10,196 - synapse.access.http.8008 - 415 - DEBUG - GET-29 - ::ffff:172.17.0.1 - 8008 - Received request: GET /_matrix/client/v3/sync?timeout=30000&since=s20535_72983_0_62_800_1_10_553_0_1
2023-03-07 13:28:10,196 - synapse.rest.client.sync - 131 - DEBUG - GET-29 - /sync: user=@sylvester:thomass-macbook-pro.local, timeout=30000, since='s20535_72983_0_62_800_1_10_553_0_1', set_presence='online', filter_id=None, device_id='LAPTOP'
2023-03-07 13:28:10,196 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block presence_update_states
2023-03-07 13:28:10,196 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block presence_update_states
2023-03-07 13:28:10,196 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block presence_update_states
2023-03-07 13:28:10,197 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block presence_update_states
2023-03-07 13:28:10,197 - synapse.util.caches.response_cache - 236 - DEBUG - GET-29 - [sync]: no cached result for [(@sylvester:thomass-macbook-pro.local, 30000, 's20535_72983_0_62_800_1_10_553_0_1', None, False, 'LAPTOP')], calculating new one
2023-03-07 13:28:10,197 - synapse.storage.txn - 692 - DEBUG - GET-29 - [TXN START] {delete_messages_for_device-100}
2023-03-07 13:28:10,198 - synapse.storage.txn - 796 - DEBUG - GET-29 - [TXN END] {delete_messages_for_device-100} 0.000213 sec
2023-03-07 13:28:10,198 - synapse.handlers.sync - 366 - DEBUG - GET-29 - Deleted 0 to-device messages up to 10
2023-03-07 13:28:10,199 - synapse.handlers.sync - 1440 - DEBUG - GET-29 - Calculating sync response for @sylvester:thomass-macbook-pro.local between StreamToken(room_key=RoomStreamToken(topological=None, stream=20535, instance_map=frozendict.frozendict({})), presence_key=72983, typing_key=0, receipt_key=62, account_data_key=800, push_rules_key=1, to_device_key=10, device_list_key=553, groups_key=0, un_partial_stated_rooms_key=1) and StreamToken(room_key=RoomStreamToken(topological=None, stream=20535, instance_map=frozendict.frozendict({})), presence_key=72984, typing_key=0, receipt_key=62, account_data_key=800, push_rules_key=1, to_device_key=10, device_list_key=553, groups_key=0, un_partial_stated_rooms_key=1)
2023-03-07 13:28:10,199 - synapse.handlers.sync - 1458 - DEBUG - GET-29 - Fetching account data
2023-03-07 13:28:10,199 - synapse.storage.txn - 692 - DEBUG - GET-29 - [TXN START] {get_updated_global_account_data_for_user-101}
2023-03-07 13:28:10,199 - synapse.storage.txn - 796 - DEBUG - GET-29 - [TXN END] {get_updated_global_account_data_for_user-101} 0.000255 sec
2023-03-07 13:28:10,200 - synapse.storage.txn - 692 - DEBUG - GET-29 - [TXN START] {have_push_rules_changed-102}
2023-03-07 13:28:10,200 - synapse.storage.txn - 796 - DEBUG - GET-29 - [TXN END] {have_push_rules_changed-102} 0.000336 sec
2023-03-07 13:28:10,201 - synapse.handlers.sync - 1481 - DEBUG - GET-29 - Fetching room data
2023-03-07 13:28:10,201 - synapse.storage.txn - 692 - DEBUG - GET-29 - [TXN START] {get_updated_room_account_data_for_user-103}
2023-03-07 13:28:10,201 - synapse.storage.txn - 796 - DEBUG - GET-29 - [TXN END] {get_updated_room_account_data_for_user-103} 0.000160 sec
2023-03-07 13:28:10,201 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block ephemeral_by_room
2023-03-07 13:28:10,202 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block typing.get_new_events
2023-03-07 13:28:10,202 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block typing.get_new_events
2023-03-07 13:28:10,202 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block ephemeral_by_room
2023-03-07 13:28:10,202 - synapse.storage.txn - 692 - DEBUG - GET-29 - [TXN START] {get_updated_tags-104}
2023-03-07 13:28:10,202 - synapse.storage.txn - 796 - DEBUG - GET-29 - [TXN END] {get_updated_tags-104} 0.000169 sec
2023-03-07 13:28:10,203 - synapse.handlers.sync - 1915 - DEBUG - GET-29 - no-oping sync
2023-03-07 13:28:10,203 - synapse.handlers.sync - 1504 - DEBUG - GET-29 - Fetching presence data
2023-03-07 13:28:10,203 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block presence.get_new_events
2023-03-07 13:28:10,203 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block presence.get_new_events
2023-03-07 13:28:10,203 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block _generate_sync_entry_for_device_list
2023-03-07 13:28:10,204 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block _generate_sync_entry_for_device_list
2023-03-07 13:28:10,204 - synapse.handlers.sync - 1520 - DEBUG - GET-29 - Fetching to-device data
2023-03-07 13:28:10,204 - synapse.handlers.sync - 1523 - DEBUG - GET-29 - Fetching OTK data
2023-03-07 13:28:10,204 - synapse.handlers.sync - 1552 - DEBUG - GET-29 - Sync response calculation complete
2023-03-07 13:28:10,204 - synapse.handlers.sync - 324 - DEBUG - GET-29 - Returning sync response for @sylvester:thomass-macbook-pro.local
2023-03-07 13:28:10,204 - synapse.util.metrics - 163 - DEBUG - GET-29 - Entering block presence_update_states
2023-03-07 13:28:10,204 - synapse.util.metrics - 176 - DEBUG - GET-29 - Exiting block presence_update_states
2023-03-07 13:28:10,205 - synapse.rest.client.sync - 222 - DEBUG - GET-29 - Formatting events in sync response
2023-03-07 13:28:10,205 - synapse.rest.client.sync - 257 - DEBUG - GET-29 - building sync response dict
2023-03-07 13:28:10,205 - synapse.rest.client.sync - 211 - DEBUG - GET-29 - Event formatting complete
2023-03-07 13:28:10,206 - synapse.access.http.8008 - 460 - INFO - GET-29 - ::ffff:172.17.0.1 - 8008 - {@sylvester:thomass-macbook-pro.local} Processed request: 0.010sec/0.001sec (0.004sec, 0.002sec) (0.001sec/0.001sec/5) 1340B 200 "GET /_matrix/client/v3/sync?timeout=30000&since=s20535_72983_0_62_800_1_10_553_0_1 HTTP/1.1" "curl/7.86.0" [0 dbevts] |
|
This gets even more strange. I witness the following on our production server (v1.78.0 started with docker compose using PostgreSQL):
const EVENT_TYPES = {
STATE: ['m.room.name', 'm.room.member', 'm.space.child', 'm.room.create']
}
const filter = {
room: {
timeline: { limit: 1000, types: EVENT_TYPES.STATE },
ephemeral: {
not_types: [ '*' ]
}
}
}
|
|
According to @richvdh:
Unclear what the root cause of this is, however. |
|
This is a dupe of #15824 |
|
Seems like it. 👍 |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Description
#8518 seems to be reocurring on my dev setup. Symptoms appear to be the same and since this my dev homeserver, there's nothing else happening on the server, so the sync response is indeed empty. I start the synapse server, the client connects and completes 4 sync requests normally, each taking 30 seconds. The 5th and subsequent requests return straight away and start tightlooping. Also notable is the fact that the last sync response that takes 30 seconds contains a presence update for the user's own user.
Steps to reproduce
Probably:
...although I've not changed anything about my dev setup and I haven't seen this previously, so this would suggest something else has changed.
Homeserver
local dev
Synapse Version
d1efc47
Installation Method
Other (please mention below)
Database
sqlite
Workers
Single process
Platform
Running from source with poetry, macos.
Configuration
No response
Relevant log output
Anything else that would be useful to know?
No response
The text was updated successfully, but these errors were encountered: