Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Sync: list index out of range #5407

Closed
waylon531 opened this issue Jun 9, 2019 · 13 comments
Closed

Sync: list index out of range #5407

waylon531 opened this issue Jun 9, 2019 · 13 comments
Assignees
Labels
z-bug (Deprecated Label)

Comments

@waylon531
Copy link
Contributor

Description

This morning when opened up Riot I got a message that I had lost connectivity to the homeserver. Synapse and all of its workers appeared to be running fine, but my logs for the synchrotron worker were filled with this error message:

https://gist.github.com/waylon531/90c205b7540ea017dbf0fec705506e05

As far as workers go I'm running a federation sender, a federation reader, and a synchrotron worker. The synchrotron worker is the only worker that appears to be broken. I have no clue what caused this error, the server was working fine last night and appears to have broken by itself overnight.

Version information

  • Homeserver: riot.firechicken.net

  • Version: 99.5.2

  • Install method: pip

  • Platform: A google cloud VPS running CentOS 7

@waylon531 waylon531 changed the title Synchotron worker broken Synchrotron worker broken Jun 9, 2019
@aaronraimist
Copy link
Contributor

Related: #4842

By the way it is probably better if you paste your error in here in a code block so it is searchable

@waylon531
Copy link
Contributor Author

Will do, here it is:

