signal
signal copied to clipboard
mautrix
Multiple images sent as one message only show one image
When receiving multiple images as a gallery, I only see one image, and don't see the text associated either.
In matrix:
In Signal:
The logs show that a couple of things fail - including an FileNotFoundError error. I've attached the logs below - I've tried to remove any identifying or sensitive data, but please let me know if there's anything further in these logs that should be redacted.
bridge-signal_1 | [2022-08-01 03:44:15,307] [[email protected]] get_by_chat_id(Address(number='+XXX', uuid=UUID('XXX')), +XXX) -> 0x7ff4a5be4c40
bridge-signal_1 | [2022-08-01 03:44:15,309] [[email protected]] Started handling message 1659325455367 by XXX
bridge-signal_1 | [2022-08-01 03:44:15,311] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3356: POST https://matrix.at.alexmaras.com/_matrix/media/v3/upload?filename=PJwSlvZjc_WZiv6ja7Q7&user_id=@signal_XXX:matrix.at.alexmaras.com <851071 bytes>
bridge-signal_1 | [2022-08-01 03:44:15,366] [[email protected]] get_by_chat_id(Address(number=None, uuid=UUID('XXX')), +XXX) -> 0x7ff4a5b5a500
bridge-signal_1 | [2022-08-01 03:44:15,368] [[email protected]] Started handling message 1659325455367 by XXX
bridge-signal_1 | [2022-08-01 03:44:15,369] [[email protected]] Failed to bridge attachment, no incoming filename: Attachment(width=1053, height=1062, caption=None, preview=None, blurhash='LRK18W-m~UWU^YIWR*t7~6NHM{jY', voice_note=False, content_type='image/png', custom_filename=None, id='PJwSlvZjc_WZiv6ja7Q7', incoming_filename=None, digest='ETqbdKuDMcS1JOkEs9p1N1sA1qbZ9CEbBq0KSCrQdrQ=', size=851071, outgoing_filename=None)
bridge-signal_1 | [2022-08-01 03:44:15,370] [[email protected].@eggie:matrix.at.alexmaras.com] req #3357: POST https://matrix.at.alexmaras.com/_matrix/media/v3/upload?filename=v3NNKUGb7XxoP4FrIfC0 <15027 bytes>
bridge-signal_1 | [2022-08-01 03:44:15,731] [[email protected].@eggie:matrix.at.alexmaras.com] req #3357 (/_matrix/media/v3/upload) completed in 360.6ms with status 200
bridge-signal_1 | [2022-08-01 03:44:15,736] [[email protected].@eggie:matrix.at.alexmaras.com] req #3358: PUT https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/send/m.room.message/mautrix-python_1659325455736494606_20?ts=1659325455367 {"msgtype": "m.image", "body": "v3NNKUGb7XxoP4FrIfC0.jpg", "url": "mxc://matrix.at.alexmaras.com/FxFfpbwLnNSpvcEJyTJsSWip", "info": {"mimetype": "image/jpeg", "size": 15027, "thumbnail_url": "mxc://matrix.at.alexmaras.com/FxFfpbwLnNSpvcEJyTJsSWip", "h": 256, "w": 256, "blurhash": "LHKT#k4TPE~U9Yo~8^IV5_%g%MpK", "xyz.amorgan.blurhash": "LHKT#k4TPE~U9Yo~8^IV5_%g%MpK"}, "fi.mau.double_puppet_source": "mautrix-signal"}
bridge-signal_1 | [2022-08-01 03:44:15,932] [[email protected].@eggie:matrix.at.alexmaras.com] req #3358 (/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/send/m.room.message/mautrix-python_1659325455736494606_20) completed in 195.8ms with status 200
bridge-signal_1 | [2022-08-01 03:44:15,933] [[email protected].@eggie:matrix.at.alexmaras.com] req #3359: POST https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers {"m.fully_read": "$I1-VwXPqxv5xf0B6BzZ3jzh9VWCANFxfvswEiaThBKc", "m.read": "$I1-VwXPqxv5xf0B6BzZ3jzh9VWCANFxfvswEiaThBKc", "com.beeper.fully_read.extra": {"fi.mau.double_puppet_source": "mautrix-signal"}, "com.beeper.read.extra": {"fi.mau.double_puppet_source": "mautrix-signal"}}
bridge-signal_1 | [2022-08-01 03:44:15,938] [[email protected].@eggie:matrix.at.alexmaras.com] req #3360: PUT https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/send/m.room.message/mautrix-python_1659325455937986009_21?ts=1659325455367 {"msgtype": "m.text", "body": "Hedging do yoghurt", "fi.mau.double_puppet_source": "mautrix-signal"}
bridge-signal_1 | [2022-08-01 03:44:15,952] [[email protected]] 192.168.240.7 [01/Aug/2022:03:44:15 +0000] "PUT /transactions/23522?access_token=XXXXXXX HTTP/1.1" 200 159 "-" "Synapse/1.63.1"
bridge-signal_1 | [2022-08-01 03:44:16,010] [[email protected].@eggie:matrix.at.alexmaras.com] req #3359 (/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers) completed in 76.1ms with status 200
bridge-signal_1 | [2022-08-01 03:44:16,077] [[email protected].@eggie:matrix.at.alexmaras.com] req #3360 (/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/send/m.room.message/mautrix-python_1659325455937986009_21) completed in 138.9ms with status 200
bridge-signal_1 | [2022-08-01 03:44:16,078] [[email protected].@eggie:matrix.at.alexmaras.com] req #3363: POST https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers {"m.fully_read": "$oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig", "m.read": "$oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig", "com.beeper.fully_read.extra": {"fi.mau.double_puppet_source": "mautrix-signal"}, "com.beeper.read.extra": {"fi.mau.double_puppet_source": "mautrix-signal"}}
bridge-signal_1 | [2022-08-01 03:44:16,114] [[email protected]] Handled Signal message 1659325455367 -> $oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig
bridge-signal_1 | [2022-08-01 03:44:16,118] [[email protected]] 192.168.240.7 [01/Aug/2022:03:44:16 +0000] "PUT /transactions/23523?access_token=XXXXXXX HTTP/1.1" 200 159 "-" "Synapse/1.63.1"
bridge-signal_1 | [2022-08-01 03:44:16,142] [[email protected].@eggie:matrix.at.alexmaras.com] req #3363 (/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers) completed in 63.7ms with status 200
bridge-signal_1 | [2022-08-01 03:44:16,150] [DEBUG@mausignald] Request b00a934f-8ede-4f87-8ba3-ad565dfc1932: mark_read
bridge-signal_1 | [2022-08-01 03:44:16,304] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3356 (/_matrix/media/v3/upload) completed in 993.5ms with status 200
bridge-signal_1 | [2022-08-01 03:44:16,309] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3365: PUT https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21ILWvCKgsxaFEnIbaQD%3Amatrix.at.alexmaras.com/send/m.room.message/mautrix-python_1659325456308909844_37?ts=1659325455367&user_id=@signal_XXX:matrix.at.alexmaras.com {"msgtype": "m.image", "body": "PJwSlvZjc_WZiv6ja7Q7.png", "url": "mxc://matrix.at.alexmaras.com/bzJlGaqvhuMLGxNPGoWgebvO", "info": {"mimetype": "image/png", "size": 851071, "thumbnail_url": "mxc://matrix.at.alexmaras.com/bzJlGaqvhuMLGxNPGoWgebvO", "h": 1062, "w": 1053, "blurhash": "LRK18W-m~UWU^YIWR*t7~6NHM{jY", "xyz.amorgan.blurhash": "LRK18W-m~UWU^YIWR*t7~6NHM{jY"}}
bridge-signal_1 | [2022-08-01 03:44:16,386] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3365 (/v3/rooms/%21ILWvCKgsxaFEnIbaQD%3Amatrix.at.alexmaras.com/send/m.room.message/mautrix-python_1659325456308909844_37) completed in 76.9ms with status 200
bridge-signal_1 | [2022-08-01 03:44:16,386] [ERROR@mausignald] Exception in event handler
bridge-signal_1 | Traceback (most recent call last):
bridge-signal_1 | File "/opt/mautrix-signal/mausignald/signald.py", line 82, in _run_event_handler
bridge-signal_1 | await handler(event)
bridge-signal_1 | File "/usr/lib/python3.10/site-packages/mautrix_signal/signal.py", line 75, in on_message
bridge-signal_1 | await self.handle_message(user, sender, evt.data_message)
bridge-signal_1 | File "/usr/lib/python3.10/site-packages/mautrix_signal/signal.py", line 168, in handle_message
bridge-signal_1 | await self._handle_message(user, sender, msg, addr_override)
bridge-signal_1 | File "/usr/lib/python3.10/site-packages/mautrix_signal/signal.py", line 241, in _handle_message
bridge-signal_1 | await portal.handle_signal_message(user, sender, msg)
bridge-signal_1 | File "/usr/lib/python3.10/site-packages/mautrix_signal/portal.py", line 1196, in handle_signal_message
bridge-signal_1 | content = await self._handle_signal_attachment(intent, attachment, text=as_text)
bridge-signal_1 | File "/usr/lib/python3.10/site-packages/mautrix_signal/portal.py", line 1527, in _handle_signal_attachment
bridge-signal_1 | with open(attachment.incoming_filename, "rb") as file:
bridge-signal_1 | FileNotFoundError: [Errno 2] No such file or directory: '/signald/attachments/v3NNKUGb7XxoP4FrIfC0'
bridge-signal_1 | [2022-08-01 03:44:16,402] [[email protected]] 192.168.240.7 [01/Aug/2022:03:44:16 +0000] "PUT /transactions/23524?access_token=XXXXXXX HTTP/1.1" 200 159 "-" "Synapse/1.63.1"
bridge-signal_1 | [2022-08-01 03:44:31,528] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3367: POST https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers?user_id=@signal_XXX:matrix.at.alexmaras.com {"m.fully_read": "$oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig", "m.read": "$oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig"}
bridge-signal_1 | [2022-08-01 03:44:31,534] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3368: POST https://matrix.at.alexmaras.com/_matrix/client/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers?user_id=@signal_XXX:matrix.at.alexmaras.com {"m.fully_read": "$oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig", "m.read": "$oXmO4jIHCi2e1M0arc7Tmmdcq0usPCk9FcLPmISV8Ig"}
bridge-signal_1 | [2022-08-01 03:44:31,618] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3367 (/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers) completed in 90.1ms with status 200
bridge-signal_1 | [2022-08-01 03:44:31,619] [[email protected].@signal_XXX:matrix.at.alexmaras.com] req #3368 (/v3/rooms/%21uHSkqykJmszjMGkXcT%3Amatrix.at.alexmaras.com/read_markers) completed in 85.0ms with status 200
All other Signal messages appear to work.
I can't reproduce the bug here. Try upgrading signald and the bridge if you haven't already (possibly use master for the bridge, there hasn't been a release in a while). This looks like it might be a signald issue though. The uuids (d292.... And 6249...) are somewhat sensitive.
Thanks for the mention about UUIDs - I've stripped those out of the logs.
I've just pulled the latest version (was on :latest already, which appears to have been pushed a day ago) and still have the issue. Weirdly, it doesn't fail if I do a Note to self from Signal, but my partner sending me a message fails with the same trace.
I can go report the issue to the signald repo and see if we make any progress there though, if you think it's not related to the bridge.
Aha - turning off remove_file_after_handling fixed the issue. Previously, that was true for me, setting it to false makes them come through
That's still a bug though, remove_file_after_handling shouldn't remove the file before handling. I also have that setting set to true. The file is removed after the line that gives you an error.
Yep, agreed that it's still a bug. Just might provide a lead towards what's going on if that's happening sometimes. I've tested a number of times and it hasn't failed since I changed that setting. I'm having a trawl through the codebase to see if there's anything that jumps out at me around that setting.
I think this may be related to double puppeting. In my case, the other user (sending me the messages) is a signal user that has double-puppeting enabled in my matrix server, and I'm seeing it try to handle the message twice (self.log.debug(f"Started handling message {message.timestamp} by {sender.uuid}")) with different UUIDs for the receiver, but the same for the sender. I'm assuming this is because for both users, the same image is being processed, which has the same filename. Once it's handled for other person's account, it's deleted from the filesystem, and therefore can't be handled for my account.
I added a debug log into the code to show a message when the file is deleted, and it sure does delete the same file and then try to access that later on. The UUID on the "removing attachment` message is for one of the users, and the UUID on the stack-trace part is the the other users. The removal happens after handling for one of the users, but not both of the users.