Event with `m.relates_to: null` causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

progserega · 2019-06-09T03:07:06Z

Description

After update to homeserver.py version 0.99.5.2 - in logs I get errors:

      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
        return g.throw(self.type, self.value, self.tb)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/util/metrics.py", line 63, in measured_func
        r = yield func(self, *args, **kwargs)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
        result = g.send(result)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/handlers/message.py", line 608, in create_new_client_event
        if relation.get("rel_type") == RelationTypes.ANNOTATION:
    AttributeError: 'NoneType' object has no attribute 'get'

error.log

Version information

deb packet: matrix-synapse-py3 0.99.5.2+stretch1 amd64
Debian 9.8
LXC container.

The text was updated successfully, but these errors were encountered:

silkeh · 2019-06-12T19:29:01Z

Seeing this on 1.0.0 as well. Possibly introduced in #5212?

richvdh · 2019-06-27T10:55:57Z

I see this happens when you try to send an event. What is the body of the event you are sending?

progserega · 2019-06-29T23:13:02Z

I do not know.
On new server I got (may be this is other error...):

    2019-06-30 08:02:18,475 - synapse.access.http.8008 - 233 - INFO - GET-2520523- ::1 - 8008 - Received request: GET /_matrix/media/v1/thumbnail/rsprim.ru/bDSYwzHrPnqHMQXWHXgfzIgf?width=40&height=40&method=crop
    2019-06-30 08:02:18,480 - synapse.http.site - 203 - WARNING - GET-2520523- Error processing request <SynapseRequest at 0x7fb76d5e1160 method='GET' uri='/_matrix/media/v1/thumbnail/rsprim.ru/bDSYwzHrPnqHMQXWHXgfzIgf?width=40&height=40&method=crop' clientproto='HTTP/1.0' site=8008>: <class 'twisted.internet.error.C    __onnectionDone'> Connection was closed cleanly.
    2019-06-30 08:02:18,481 - synapse.access.http.8008 - 233 - INFO - GET-2520524- 127.0.0.1 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=3&timeout=30000&since=s832087_40098896_16971_1423230_276637_1059_25628_174542_407
    2019-06-30 08:02:18,482 - synapse.util.caches.response_cache - 151 - INFO - GET-2520524- [sync]: no cached result for [(@svc_disp_340-00:rsprim.ru, 30000, 's832087_40098896_16971_1423230_276637_1059_25628_174542_407', '3', False, 'YKYJJDGEYD')], calculating new one
    2019-06-30 08:02:18,485 - synapse.rest.media.v1._base - 192 - WARNING - GET-2520523- Failed to write to consumer: <class 'AttributeError'> 'NoneType' object has no attribute 'registerProducer'
    2019-06-30 08:02:18,486 - synapse.http.server - 112 - ERROR - GET-2520523- Failed handle request via 'ThumbnailResource': <SynapseRequest at 0x7fb76d5e1160 method='GET' uri='/_matrix/media/v1/thumbnail/rsprim.ru/bDSYwzHrPnqHMXXWHQgfzIgf?width=40&height=40&method=crop' clientproto='HTTP/1.0' site=8008>
    Traceback (most recent call last):
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
        result = g.send(result)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/storage/_base.py", line 527, in runWithConnection
        defer.returnValue(result)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
        raise _DefGen_Return(val)
    twisted.internet.defer._DefGen_Return: [{'thumbnail_width': 320, 'thumbnail_length': 5353, 'thumbnail_height': 51, 'thumbnail_method': 'scale', 'thumbnail_type': 'image/jpeg'}, {'thumbnail_width': 96, 'thumbnail_length': 4181, 'thumbnail_height': 96, 'thumbnail_method': 'crop', 'thumbnail_type': 'image/jpeg'}, {'    __thumbnail_width': 800, 'thumbnail_length': 19420, 'thumbnail_height': 129, 'thumbnail_method': 'scale', 'thumbnail_type': 'image/jpeg'}, {'thumbnail_width': 32, 'thumbnail_length': 1122, 'thumbnail_height': 32, 'thumbnail_method': 'crop', 'thumbnail_type': 'image/jpeg'}, {'thumbnail_width': 640, 'thumbnail_leng    __th': 14015, 'thumbnail_height': 103, 'thumbnail_method': 'scale', 'thumbnail_type': 'image/jpeg'}]
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last): 
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
        result = g.send(result)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/storage/_base.py", line 487, in runInteraction
        defer.returnValue(result)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
        raise _DefGen_Return(val)
    twisted.internet.defer._DefGen_Return: [{'thumbnail_width': 320, 'thumbnail_length': 5353, 'thumbnail_height': 51, 'thumbnail_method': 'scale', 'thumbnail_type': 'image/jpeg'}, {'thumbnail_width': 96, 'thumbnail_length': 4181, 'thumbnail_height': 96, 'thumbnail_method': 'crop', 'thumbnail_type': 'image/jpeg'}, {'    __thumbnail_width': 800, 'thumbnail_length': 19420, 'thumbnail_height': 129, 'thumbnail_method': 'scale', 'thumbnail_type': 'image/jpeg'}, {'thumbnail_width': 32, 'thumbnail_length': 1122, 'thumbnail_height': 32, 'thumbnail_method': 'crop', 'thumbnail_type': 'image/jpeg'}, {'thumbnail_width': 640, 'thumbnail_leng    __th': 14015, 'thumbnail_height': 103, 'thumbnail_method': 'scale', 'thumbnail_type': 'image/jpeg'}]
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last): 
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/_base.py", line 187, in respond_with_responder
        yield responder.write_to_consumer(request)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/media_storage.py", line 263, in write_to_consumer
        FileSender().beginFileTransfer(self.open_file, consumer)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/protocols/basic.py", line 923, in beginFileTransfer
        self.consumer.registerProducer(self, False) 
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/web/http.py", line 961, in registerProducer
        self.channel.registerProducer(producer, streaming)
    AttributeError: 'NoneType' object has no attribute 'registerProducer'
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last): 
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
        yield h(self, request)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 71, in _async_render_GET
        request, media_id, width, height, method, m_type 
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 121, in _respond_local_thumbnail
        yield respond_with_responder(request, responder, t_type, t_length)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
        result = g.send(result)
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/_base.py", line 196, in respond_with_responder
        request.unregisterProducer()
      File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/web/http.py", line 967, in unregisterProducer
        self.channel.unregisterProducer()
    AttributeError: 'NoneType' object has no attribute 'unregisterProducer'
    2019-06-30 08:02:18,501 - synapse.http.server - 415 - WARNING - GET-2520523- Not sending response to request <SynapseRequest at 0x7fb76d5e1160 method='GET' uri='/_matrix/media/v1/thumbnail/rsprim.ru/bDSYwzHrPnqHMQXWHXgfzIgf?width=40&height=40&method=crop' clientproto='HTTP/1.0' site=8008>, already disconnected.
    2019-06-30 08:02:18,501 - synapse.access.http.8008 - 302 - INFO - GET-2520523- ::1 - 8008 - {None} Processed request: 0.026sec/-0.021sec (0.003sec, 0.001sec) (0.001sec/0.003sec/2) 0B 200! "GET /_matrix/media/v1/thumbnail/rsprim.ru/bDSYwzHrPnqHMXXWHQgfzIgf?width=40&height=40&method=crop HTTP/1.0" "Mozilla/5.0 (Win    __dows NT 10.0; Win64; x64; rv:67.0) Gecko/20100101 Firefox/67.0" [0 dbevts]
    2019-06-30 08:02:18,502 - synapse.metrics - 372 - INFO - - Collecting gc 0

