Synapse: Failed to handle EDU of type 'm.receipt': argument of type 'ObservableDeferred' is not iterable

Created on 18 May 2018  路  10Comments  路  Source: matrix-org/synapse

Infrequent in appearance (only saw it a couple times while watching the logs for ~5min)

homeserver - 2018-05-18 00:40:04,123 - synapse.federation.federation_server - 643 - ERROR - Failed to handle edu 'm.receipt'
Traceback (most recent call last):
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/synapse/federation/federation_server.py", line 639, in on_edu
    yield handler(origin, content)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1384, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/python/failure.py", line 422, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/synapse/handlers/receipts.py", line 84, in _received_remote_receipt
    yield self._handle_new_receipts(receipts)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1384, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/python/failure.py", line 422, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/synapse/handlers/receipts.py", line 101, in _handle_new_receipts
    room_id, receipt_type, user_id, event_ids, data
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1384, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/python/failure.py", line 422, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/synapse/storage/receipts.py", line 456, in insert_receipt
    stream_id=stream_id,
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1386, in _inlineCallbacks
    result = g.send(result)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/synapse/storage/_base.py", line 323, in runInteraction
    after_callback(*after_args, **after_kwargs)
  File "/home/matrix/.synapse/local/lib/python2.7/site-packages/synapse/storage/receipts.py", line 308, in _invalidate_get_users_with_receipts_in_room
    if user_id in res:
TypeError: argument of type 'ObservableDeferred' is not iterable

Version

Synapse 0.29.1 with patches: https://github.com/matrix-org/synapse/compare/master...turt2live:travis/t2bot.io
Domain: t2bot.io

Related issues

The stack trace shows up in https://github.com/matrix-org/synapse/issues/3188

bug p2
Source
picture turt2live
👍1

All 10 comments

As per #3235, this was introduced in #2158

richvdh picture richvdh on 18 May 2018

Closing because https://github.com/matrix-org/synapse/pull/3235 has been merged.

turt2live picture turt2live on 18 May 2018

I just got the following on 0.33.3:

synapse.federation.federation_server - 802 - ERROR - [PUT-68] Failed to handle edu u'm.receipt'
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/synapse/federation/federation_server.py", line 798, in on_edu
    yield handler(origin, content)
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/synapse/handlers/receipts.py", line 81, in _received_remote_receipt
    yield self._handle_new_receipts(receipts)
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/synapse/handlers/receipts.py", line 98, in _handle_new_receipts
    room_id, receipt_type, user_id, event_ids, data
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/synapse/storage/receipts.py", line 474, in insert_receipt
    stream_id=stream_id,
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/usr/lib/python2.7/site-packages/synapse/storage/_base.py", line 328, in runInteraction
    after_callback(*after_args, **after_kwargs)
  File "/usr/lib/python2.7/site-packages/synapse/storage/receipts.py", line 326, in _invalidate_get_users_with_receipts_in_room
    if res and user_id in res:
TypeError: argument of type 'ObservableDeferred' is not iterable
kyrias picture kyrias on 24 Aug 2018

Just chiming in that this is still happening in 0.99.3

