signal icon indicating copy to clipboard operation
signal copied to clipboard

Disappearing messages gets disabled randomly

Open HNGamingUK opened this issue 1 year ago • 4 comments

For clarity I am using the following repo to install the signal bridge and have enabled end to bridge encryption and double puppeting. https://github.com/spantaleev/matrix-docker-ansible-deploy

I have noticed that randomly (which I know is not helpful) disappearing messages get disabled. When on Matrix it looks as though the other user disabled them however when I check Signal it shows as me disabling it.

I am unsure on what logs or such to provide to help but let me know and I can provide it.

HNGamingUK avatar Mar 23 '23 14:03 HNGamingUK

I've experienced something similar for a few weeks now that I can't get a hang of. This is what I have discovered so far:

  • It only happens in one on one portals, never in group portals
  • It occurs when a reaction emoji has been used on a message earlier in the conversation but it doesn't matter if I reacted or the other user did nor does it matter if the message reacted to is mine or theirs
  • Disappearing messages are turned off when a new message is sent from the Matrix side of things but it always turns off before the actual message is delivered
  • Signal says I am the one who turned it off and Matrix says the other user did it
  • Usually it takes 3-5 messages before Matrix lets me know that disappearing messages have been turned off as compared to Signal where it happens immediately

rufflepot avatar Apr 01 '23 11:04 rufflepot

@rufflepot After monitoiring this for a couple of weeks now I have come to the same conclusion as yourself around when it is seemingly disabling the dissapearing messages.

As mentioned in my intial bug report note I am using matrix-docker-ansible-deploy to deploy and using journalctl to check the log for the mautrix-signal service isn't showing a mention of disabling it. However the logging level might not be high enough or I am not using journalctl correctly.

HNGamingUK avatar Apr 14 '23 18:04 HNGamingUK

I'm not using ansible so we differ on that part. I tried this simple behavior a few times with 100% success rate on getting the bug:

  1. Setting disappearing messages to 1 day in Signal
  2. Writing a message from Element Desktop (not web)
  3. Liking the message from Signal
  4. Writing another message from Element Desktop This always resulted in the disappearing messages being turned off "before" the second message arrived, so the second message will not be a part of the disappearing message feature. Since it never happens in group chats I tried inviting one of my bots located on the same server into the one-on-one portal but that didn't help, unfortunately.

I cleared logs from signald and mautrix-signal after every step and saved them so nothing would get in the way. These logs should only show what happens during those four steps mentioned above and nothing else. I hope I've removed any private information, but if not please let me now. I'm not running encrypted so the short test messages will of course be in plain text. I put XXX instead of the user name, access token, room name and server name. The IP and domain names are internal since it's running in docker so that shouldn't be an issue.

Signald at setting Disappearing Messages (nothing in mautrix-signal):

4/27/2023 9:23:06 AM
07:23:06.730 [[redacted 33]036-receiver] INFO  manager-[redacted 33]036 - received sent message transcript from device 1

Signald when message from Element is sent:

04/27/2023 9:24:03 AM
07:24:03.814 [494414e6-3594-4979-b55e-2c339ea2bbdb-send] INFO  send - handled request 494414e6-3594-4979-b55e-2c339ea2bbdb successfully

Mautrix-signal when message from Element is sent:

04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,542] [[email protected]] Handling transaction 381572 with 1 PDUs
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,542] [[email protected]] Finished handling transaction 381572
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,543] [[email protected]] 172.18.0.10 [27/Apr/2023:07:24:03 +0000] "PUT /_matrix/app/v1/transactions/381572?access_token=XXX HTTP/1.1" 200 159 "-" "Synapse/1.82.0"
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,543] [[email protected]] Received Matrix event $oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU from @XXX in !XXX
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,544] [[email protected]] Sending Matrix message $oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU to Signal with timestamp 1682580243544
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,544] [[email protected]] Send attempt 0. Attempting to send $oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU with 494414e6-3594-4979-b55e-2c339ea2bbdb
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,544] [DEBUG@mausignald] Request 494414e6-3594-4979-b55e-2c339ea2bbdb: send
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,815] [INFO@mausignald] Successfully sent message to 1/1 users in 4164ccdf-0c39-4ac0-92e7-b1e786e15385 with 0 unregistered failures
04/27/2023 9:24:03 AM
[2023-04-27 09:24:03,822] [[email protected]] Handled Matrix message $oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU -> 1682580243544