progserega · 2019-06-29T23:14:43Z

I think last error occur when user try get big image (more then 4000x4000 pixels).

richvdh · 2019-06-30T20:16:51Z

On new server I got (may be this is other error...):

yes, it seems to be unrelated, and probably #5304.

WGH- · 2019-07-15T09:14:39Z

At least one third-party bridge sends such events, and it used to work. It was broken in some Synapse update, hence it's certainly a regression.

mautrix/telegram#336 this bridge has already worked around this problem, though

richvdh · 2019-07-15T09:32:45Z

@WGH-: please can you share an example of an event that causes this problem?

WGH- · 2019-07-15T09:44:13Z

I think an example of such event is provided in the opening message of the linked issue. Here's copy-paste: [2019-06-15 21:32:07,871] [DEBUG@mau.as.api] PUT /room/%21mMWGhycXzeDvpkjCzk%3Aroom409.xyz/send/m.room.message/61560634327871 {"body": "Forever", "msgtype": "m.text", "m.relates_to": null, "external_url": "https://t.me/c /1050980458/48908"} as user @telegram_163061100:room409.xyz

…

On July 15, 2019 12:32:55 PM GMT+03:00, Richard van der Hoff ***@***.***> wrote: @WGH-: please can you share an example of an event that causes this problem?