Apr 06 16:25:46 ubuntu systemd[1]: matrix-synapse.service: Main process exited, code=exited, status=137/n/a
Apr 06 16:25:46 ubuntu systemd[1]: matrix-synapse.service: Failed with result 'exit-code'.
Apr 06 16:26:16 ubuntu systemd[1]: matrix-synapse.service: Service hold-off time over, scheduling restart.
Apr 06 16:26:16 ubuntu systemd[1]: matrix-synapse.service: Scheduled restart job, restart counter is at 1.
Apr 06 16:26:16 ubuntu systemd[1]: Stopped Matrix Synapse server.
Apr 06 16:26:16 ubuntu systemd[1]: Starting Matrix Synapse server...
Apr 06 16:26:17 ubuntu docker[30834]: Error response from daemon: Cannot kill container: matrix-synapse: No such container: matrix-synapse
Apr 06 16:26:17 ubuntu docker[30920]: Error: No such container: matrix-synapse
Apr 06 16:26:17 ubuntu systemd[1]: Started Matrix Synapse server.
Apr 06 16:26:24 ubuntu docker[30927]: 2019-04-06 16:26:24,196 - root - 211 - WARNING - None - ***** STARTING SERVER *****
Apr 06 16:26:24 ubuntu docker[30927]: 2019-04-06 16:26:24,207 - root - 214 - WARNING - None - Server /usr/local/lib/python3.6/site-packages/synapse/app/homeserver.py version 0.99.3
Apr 06 16:26:52 ubuntu docker[30927]: 2019-04-06 16:26:52,934 - synapse.federation.federation_server - 857 - ERROR - PUT-57 - Failed to handle edu 'm.receipt'
Apr 06 16:26:52 ubuntu docker[30927]: Traceback (most recent call last):
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Apr 06 16:26:52 ubuntu docker[30927]:     result = g.send(result)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/storage/_base.py", line 460, in runWithConnection
Apr 06 16:26:52 ubuntu docker[30927]:     defer.returnValue(result)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Apr 06 16:26:52 ubuntu docker[30927]:     raise _DefGen_Return(val)
Apr 06 16:26:52 ubuntu docker[30927]: twisted.internet.defer._DefGen_Return: 0
Apr 06 16:26:52 ubuntu docker[30927]: During handling of the above exception, another exception occurred:
Apr 06 16:26:52 ubuntu docker[30927]: Traceback (most recent call last):
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/federation/federation_server.py", line 853, in on_edu
Apr 06 16:26:52 ubuntu docker[30927]:     yield handler(origin, content)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
Apr 06 16:26:52 ubuntu docker[30927]:     result = result.throwExceptionIntoGenerator(g)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
Apr 06 16:26:52 ubuntu docker[30927]:     return g.throw(self.type, self.value, self.tb)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/handlers/receipts.py", line 56, in _received_remote_receipt
Apr 06 16:26:52 ubuntu docker[30927]:     yield self._handle_new_receipts(receipts)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
Apr 06 16:26:52 ubuntu docker[30927]:     result = result.throwExceptionIntoGenerator(g)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
Apr 06 16:26:52 ubuntu docker[30927]:     return g.throw(self.type, self.value, self.tb)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/handlers/receipts.py", line 71, in _handle_new_receipts
Apr 06 16:26:52 ubuntu docker[30927]:     receipt.data,
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
Apr 06 16:26:52 ubuntu docker[30927]:     result = result.throwExceptionIntoGenerator(g)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
Apr 06 16:26:52 ubuntu docker[30927]:     return g.throw(self.type, self.value, self.tb)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/storage/receipts.py", line 484, in insert_receipt
Apr 06 16:26:52 ubuntu docker[30927]:     stream_id=stream_id,
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Apr 06 16:26:52 ubuntu docker[30927]:     result = g.send(result)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/storage/_base.py", line 412, in runInteraction
Apr 06 16:26:52 ubuntu docker[30927]:     after_callback(*after_args, **after_kwargs)
Apr 06 16:26:52 ubuntu docker[30927]:   File "/usr/local/lib/python3.6/site-packages/synapse/storage/receipts.py", line 328, in _invalidate_get_users_with_receipts_in_room
Apr 06 16:26:52 ubuntu docker[30927]:     if res and user_id in res:
Apr 06 16:26:52 ubuntu docker[30927]: TypeError: argument of type 'ObservableDeferred' is not iterable
aaronraimist picture aaronraimist on 6 Apr 2019

Just found this issue in 1.9.0RC1.