2019-06-09 19:03:46,553 - synapse.http.server - 112 - ERROR - GET-835 - Failed handle request via 'SyncRestServlet': <SynapseRequest at 0x7f955618ce10 method='GET' uri='/_matrix/client/r0/sync?filter=0&timeout=0&since=s707461_26561430_2874_634533_24909_56_95_55442_1' clientproto='HTTP/1.0' site=8083>
Traceback (most recent call last):
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/storage/_base.py", line 527, in runWithConnection
    defer.returnValue(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: [_EventDictReturn(event_id='$15600950391010258hrwAd:matrix.org', topological_ordering=None, stream_ordering=708773), _EventDictReturn(event_id='$15600950171010117CdspK:matrix.org', topological_ordering=None, stream_ordering=708772), _EventDictReturn(event_id='$15600949401009508lTpzl:matrix.org', topological_ordering=None, stream_ordering=708771), _EventDictReturn(event_id='$15600949261009398foetQ:matrix.org', topological_ordering=None, stream_ordering=708770), _EventDictReturn(event_id='$15600949091009307PONGY:matrix.org', topological_ordering=None, stream_ordering=708769), _EventDictReturn(event_id='$15600948911009164JkHeG:matrix.org', topological_ordering=None, stream_ordering=708768), _EventDictReturn(event_id='$15600948821009108qkrIj:matrix.org', topological_ordering=None, stream_ordering=708767), _EventDictReturn(event_id='$15600948591008929UoHxd:matrix.org', topological_ordering=None, stream_ordering=708766), _EventDictReturn(event_id='$15600948501008732joyAz:matrix.org', topological_ordering=None, stream_ordering=708765), _EventDictReturn(event_id='$15600948321008586DDtRZ:matrix.org', topological_ordering=None, stream_ordering=708764), _EventDictReturn(event_id='$15600948311008562BFdsx:matrix.org', topological_ordering=None, stream_ordering=708763), _EventDictReturn(event_id='$15600948311008555lylfW:matrix.org', topological_ordering=None, stream_ordering=708762), _EventDictReturn(event_id='$15600948051008364bsBFK:matrix.org', topological_ordering=None, stream_ordering=708761), _EventDictReturn(event_id='$15600947551008018jCiVq:matrix.org', topological_ordering=None, stream_ordering=708760), _EventDictReturn(event_id='$15600947491007978QDPLH:matrix.org', topological_ordering=None, stream_ordering=708759), _EventDictReturn(event_id='$15600947131007663SiNSd:matrix.org', topological_ordering=None, stream_ordering=708758), _EventDictReturn(event_id='$15600946391007033aolro:matrix.org', topological_ordering=None, stream_ordering=708755), _EventDictReturn(event_id='$15600946091006766ZzkSV:matrix.org', topological_ordering=None, stream_ordering=708754), _EventDictReturn(event_id='$15600945021005812lLBZU:matrix.org', topological_ordering=None, stream_ordering=708752), _EventDictReturn(event_id='$15600945001005804zAlqr:matrix.org', topological_ordering=None, stream_ordering=708751), _EventDictReturn(event_id='$15600945001005796CUSFf:matrix.org', topological_ordering=None, stream_ordering=708750)]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/storage/_base.py", line 487, in runInteraction
    defer.returnValue(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: [_EventDictReturn(event_id='$15600950391010258hrwAd:matrix.org', topological_ordering=None, stream_ordering=708773), _EventDictReturn(event_id='$15600950171010117CdspK:matrix.org', topological_ordering=None, stream_ordering=708772), _EventDictReturn(event_id='$15600949401009508lTpzl:matrix.org', topological_ordering=None, stream_ordering=708771), _EventDictReturn(event_id='$15600949261009398foetQ:matrix.org', topological_ordering=None, stream_ordering=708770), _EventDictReturn(event_id='$15600949091009307PONGY:matrix.org', topological_ordering=None, stream_ordering=708769), _EventDictReturn(event_id='$15600948911009164JkHeG:matrix.org', topological_ordering=None, stream_ordering=708768), _EventDictReturn(event_id='$15600948821009108qkrIj:matrix.org', topological_ordering=None, stream_ordering=708767), _EventDictReturn(event_id='$15600948591008929UoHxd:matrix.org', topological_ordering=None, stream_ordering=708766), _EventDictReturn(event_id='$15600948501008732joyAz:matrix.org', topological_ordering=None, stream_ordering=708765), _EventDictReturn(event_id='$15600948321008586DDtRZ:matrix.org', topological_ordering=None, stream_ordering=708764), _EventDictReturn(event_id='$15600948311008562BFdsx:matrix.org', topological_ordering=None, stream_ordering=708763), _EventDictReturn(event_id='$15600948311008555lylfW:matrix.org', topological_ordering=None, stream_ordering=708762), _EventDictReturn(event_id='$15600948051008364bsBFK:matrix.org', topological_ordering=None, stream_ordering=708761), _EventDictReturn(event_id='$15600947551008018jCiVq:matrix.org', topological_ordering=None, stream_ordering=708760), _EventDictReturn(event_id='$15600947491007978QDPLH:matrix.org', topological_ordering=None, stream_ordering=708759), _EventDictReturn(event_id='$15600947131007663SiNSd:matrix.org', topological_ordering=None, stream_ordering=708758), _EventDictReturn(event_id='$15600946391007033aolro:matrix.org', topological_ordering=None, stream_ordering=708755), _EventDictReturn(event_id='$15600946091006766ZzkSV:matrix.org', topological_ordering=None, stream_ordering=708754), _EventDictReturn(event_id='$15600945021005812lLBZU:matrix.org', topological_ordering=None, stream_ordering=708752), _EventDictReturn(event_id='$15600945001005804zAlqr:matrix.org', topological_ordering=None, stream_ordering=708751), _EventDictReturn(event_id='$15600945001005796CUSFf:matrix.org', topological_ordering=None, stream_ordering=708750)]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/storage/stream.py", line 414, in get_room_events_stream_for_room
    defer.returnValue((ret, key))
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: ([<FrozenEvent event_id='$15600945001005796CUSFf:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600945001005804zAlqr:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600945021005812lLBZU:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600946091006766ZzkSV:matrix.org', type='m.room.member', state_key='@freenode_heatsink:matrix.org'>, <FrozenEvent event_id='$15600946391007033aolro:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600947131007663SiNSd:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600947491007978QDPLH:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600947551008018jCiVq:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948051008364bsBFK:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948311008555lylfW:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948311008562BFdsx:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948321008586DDtRZ:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948501008732joyAz:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948591008929UoHxd:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948821009108qkrIj:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600948911009164JkHeG:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600949091009307PONGY:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600949261009398foetQ:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600949401009508lTpzl:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600950171010117CdspK:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$15600950391010258hrwAd:matrix.org', type='m.room.message', state_key='None'>], 's708750')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 472, in _load_filtered_recents
    limited=limited or newly_joined_room
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: TimelineBatch(prev_batch=StreamToken(room_key='s708889', presence_key=26599051, typing_key=57, receipt_key=636004, account_data_key=24914, push_rules_key=56, to_device_key=95, device_list_key=55442, groups_key=1), events=[], limited=True)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
    yield h(self, request)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/http/server.py", line 316, in _async_render
    callback_return = yield callback(request, **kwargs)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/rest/client/v2_alpha/sync.py", line 167, in on_GET
    full_state=full_state
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 242, in wait_for_sync_for_user
    sync_config, since_token, timeout, full_state,
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 264, in _wait_for_sync_for_user
    sync_config, since_token, full_state=full_state,
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 935, in generate_sync_result
    sync_result_builder, account_data_by_room
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 1316, in _generate_sync_entry_for_rooms
    yield concurrently_execute(handle_room_entries, room_entries, 10)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/util/async_helpers.py", line 149, in _concurrently_execute_inner
    yield func(next(it))
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 1752, in _generate_room_entry
    full_state=full_state
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/synapse/synapse/env3/lib/python3.6/site-packages/synapse/handlers/sync.py", line 775, in compute_state_delta
    batch.events[0].event_id, state_filter=state_filter,
IndexError: list index out of range

@waylon531
Copy link
Contributor Author

Here's the object I'm getting with no events:

TimelineBatch(prev_batch=StreamToken(room_key='s708889', presence_key=26606688, 
  typing_key=181, receipt_key=636329, account_data_key=24914, push_rules_key=56, 
  to_device_key=95, device_list_key=55442, groups_key=1), 
events=[], limited=True)

@waylon531
Copy link
Contributor Author

For some reason this error only happens when I'm connecting via my self-hosted riot instance. I can connect fine using the android app even though both clients are calling the same endpoint

This request triggers the error: GET /_matrix/client/r0/sync?filter=0&timeout=0&since=s707461_26561430_2874_634533_24909_56_95_55442_1

But this doesn't: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s710004_26612436_282_636657_24915_56_95_55442_1

@Half-Shot
Copy link
Collaborator

For some reason this error only happens when I'm connecting via my self-hosted riot instance. I can connect fine using the android app even though both clients are calling the same endpoint

Have you tried doing cache refresh in your riot instance? Could be some broken incremental sync data.

@waylon531
Copy link
Contributor Author

Yep, that did it. It's working now, thanks!

@waylon531
Copy link
Contributor Author

It turns out that clearing the cache was a temporary fix. I get the same issue about once a day now, fortunately fixing it again is pretty easy but it's still annoying

@richvdh
Copy link
Member

richvdh commented Jun 27, 2019

So this is the same as #4842, which we never got to the bottom of. Again, the surprising thing is that the returned results have limited=True with events=[].

@waylon531 I'm interested in the settings on your sync filter. Can you share the results of this database query: select encode(filter_json, 'escape') from user_filters where user_id='uelen' and filter_id=0;

@richvdh richvdh changed the title Synchrotron worker broken Sync: list index out of range Jun 27, 2019
@waylon531
Copy link
Contributor Author

Here it is:

synapse=> select encode(filter_json, 'escape') from user_filters where user_id='uelen' and filter_id=0;
                    encode                     
-----------------------------------------------
 {"room":{"state":{"lazy_load_members":true}}}
(1 row)

@ara4n
Copy link
Member

ara4n commented Aug 5, 2019

Parity are seeing this too for a user on their homeserver with precisely the same symptoms - it's fixed by clearing cache, but then breaks roughly once a day. stacktrace is:

2019-08-02 09:55:04,695 - synapse.handlers.sync - 1859 - INFO - GET-654776- Incremental gappy sync of !fOOzymDEHiIIUtmlBE:matrix.org for user @xxxxx:matrix.parity.io with 6 state events
2019-08-02 09:55:04,698 - synapse.http.server - 108 - ERROR - GET-654776- Failed handle request via 'SyncRestServlet': <SynapseRequest at 0x7f15030838d0 method='GET' uri='/_matrix/client/r0/sync?filter=2&set_presence=offline&timeout=30000&since=s4595570_52728671_220931_4516767_2479108_3345_1584806_196913_331' clientproto='HTTP/1.0' site=8008>
Traceback (most recent call last):
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/synapse/storage/_base.py", line 542, in runWithConnection
    defer.returnValue(result)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: [_EventDictReturn(event_id='$1564717051444590nClvE:matrix.org', topological_ordering=None, stream_ordering=4609238), _EventDictReturn(event_id='$1564717038444527BwigZ:matrix.org', topological_ordering=None, stream_ordering=4609236), _EventDictReturn(event_id='$1564716506441830NfarU:matrix.org', topological_ordering=None, stream_ordering=4609230), _EventDictReturn(event_id='$1564716455441595yCQRr:matrix.org', topological_ordering=None, stream_ordering=4609229), _EventDictReturn(event_id='$1564716259440492UVxKe:matrix.org', topological_ordering=None, stream_ordering=4609224), _EventDictReturn(event_id='$1564715302434816qGSGE:matrix.org', topological_ordering=None, stream_ordering=4609207), _EventDictReturn(event_id='$1564715262434620WyShA:matrix.org', topological_ordering=None, stream_ordering=4609206), _EventDictReturn(event_id='$1564715241434521QPSqb:matrix.org', topological_ordering=None, stream_ordering=4609205), _EventDictReturn(event_id='$1564715130433764KOzNu:matrix.org', topological_ordering=None, stream_ordering=4609203), _EventDictReturn(event_id='$1564714939432644bZqIZ:matrix.org', topological_ordering=None, stream_ordering=4609201), _EventDictReturn(event_id='$1564714912432488TrYwO:matrix.org', topological_ordering=None, stream_ordering=4609198), _EventDictReturn(event_id='$1564714904432430RIFIp:matrix.org', topological_ordering=None, stream_ordering=4609197), _EventDictReturn(event_id='$1564714807431835pTodu:matrix.org', topological_ordering=None, stream_ordering=4609196), _EventDictReturn(event_id='$1564714805431828upIXQ:matrix.org', topological_ordering=None, stream_ordering=4609195), _EventDictReturn(event_id='$1564714797431782rphGA:matrix.org', topological_ordering=None, stream_ordering=4609194), _EventDictReturn(event_id='$1564714795431770TYuPq:matrix.org', topological_ordering=None, stream_ordering=4609193), _EventDictReturn(event_id='$1564714794431759jTOAF:matrix.org', topological_ordering=None, stream_ordering=4609192), _EventDictReturn(event_id='$1564714792431752otGTC:matrix.org', topological_ordering=None, stream_ordering=4609191), _EventDictReturn(event_id='$1564714792431749MouBZ:matrix.org', topological_ordering=None, stream_ordering=4609190), _EventDictReturn(event_id='$1564714791431747VGcSe:matrix.org', topological_ordering=None, stream_ordering=4609189), _EventDictReturn(event_id='$1564714791431745CKyqe:matrix.org', topological_ordering=None, stream_ordering=4609188)]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/synapse/storage/_base.py", line 502, in runInteraction
    defer.returnValue(result)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: [_EventDictReturn(event_id='$1564717051444590nClvE:matrix.org', topological_ordering=None, stream_ordering=4609238), _EventDictReturn(event_id='$1564717038444527BwigZ:matrix.org', topological_ordering=None, stream_ordering=4609236), _EventDictReturn(event_id='$1564716506441830NfarU:matrix.org', topological_ordering=None, stream_ordering=4609230), _EventDictReturn(event_id='$1564716455441595yCQRr:matrix.org', topological_ordering=None, stream_ordering=4609229), _EventDictReturn(event_id='$1564716259440492UVxKe:matrix.org', topological_ordering=None, stream_ordering=4609224), _EventDictReturn(event_id='$1564715302434816qGSGE:matrix.org', topological_ordering=None, stream_ordering=4609207), _EventDictReturn(event_id='$1564715262434620WyShA:matrix.org', topological_ordering=None, stream_ordering=4609206), _EventDictReturn(event_id='$1564715241434521QPSqb:matrix.org', topological_ordering=None, stream_ordering=4609205), _EventDictReturn(event_id='$1564715130433764KOzNu:matrix.org', topological_ordering=None, stream_ordering=4609203), _EventDictReturn(event_id='$1564714939432644bZqIZ:matrix.org', topological_ordering=None, stream_ordering=4609201), _EventDictReturn(event_id='$1564714912432488TrYwO:matrix.org', topological_ordering=None, stream_ordering=4609198), _EventDictReturn(event_id='$1564714904432430RIFIp:matrix.org', topological_ordering=None, stream_ordering=4609197), _EventDictReturn(event_id='$1564714807431835pTodu:matrix.org', topological_ordering=None, stream_ordering=4609196), _EventDictReturn(event_id='$1564714805431828upIXQ:matrix.org', topological_ordering=None, stream_ordering=4609195), _EventDictReturn(event_id='$1564714797431782rphGA:matrix.org', topological_ordering=None, stream_ordering=4609194), _EventDictReturn(event_id='$1564714795431770TYuPq:matrix.org', topological_ordering=None, stream_ordering=4609193), _EventDictReturn(event_id='$1564714794431759jTOAF:matrix.org', topological_ordering=None, stream_ordering=4609192), _EventDictReturn(event_id='$1564714792431752otGTC:matrix.org', topological_ordering=None, stream_ordering=4609191), _EventDictReturn(event_id='$1564714792431749MouBZ:matrix.org', topological_ordering=None, stream_ordering=4609190), _EventDictReturn(event_id='$1564714791431747VGcSe:matrix.org', topological_ordering=None, stream_ordering=4609189), _EventDictReturn(event_id='$1564714791431745CKyqe:matrix.org', topological_ordering=None, stream_ordering=4609188)]
During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/synapse/storage/stream.py", line 410, in get_room_events_stream_for_room
    defer.returnValue((ret, key))
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: ([<FrozenEvent event_id='$1564714791431745CKyqe:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714791431747VGcSe:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714792431749MouBZ:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714792431752otGTC:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714794431759jTOAF:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714795431770TYuPq:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714797431782rphGA:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714805431828upIXQ:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714807431835pTodu:matrix.org', type='m.room.message', state_key='None'>, <FrozenEvent event_id='$1564714904432430RIFIp:matrix.org', type='m.room.member', state_key='@mozilla_alx741:matrix.org'>, <FrozenEvent event_id='$1564714912432488TrYwO:matrix.org', type='m.room.member', state_key='@mozilla_asdasd:matrix.org'>, <FrozenEvent event_id='$1564714939432644bZqIZ:matrix.org', type='m.room.member', state_key='@mozilla_siddhartharao17:matrix.org'>, <FrozenEvent event_id='$1564715130433764KOzNu:matrix.org', type='m.room.member', state_key='@mozilla_siddhart_:matrix.org'>, <FrozenEvent event_id='$1564715241434521QPSqb:matrix.org', type='m.room.member', state_key='@mozilla_frum:matrix.org'>, <FrozenEvent event_id='$1564715262434620WyShA:matrix.org', type='m.room.member', state_key='@mozilla_frum:matrix.org'>, <FrozenEvent event_id='$1564715302434816qGSGE:matrix.org', type='m.room.member', state_key='@mozilla_siddhartharao17:matrix.org'>, <FrozenEvent event_id='$1564716259440492UVxKe:matrix.org', type='m.room.member', state_key='@mozilla_sp1ff1:matrix.org'>, <FrozenEvent event_id='$1564716455441595yCQRr:matrix.org', type='m.room.member', state_key='@mozilla_fowlslegs:matrix.org'>, <FrozenEvent event_id='$1564716506441830NfarU:matrix.org', type='m.room.member', state_key='@mozilla_machuga:matrix.org'>, <FrozenEvent event_id='$1564717038444527BwigZ:matrix.org', type='m.room.member', state_key='@mozilla_SandraRE:matrix.org'>, <FrozenEvent event_id='$1564717051444590nClvE:matrix.org', type='m.room.member', state_key='@mozilla_Guest12645:matrix.org'>], 's4609188')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/synapse/handlers/sync.py", line 497, in _load_filtered_recents
    limited=limited or newly_joined_room,
  File "/home/matrix/.synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: TimelineBatch(prev_batch=StreamToken(room_key='s4610833', presence_key=52921735, typing_key=7502, receipt_key=4534228, account_data_key=2500108, push_rules_key=3369, to_device_key=1593624, device_list_key=197629, groups_key=331), events=[], limited=True)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/matrix/.synapse/lib/python3.5/site-packages/synapse/http/server.py", line 76, in wrapped_request_handler
    await h(self, request)
  File "/home/matrix/.synapse/lib/python3.5/site-packages/synapse/http/server.py", line 315, in _async_render
    callback_return = await callback_return
IndexError: list index out of range
2019-08-02 09:55:04,700 - synapse.access.http.8008 - 302 - INFO - GET-654776- 127.0.0.1 - 8008 - {@xxxxx:matrix.parity.io} Processed request: 0.391sec/0.000sec (0.253sec, 0.030sec) (0.451sec/0.965sec/110) 67B 500 "GET /_matrix/client/r0/sync?filter=2&set_presence=offline&timeout=30000&since=s4595570_52728671_220931_4516767_2479108_3345_1584806_196913_331 HTTP/1.0" "Riot.im/0.9.3 (Linux; U; Android 9; SM-G975F Build/PPR1.180610.01; Flavour GooglePlay; MatrixAndroidSDK 0.9.26)" [0 dbevts]

@ara4n ara4n added z-bug (Deprecated Label) p1 labels Aug 6, 2019
@ara4n
Copy link
Member

ara4n commented Aug 6, 2019

...and parity now have another user being bitten by this.

erikjohnston added a commit that referenced this issue Aug 6, 2019
This hopefully addresses #5407 by gracefully handling an empty but
limited TimelineBatch. We also add some logging to figure out how this
is happening.
@erikjohnston
Copy link
Member

I've pushed #5825, which should a) fix this and b) add some logging to figure out how this comes about. It would be great if those that were bitten by this could keep an eye on their logs for the new logging, that would be greatly appreciated.

@erikjohnston
Copy link
Member

At least one cause of this appears to be that the syncing user has ignored the senders of all recent events. _load_filtered_recents will loop to attempt to fetch more events, but has a limit to stop it from spinning.

We could potentially handle this case better, but it doesn't particularly feel like an actual bug that this happens.

erikjohnston added a commit that referenced this issue Aug 19, 2019
anoadragon453 added a commit that referenced this issue Oct 3, 2019
Synapse 1.4.0 (2019-10-03)
==========================

Bugfixes
--------

- Redact `client_secret` in server logs. ([\#6158](#6158))

Synapse 1.4.0rc2 (2019-10-02)
=============================

Bugfixes
--------

- Fix bug in background update that adds last seen information to the `devices` table, and improve its performance on Postgres. ([\#6135](#6135))
- Fix bad performance of censoring redactions background task. ([\#6141](#6141))
- Fix fetching censored redactions from DB, which caused APIs like initial sync to fail if it tried to include the censored redaction. ([\#6145](#6145))
- Fix exceptions when storing large retry intervals for down remote servers. ([\#6146](#6146))

Internal Changes
----------------

- Fix up sample config entry for `redaction_retention_period` option. ([\#6117](#6117))

Synapse 1.4.0rc1 (2019-09-26)
=============================

Note that this release includes significant changes around 3pid
verification. Administrators are reminded to review the [upgrade notes](UPGRADE.rst#upgrading-to-v140).

Features
--------

- Changes to 3pid verification:
  - Add the ability to send registration emails from the homeserver rather than delegating to an identity server. ([\#5835](#5835), [\#5940](#5940), [\#5993](#5993), [\#5994](#5994), [\#5868](#5868))
  - Replace `trust_identity_server_for_password_resets` config option with `account_threepid_delegates`, and make the `id_server` parameteter optional on `*/requestToken` endpoints, as per [MSC2263](matrix-org/matrix-spec-proposals#2263). ([\#5876](#5876), [\#5969](#5969), [\#6028](#6028))
  - Switch to using the v2 Identity Service `/lookup` API where available, with fallback to v1. (Implements [MSC2134](matrix-org/matrix-spec-proposals#2134) plus `id_access_token authentication` for v2 Identity Service APIs from [MSC2140](matrix-org/matrix-spec-proposals#2140)). ([\#5897](#5897))
  - Remove `bind_email` and `bind_msisdn` parameters from `/register` ala [MSC2140](matrix-org/matrix-spec-proposals#2140). ([\#5964](#5964))
  - Add `m.id_access_token` to `unstable_features` in `/versions` as per [MSC2264](matrix-org/matrix-spec-proposals#2264). ([\#5974](#5974))
  - Use the v2 Identity Service API for 3PID invites. ([\#5979](#5979))
  - Add `POST /_matrix/client/unstable/account/3pid/unbind` endpoint from [MSC2140](matrix-org/matrix-spec-proposals#2140) for unbinding a 3PID from an identity server without removing it from the homeserver user account. ([\#5980](#5980), [\#6062](#6062))
  - Use `account_threepid_delegate.email` and `account_threepid_delegate.msisdn` for validating threepid sessions. ([\#6011](#6011))
  - Allow homeserver to handle or delegate email validation when adding an email to a user's account. ([\#6042](#6042))
  - Implement new Client Server API endpoints `/account/3pid/add` and `/account/3pid/bind` as per [MSC2290](matrix-org/matrix-spec-proposals#2290). ([\#6043](#6043))
  - Add an unstable feature flag for separate add/bind 3pid APIs. ([\#6044](#6044))
  - Remove `bind` parameter from Client Server POST `/account` endpoint as per [MSC2290](matrix-org/matrix-spec-proposals#2290). ([\#6067](#6067))
  - Add `POST /add_threepid/msisdn/submit_token` endpoint for proxying submitToken on an `account_threepid_handler`. ([\#6078](#6078))
  - Add `submit_url` response parameter to `*/msisdn/requestToken` endpoints. ([\#6079](#6079))
  - Add `m.require_identity_server` flag to /version's unstable_features. ([\#5972](#5972))
- Enhancements to OpenTracing support:
  - Make OpenTracing work in worker mode. ([\#5771](#5771))
  - Pass OpenTracing contexts between servers when transmitting EDUs. ([\#5852](#5852))
  - OpenTracing for device list updates. ([\#5853](#5853))
  - Add a tag recording a request's authenticated entity and corresponding servlet in OpenTracing. ([\#5856](#5856))
  - Add minimum OpenTracing for client servlets. ([\#5983](#5983))
  - Check at setup that OpenTracing is installed if it's enabled in the config. ([\#5985](#5985))
  - Trace replication send times. ([\#5986](#5986))
  - Include missing OpenTracing contexts in outbout replication requests. ([\#5982](#5982))
  - Fix sending of EDUs when OpenTracing is enabled with an empty whitelist. ([\#5984](#5984))
  - Fix invalid references to None while OpenTracing if the log context slips. ([\#5988](#5988), [\#5991](#5991))
  - OpenTracing for room and e2e keys. ([\#5855](#5855))
  - Add OpenTracing span over HTTP push processing. ([\#6003](#6003))
- Add an admin API to purge old rooms from the database. ([\#5845](#5845))
- Retry well-known lookups if we have recently seen a valid well-known record for the server. ([\#5850](#5850))
- Add support for filtered room-directory search requests over federation ([MSC2197](matrix-org/matrix-spec-proposals#2197), in order to allow upcoming room directory query performance improvements. ([\#5859](#5859))
- Correctly retry all hosts returned from SRV when we fail to connect. ([\#5864](#5864))
- Add admin API endpoint for setting whether or not a user is a server administrator. ([\#5878](#5878))
- Enable cleaning up extremities with dummy events by default to prevent undue build up of forward extremities. ([\#5884](#5884))
- Add config option to sign remote key query responses with a separate key. ([\#5895](#5895))
- Add support for config templating. ([\#5900](#5900))
- Users with the type of "support" or "bot" are no longer required to consent. ([\#5902](#5902))
- Let synctl accept a directory of config files. ([\#5904](#5904))
- Increase max display name size to 256. ([\#5906](#5906))
- Add admin API endpoint for getting whether or not a user is a server administrator. ([\#5914](#5914))
- Redact events in the database that have been redacted for a week. ([\#5934](#5934))
- New prometheus metrics:
  - `synapse_federation_known_servers`: represents the total number of servers your server knows about (i.e. is in rooms with), including itself. Enable by setting `metrics_flags.known_servers` to True in the configuration.([\#5981](#5981))
  - `synapse_build_info`: exposes the Python version, OS version, and Synapse version of the running server. ([\#6005](#6005))
- Give appropriate exit codes when synctl fails. ([\#5992](#5992))
- Apply the federation blacklist to requests to identity servers. ([\#6000](#6000))
- Add `report_stats_endpoint` option to configure where stats are reported to, if enabled. Contributed by @Sorunome. ([\#6012](#6012))
- Add config option to increase ratelimits for room admins redacting messages. ([\#6015](#6015))
- Stop sending federation transactions to servers which have been down for a long time. ([\#6026](#6026))
- Make the process for mapping SAML2 users to matrix IDs more flexible. ([\#6037](#6037))
- Return a clearer error message when a timeout occurs when attempting to contact an identity server. ([\#6073](#6073))
- Prevent password reset's submit_token endpoint from accepting trailing slashes. ([\#6074](#6074))
- Return 403 on `/register/available` if registration has been disabled. ([\#6082](#6082))
- Explicitly log when a homeserver does not have the `trusted_key_servers` config field configured. ([\#6090](#6090))
- Add support for pruning old rows in `user_ips` table. ([\#6098](#6098))

Bugfixes
--------

- Don't create broken room when `power_level_content_override.users` does not contain `creator_id`. ([\#5633](#5633))
- Fix database index so that different backup versions can have the same sessions. ([\#5857](#5857))
- Fix Synapse looking for config options `password_reset_failure_template` and `password_reset_success_template`, when they are actually `password_reset_template_failure_html`, `password_reset_template_success_html`. ([\#5863](#5863))
- Fix stack overflow when recovering an appservice which had an outage. ([\#5885](#5885))
- Fix error message which referred to `public_base_url` instead of `public_baseurl`. Thanks to @aaronraimist for the fix! ([\#5909](#5909))
- Fix 404 for thumbnail download when `dynamic_thumbnails` is `false` and the thumbnail was dynamically generated. Fix reported by rkfg. ([\#5915](#5915))
- Fix a cache-invalidation bug for worker-based deployments. ([\#5920](#5920))
- Fix admin API for listing media in a room not being available with an external media repo. ([\#5966](#5966))
- Fix list media admin API always returning an error. ([\#5967](#5967))
- Fix room and user stats tracking. ([\#5971](#5971), [\#5998](#5998), [\#6029](#6029))
- Return a `M_MISSING_PARAM` if `sid` is not provided to `/account/3pid`. ([\#5995](#5995))
- `federation_certificate_verification_whitelist` now will not cause `TypeErrors` to be raised (a regression in 1.3). Additionally, it now supports internationalised domain names in their non-canonical representation. ([\#5996](#5996))
- Only count real users when checking for auto-creation of auto-join room. ([\#6004](#6004))
- Ensure support users can be registered even if MAU limit is reached. ([\#6020](#6020))
- Fix bug where login error was shown incorrectly on SSO fallback login. ([\#6024](#6024))
- Fix bug in calculating the federation retry backoff period. ([\#6025](#6025))
- Prevent exceptions being logged when extremity-cleanup events fail due to lack of user consent to the terms of service. ([\#6053](#6053))
- Remove POST method from password-reset `submit_token` endpoint until we implement `submit_url` functionality. ([\#6056](#6056))
- Fix logcontext spam on non-Linux platforms. ([\#6059](#6059))
- Ensure query parameters in email validation links are URL-encoded. ([\#6063](#6063))
- Fix a bug which caused SAML attribute maps to be overridden by defaults. ([\#6069](#6069))
- Fix the logged number of updated items for the `users_set_deactivated_flag` background update. ([\#6092](#6092))
- Add `sid` to `next_link` for email validation. ([\#6097](#6097))
- Threepid validity checks on msisdns should not be dependent on `threepid_behaviour_email`. ([\#6104](#6104))
- Ensure that servers which are not configured to support email address verification do not offer it in the registration flows. ([\#6107](#6107))

Updates to the Docker image
---------------------------

- Avoid changing `UID/GID` if they are already correct. ([\#5970](#5970))
- Provide `SYNAPSE_WORKER` envvar to specify python module. ([\#6058](#6058))

Improved Documentation
----------------------

- Convert documentation to markdown (from rst) ([\#5849](#5849))
- Update `INSTALL.md` to say that Python 2 is no longer supported. ([\#5953](#5953))
- Add developer documentation for using SAML2. ([\#6032](#6032))
- Add some notes on rolling back to v1.3.1. ([\#6049](#6049))
- Update the upgrade notes. ([\#6050](#6050))

Deprecations and Removals
-------------------------

- Remove shared-secret registration from `/_matrix/client/r0/register` endpoint. Contributed by Awesome Technologies Innovationslabor GmbH. ([\#5877](#5877))
- Deprecate the `trusted_third_party_id_servers` option. ([\#5875](#5875))

Internal Changes
----------------

- Lay the groundwork for structured logging output. ([\#5680](#5680))
- Retry well-known lookup before the cache expires, giving a grace period where the remote well-known can be down but we still use the old result. ([\#5844](#5844))
- Remove log line for debugging issue #5407. ([\#5860](#5860))
- Refactor the Appservice scheduler code. ([\#5886](#5886))
- Compatibility with v2 Identity Service APIs other than /lookup. ([\#5892](#5892), [\#6013](#6013))
- Stop populating some unused tables. ([\#5893](#5893), [\#6047](#6047))
- Add missing index on `users_in_public_rooms` to improve the performance of directory queries. ([\#5894](#5894))
- Improve the logging when we have an error when fetching signing keys. ([\#5896](#5896))
- Add support for database engine-specific schema deltas, based on file extension. ([\#5911](#5911))
- Update Buildkite pipeline to use plugins instead of buildkite-agent commands. ([\#5922](#5922))
- Add link in sample config to the logging config schema. ([\#5926](#5926))
- Remove unnecessary parentheses in return statements. ([\#5931](#5931))
- Remove unused `jenkins/prepare_sytest.sh` file. ([\#5938](#5938))
- Move Buildkite pipeline config to the pipelines repo. ([\#5943](#5943))
- Remove unnecessary return statements in the codebase which were the result of a regex run. ([\#5962](#5962))
- Remove left-over methods from v1 registration API. ([\#5963](#5963))
- Cleanup event auth type initialisation. ([\#5975](#5975))
- Clean up dependency checking at setup. ([\#5989](#5989))
- Update OpenTracing docs to use the unified `trace` method. ([\#5776](#5776))
- Small refactor of function arguments and docstrings in` RoomMemberHandler`. ([\#6009](#6009))
- Remove unused `origin` argument on `FederationHandler.add_display_name_to_third_party_invite`. ([\#6010](#6010))
- Add a `failure_ts` column to the `destinations` database table. ([\#6016](#6016), [\#6072](#6072))
- Clean up some code in the retry logic. ([\#6017](#6017))
- Fix the structured logging tests stomping on the global log configuration for subsequent tests. ([\#6023](#6023))
- Clean up the sample config for SAML authentication. ([\#6064](#6064))
- Change mailer logging to reflect Synapse doesn't just do chat notifications by email now. ([\#6075](#6075))
- Move last-seen info into devices table. ([\#6089](#6089))
- Remove unused parameter to `get_user_id_by_threepid`. ([\#6099](#6099))
- Refactor the user-interactive auth handling. ([\#6105](#6105))
- Refactor code for calculating registration flows. ([\#6106](#6106))
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
z-bug (Deprecated Label)
Projects
None yet
Development

No branches or pull requests

6 participants