Signald when the message is liked from Signal:

04/27/2023 9:24:50 AM
07:24:50.129 [[redacted 33]036-receiver] INFO  manager-[redacted 33]036 - received sent message transcript from device 1

Mautrix-signal when the message is liked from Signal:

04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,148] [[email protected].@XXX] req #4045: PUT http://synapse:8008/_matrix/client/v3/rooms/XXX/send/m.reaction/mautrix-python_1682580290147674858_8?ts=1682580286078 {"m.relates_to": {"rel_type": "m.annotation", "event_id": "$oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU", "key": "\u2764\ufe0f"}, "fi.mau.double_puppet_source": "mautrix-signal"}
04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,233] [[email protected].@XXX] req #4045 (/v3/rooms/XXX/send/m.reaction/mautrix-python_1682580290147674858_8) completed in 84.9ms with status 200
04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,233] [[email protected]] db555fb8-4cf2-423c-9e7c-412e379ca036 reacted to $oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU -> $vLaFiS8SLktsXmZx4Gf1suRjKzFpmLBg_olb1Wmzq6Y
04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,233] [[email protected]] _upsert_reaction inserting $vLaFiS8SLktsXmZx4Gf1suRjKzFpmLBg_olb1Wmzq6Y (message: $oTKGk7znah8TH_9oln-9UpfOBc6z-cUD9TRg8h9WzvU)
04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,309] [[email protected]] Handling transaction 381573 with 1 PDUs
04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,309] [[email protected]] Finished handling transaction 381573
04/27/2023 9:24:50 AM
[2023-04-27 09:24:50,310] [[email protected]] 172.18.0.10 [27/Apr/2023:07:24:50 +0000] "PUT /_matrix/app/v1/transactions/381573?access_token=XXX HTTP/1.1" 200 159 "-" "Synapse/1.82.0"

Signald when message from Element is sent after liking from Signal (this is the moment when Disappearing Messages is turned off automatically):

04/27/2023 9:26:21 AM
07:26:21.539 [12acfda5-fb9a-469c-a009-06d7aa63ed05-send] INFO  send - handled request 12acfda5-fb9a-469c-a009-06d7aa63ed05 successfully

Mautrix-signal when message from Element is sent after liking from Signal (this is the moment when Disappearing Messages is turned off automatically):

04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,246] [[email protected]] Handling transaction 381576 with 1 PDUs
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,246] [[email protected]] Finished handling transaction 381576
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,247] [[email protected]] 172.18.0.10 [27/Apr/2023:07:26:21 +0000] "PUT /_matrix/app/v1/transactions/381576?access_token=XXX HTTP/1.1" 200 159 "-" "Synapse/1.82.0"
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,248] [[email protected]] Received Matrix event $hxOebZEPnG0VTdmlGr8zoxZl3OzgGS5Oco_uHCsFdto from @XXX in !XXX
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,248] [[email protected]] Sending Matrix message $hxOebZEPnG0VTdmlGr8zoxZl3OzgGS5Oco_uHCsFdto to Signal with timestamp 1682580381248
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,248] [[email protected]] Send attempt 0. Attempting to send $hxOebZEPnG0VTdmlGr8zoxZl3OzgGS5Oco_uHCsFdto with 12acfda5-fb9a-469c-a009-06d7aa63ed05
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,248] [DEBUG@mausignald] Request 12acfda5-fb9a-469c-a009-06d7aa63ed05: send
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,540] [INFO@mausignald] Successfully sent message to 1/1 users in 4164ccdf-0c39-4ac0-92e7-b1e786e15385 with 0 unregistered failures
04/27/2023 9:26:21 AM
[2023-04-27 09:26:21,547] [[email protected]] Handled Matrix message $hxOebZEPnG0VTdmlGr8zoxZl3OzgGS5Oco_uHCsFdto -> 1682580381248

Edit: spelling mistake and some additions.

rufflepot avatar Apr 27 '23 07:04 rufflepot

Just wanted to update on this issue. I've never had disappearing messages randomly being disabled since transferring to the new Go bridge so it is very possible this is no longer something that occurs.

rufflepot avatar Feb 21 '24 12:02 rufflepot