2020-01-23 05:43:38,857 - synapse.federation.federation_server - 834 - ERROR - PUT-21293- Failed to handle edu 'm.receipt'
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: 1576701246047

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/synapse/federation/federation_server.py", line 830, in on_edu
    await handler(origin, content)
  File "/usr/local/lib/python3.7/dist-packages/synapse/handlers/receipts.py", line 65, in _received_remote_receipt
    await self._handle_new_receipts(receipts)
  File "/usr/local/lib/python3.7/dist-packages/synapse/handlers/receipts.py", line 79, in _handle_new_receipts
    receipt.data,
  File "/usr/local/lib/python3.7/dist-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/local/lib/python3.7/dist-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/local/lib/python3.7/dist-packages/synapse/storage/data_stores/main/receipts.py", line 473, in insert_receipt
    stream_id=stream_id,
  File "/usr/local/lib/python3.7/dist-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/usr/local/lib/python3.7/dist-packages/synapse/storage/database.py", line 499, in runInteraction
TypeError: argument of type 'ObservableDeferred' is not iterable    after_callback(*after_args, **after_kwargs)
  File "/usr/local/lib/python3.7/dist-packages/synapse/storage/data_stores/main/receipts.py", line 310, in _invalidate_get_users_with_receipts_in_room
    if res and user_id in res:
TypeError: argument of type 'ObservableDeferred' is not iterable
mvgorcum picture mvgorcum on 23 Jan 2020
👍1

Bug still present in 1.10.1

synapse_1  | 2020-02-17 16:50:18,679 - synapse.access.http.8008 - 233 - INFO - PUT-168940 - redacted  - 8008 - Received request: PUT /_matrix/federation/v1/send/1581438988263/
synapse_1  | 2020-02-17 16:50:18,680 - synapse.federation.transport.server - 161 - INFO - PUT-168940 - Request from matrix.org
synapse_1  | 2020-02-17 16:50:18,680 - synapse.federation.transport.server - 406 - INFO - PUT-168940 - Received txn 1581438988263 from matrix.org. (PDUs: 1, EDUs: 1)
synapse_1  | 2020-02-17 16:50:18,683 - synapse.handlers.federation - 190 - INFO - PUT-168940-$LTixwI3IJYrHruOEpI4gHCE78l1MN4UjMtPWGhS6734 - handling received PDU: <FrozenEventV3 event_id='$LTixwI3IJYrHruOEpI4gHCE78l1MN4UjMtPWGhS6734', type='m.room.member', state_key='@gifzly:matrix.org'>
synapse_1  | 2020-02-17 16:50:18,699 - synapse.federation.federation_server - 834 - ERROR - PUT-168940 - Failed to handle edu 'm.receipt'
synapse_1  | Traceback (most recent call last):
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
synapse_1  |     result = g.send(result)
synapse_1  | StopIteration
synapse_1  | 
synapse_1  | During handling of the above exception, another exception occurred:
synapse_1  | 
synapse_1  | Traceback (most recent call last):
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/synapse/federation/federation_server.py", line 830, in on_edu
synapse_1  |     await handler(origin, content)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/synapse/handlers/receipts.py", line 65, in _received_remote_receipt
synapse_1  |     await self._handle_new_receipts(receipts)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/synapse/handlers/receipts.py", line 79, in _handle_new_receipts
synapse_1  |     receipt.data,
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
synapse_1  |     result = result.throwExceptionIntoGenerator(g)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
synapse_1  |     return g.throw(self.type, self.value, self.tb)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/synapse/storage/data_stores/main/receipts.py", line 487, in insert_receipt
synapse_1  |     yield self.insert_graph_receipt(room_id, receipt_type, user_id, event_ids, data)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
synapse_1  |     result = g.send(result)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/synapse/storage/database.py", line 499, in runInteraction
synapse_1  |     after_callback(*after_args, **after_kwargs)
synapse_1  |   File "/usr/local/lib/python3.7/site-packages/synapse/storage/data_stores/main/receipts.py", line 310, in _invalidate_get_users_with_receipts_in_room
synapse_1  |     if res and user_id in res:
synapse_1  | TypeError: argument of type 'ObservableDeferred' is not iterable
Maescool picture Maescool on 17 Feb 2020

I see this occasionally on sw1v.org too...