richvdh · 2019-07-15T11:12:58Z

thanks

richvdh · 2019-07-15T11:16:05Z

It's unclear to me what the correct behaviour is here. I've raised https://github.com/matrix-org/matrix-doc/issues/2178 to track

WGH- · 2019-07-15T11:21:01Z

Disclaimer: I'm not a developer of said bridge, and I took "It's a bug in synapse" (mentioned in that ticket) for granted. Maybe it's something more complicated.

This is the commits that seem to be related to it:
mautrix/telegram@1693b64
mautrix/python@f6064bc

richvdh · 2019-07-15T11:32:33Z

It's clear that returning a 500 and logging a stacktrace is not the correct behaviour. As per the matrix-doc issue, there is scope to debate whether the correct behaviour is to treat the event as invalid and return a 400, or to ignore the invalid m.relates_to.

richvdh · 2022-10-13T12:40:05Z

Possibly fixed by #11161? Though possibly fixed incorrectly, as the MSC says it should cause a 400 and #11161 makes it be ignored?

neilisfragile added z-bug (Deprecated Label) z-p2 (Deprecated Label) labels Jun 13, 2019

richvdh changed the title ~~AttributeError: 'NoneType' object has no attribute 'get'~~ Event annotations: AttributeError: 'NoneType' object has no attribute 'get' Jun 27, 2019

richvdh changed the title ~~Event annotations: AttributeError: 'NoneType' object has no attribute 'get'~~ Event with m.relates_to: null causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') Jul 15, 2019

This was referenced Mar 1, 2022

spec does not say that invalid m.relates_to properties are rejected matrix-org/matrix-spec#504

Open

Attempting to post a reaction without a key returns a 500 #10120

Open

MadLittleMods added A-Media-Repository Uploading, downloading images and video, thumbnailing T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues. labels Jun 10, 2022

matrixbot mentioned this issue Dec 21, 2023

Event with m.relates_to: null causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') element-hq/synapse#5404

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Event with `m.relates_to: null` causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

Event with `m.relates_to: null` causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

progserega commented Jun 9, 2019

silkeh commented Jun 12, 2019

richvdh commented Jun 27, 2019

progserega commented Jun 29, 2019

progserega commented Jun 29, 2019

richvdh commented Jun 30, 2019

WGH- commented Jul 15, 2019

richvdh commented Jul 15, 2019

WGH- commented Jul 15, 2019 via email •

edited

Loading

richvdh commented Jul 15, 2019

richvdh commented Jul 15, 2019

WGH- commented Jul 15, 2019

richvdh commented Jul 15, 2019

richvdh commented Oct 13, 2022

Event with m.relates_to: null causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

Event with m.relates_to: null causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

Comments

progserega commented Jun 9, 2019

Description

Version information

silkeh commented Jun 12, 2019

richvdh commented Jun 27, 2019

progserega commented Jun 29, 2019

progserega commented Jun 29, 2019

richvdh commented Jun 30, 2019

WGH- commented Jul 15, 2019

richvdh commented Jul 15, 2019

WGH- commented Jul 15, 2019 via email • edited Loading

richvdh commented Jul 15, 2019

richvdh commented Jul 15, 2019

WGH- commented Jul 15, 2019

richvdh commented Jul 15, 2019

richvdh commented Oct 13, 2022

Event with `m.relates_to: null` causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

Event with `m.relates_to: null` causes 500 error (AttributeError: 'NoneType' object has no attribute 'get') #5404

WGH- commented Jul 15, 2019 via email •

edited

Loading