richvdh picture richvdh on 24 Apr 2020 
2020-05-25T11:14:29.721612767Z Traceback (most recent call last):
2020-05-25T11:14:29.721616225Z   File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
2020-05-25T11:14:29.721619383Z     result = g.send(result)
2020-05-25T11:14:29.721622035Z StopIteration
2020-05-25T11:14:29.721624454Z
2020-05-25T11:14:29.721627126Z During handling of the above exception, another exception occurred:
2020-05-25T11:14:29.721629977Z
2020-05-25T11:14:29.721632344Z Traceback (most recent call last):
2020-05-25T11:14:29.721634990Z   File "/usr/local/lib/python3.7/site-packages/synapse/http/server.py", line 78, in wrapped_request_handler
2020-05-25T11:14:29.721637640Z     await h(self, request)
2020-05-25T11:14:29.721640217Z   File "/usr/local/lib/python3.7/site-packages/synapse/http/server.py", line 331, in _async_render
2020-05-25T11:14:29.721642769Z     callback_return = await callback_return
2020-05-25T11:14:29.721645526Z   File "/usr/local/lib/python3.7/site-packages/synapse/rest/client/v2_alpha/read_marker.py", line 48, in on_POST
2020-05-25T11:14:29.721655443Z     event_id=read_event_id,
2020-05-25T11:14:29.721657839Z   File "/usr/local/lib/python3.7/site-packages/synapse/handlers/receipts.py", line 121, in received_client_receipt
2020-05-25T11:14:29.721660169Z     is_new = await self._handle_new_receipts([receipt])
2020-05-25T11:14:29.721662369Z   File "/usr/local/lib/python3.7/site-packages/synapse/handlers/receipts.py", line 79, in _handle_new_receipts
2020-05-25T11:14:29.721664820Z     receipt.data,
2020-05-25T11:14:29.721667094Z   File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
2020-05-25T11:14:29.721669398Z     result = result.throwExceptionIntoGenerator(g)
2020-05-25T11:14:29.721671544Z   File "/usr/local/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
2020-05-25T11:14:29.721674122Z     return g.throw(self.type, self.value, self.tb)
2020-05-25T11:14:29.721676219Z   File "/usr/local/lib/python3.7/site-packages/synapse/storage/data_stores/main/receipts.py", line 487, in insert_receipt
2020-05-25T11:14:29.721678522Z     yield self.insert_graph_receipt(room_id, receipt_type, user_id, event_ids, data)
2020-05-25T11:14:29.721680769Z   File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
2020-05-25T11:14:29.721683005Z     result = g.send(result)
2020-05-25T11:14:29.721685862Z   File "/usr/local/lib/python3.7/site-packages/synapse/storage/database.py", line 539, in runInteraction
2020-05-25T11:14:29.721688105Z     after_callback(*after_args, **after_kwargs)
2020-05-25T11:14:29.721690262Z   File "/usr/local/lib/python3.7/site-packages/synapse/storage/data_stores/main/receipts.py", line 310, in _invalidate_get_users_with_receipts_in_room
2020-05-25T11:14:29.721692563Z     if res and user_id in res:
2020-05-25T11:14:29.721694654Z TypeError: argument of type 'ObservableDeferred' is not iterable
SuperSandro2000 picture SuperSandro2000 on 25 May 2020

the problem is here: https://github.com/matrix-org/synapse/blob/v1.15.0/synapse/storage/data_stores/main/receipts.py#L304

ObservableDeferred is not a subclass of defer.Deferred so the condition doesn't work

richvdh picture richvdh on 16 Jun 2020
👍1

This seems to happen quite often on matrix.org. I took a try at fixing it.

clokep picture clokep on 16 Jun 2020
Was this page helpful?
0 / 5 - 0 ratings

Related issues

ukcb picture ukcb  路  4Comments
WGH- picture WGH-  路  4Comments
williamkray picture williamkray  路  3Comments
flaki picture flaki  路  4Comments
ptman picture ptman  路  3Comments