Delay showing new-message notifications on the primary device when scli is running

[maximbaz]

I'd like to implement sending read receipts, and I want to run it by you first, to discuss some architectural decisions 😄

The primary goal: I don't want to receive signal notifications on phone/smartwatch, if I'm actively chatting in scli.

The main challenges, as I currently see them, are:

1. Implementing the code that will use signal-cli to actually send read receipt.
2. Detecting that scli is currently focused.

The first item seems possible, although I haven't worked with signal-cli before, I can see sendReadReceipt in the docs. Do you see any challenges here, missing APIs or some other problems? I haven't used Signal Desktop for a while, but I seem to remember that when Signal Desktop is open (but not focused, or focused but on a different contact), notifications on the phone arrive with a delay, seemingly giving the user a few seconds to check them out on desktop, before "spamming" their phone. I don't know if that's just "magically" works via their backend, or there's a special API to use, to activate such "delayed" mode. Do you know, perhaps?

Detecting whether a user is currently looking at scli is both difficult to implement for everyone, but at the same time is easy to do when you know the particulars of user's setup. Just to give you a concrete example, I am running Hyprland, which comes with both a CLI tool that can detect the currently focused window, and a Unix socket where you can subscribe for events of changing the active window. Identifying scli process specifically within a terminal window is also possible, e.g. by running a dedicated terminal instance with a custom app_id / class (e.g. kitty --class=scli scli).

So it sounds like it should be left to the user, to tell scli if it's currently focused, and scli should send read receipts if it has such information.

Here are the two different ways I thought such integration could potentially be implemented:

1. We give scli a command, which it periodically runs, say every second or two, to detect if scli is currently focused or not (say it outputs a boolean). Maybe also runs it additionally after every received message.
2. We teach scli a couple of Unix signals (say SIGUSR1 and SIGUSR2), which would tell sci that it got focused and unfocused respectively. We leave it up to users to send those signals (either precisely when these events occur, if they can e.g. subscribe to a socket like me, or just sending these signals in an infinite loop).

The latter seems a lot more robust and battery-friendly, but also requires users to implement more glue.

What are your thoughts on it?

[exquo]

This would be great! This feature has long been needed. Now that signal-cli has the dbus support for it (had it for while by now, actually) this really needs to be implemented in scli.

The biggest challenge is, as you say, detecting the user's "focus" (similar to #109), so that we only send read receipts for the likely-to-have-actually-been-seen messages. I think Signal-desktop has a leg-up with this: Electron probably makes available such information as whether its window is currently in focus, etc.

For the purposes of sending read receipts in scli though, I think we can just send them after any keyboard activity from the user, while the newly received messages are in view. Does that sound reasonable?
This will require writing some code for urwid's keyevents. I should be able to help with that, or point to the relevant documentation.

Another relevant issue (but a less important one) is that scli currently focuses the view on every newly received message. When there are many messages received in a chat, this results in some of the earlier ones scrolling out of the top of the view (since the latest message will always be made visible). So the last received message might be seen by the user before the first (unread) message. And so the RR will be sent for all the new messages in chat, even when the first one hasn't been seen yet.
The official clients handle this properly, by not allowing any of the unread messages to scroll out of view.
Fixing this would again require dealing with urwid's specifics (how items are focused in the corresponding ListBox object). This might be tricky, and probably not strictly necessary for implementing a good-enough read-receipt functionality.

I seem to remember that when Signal Desktop is open (but not focused, or focused but on a different contact), notifications on the phone arrive with a delay, seemingly giving the user a few seconds to check them out on desktop, before "spamming" their phone

This might be just the phone being slower to receive the messages. Perhaps because of power saving, when it polls / gets pushes less frequently. I don't think Signal clients exchange such info as which clients are concurrently opened. They just each receive new messages from the server.

Finally, some general notes on the sending-read-receipts functionality:

• This should be optional, so that users can opt out (scli's current behavior). Other choices can also be made available (if we think of them :), like under what conditions and how to send RRs.
• We'll need to check the produced implementation for not sending too many / redundant / repeated RRs. There are probably many ways to make this mistake, and initial attempts are likely make it.

Let me know if I can help with anything else related! I haven't had much time to devote to this lately, but will try to be of assistance.

[maximbaz]

Thank you, very insightful and helpful! I actually made a rough proof of concept, just of sending read receipts as soon as scli receives them, and stumbled upon the fact that the phone still receives the notifications, contrary to Signal Desktop behavior....

I asked upstream, but if you also have any thoughts, it's very appreciated 😊

AsamK/signal-cli#1163

[exquo]

Can you reliably reproduce the delayed-notifications-on-phone behavior?
Either way, it's probably not related to read receipts. Since as you say it happens when Signal Desktop is "not focused, or focused but on a different contact". In which case, read receipts for the relevant conversation wouldn't be sent from signal-desktop.

P.S. for sending read receipts automatically on every incoming message, signal-cli has a --send-read-receipts option.

[maximbaz]

I can reliably reproduce this:

• as long as Signal Desktop is open (focused or not focused), there's exactly 5 seconds delay between getting message on Desktop, and getting the notification on the phone. If I open the chat within 5 seconds (thus, marking the messages as "read"), the phone / smartwatch will never vibrate.
• using --send-read-receipts does NOT add this 5 seconds delay, yes messages are instantly marked as "read", but every message still gets instantly vibrating on the phone / smartwatch.

So there has to be something else at play, something that Signal Desktop is doing to introduce this delay, in addition to just marking messages as "read" 🤔

[exquo]

Interesting..

I suppose it's possible for signal-desktop to send "sync" messages reporting that it's running. Signal on the phone, after receiving such messages would delay showing notifications for a few seconds. Don't know if that's what's actually happening.

Maybe in addition to signal-cli's disucssions (AsamK/signal-cli#1163), this could also be asked on the official clients discussions somewhere (don't know which repo/forum would be most appropriate though). Searching through the signal-desktop's code might yield something (assuming one knows what to look for..)

Anyway, this seems to be a different kind of sync message, that is sent in addition to the read receipts.

[maximbaz]

I think you are onto something!

Here is a snippet of Signal Desktop's debug logs when I received a message while Signal was open and focused on this contact (so the phone never vibrated):

Logs

    INFO  2023-02-24T20:03:59.234Z MessageReceiver: got request PUT /api/v1/message
    INFO  2023-02-24T20:03:59.309Z MessageReceiver.decryptAndCacheBatch 1
    INFO  2023-02-24T20:03:59.310Z SignalProtocolStore.enterZone(decryptAndCacheBatch:MessageReceiver)
    INFO  2023-02-24T20:03:59.310Z queueing envelope > [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1)
    INFO  2023-02-24T20:03:59.310Z MessageReceiver.unsealEnvelope(> [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1)): unidentified message
    INFO  2023-02-24T20:03:59.310Z @signalapp/libsignal-client deserialized UnidentifiedSenderMessageContent from [REDACTED]70e.1 with type Whisper libsignal_protocol::sealed_sender rust/protocol/src/sealed_sender.rs:431
    INFO  2023-02-24T20:03:59.311Z MessageReceiver.decryptEnvelope([REDACTED]70e.1 > [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1))
    INFO  2023-02-24T20:03:59.311Z decrypt/[REDACTED]70e.1 > [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1): unidentified message
    INFO  2023-02-24T20:03:59.311Z MessageReceiver.decryptSealedSender([REDACTED]70e.1 > [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1)): unidentified message/passing to sealedSenderDecryptMessage
    INFO  2023-02-24T20:03:59.311Z @signalapp/libsignal-client deserialized UnidentifiedSenderMessageContent from [REDACTED]70e.1 with type Whisper libsignal_protocol::sealed_sender rust/protocol/src/sealed_sender.rs:431
    INFO  2023-02-24T20:03:59.311Z @signalapp/libsignal-client decrypted Whisper message from [REDACTED]70e.1 with current session state (base key 08dcc644e3252e4f1831da2f293414fb4350799add61b3496ef767bf404a815c) libsignal_protocol::session_cipher rust/protocol/src/session_cipher.rs:438
    INFO  2023-02-24T20:03:59.311Z MessageReceiver.decryptAndCacheBatch storing 1 decrypted envelopes, keeping 0 failed envelopes.
    INFO  2023-02-24T20:03:59.311Z commitZoneChanges(MessageReceiver): pending sender keys 0, pending sessions 1, pending unprocessed 1
    INFO  2023-02-24T20:03:59.313Z SignalProtocolStore.leaveZone(decryptAndCacheBatch)
    INFO  2023-02-24T20:03:59.313Z MessageReceiver.decryptAndCacheBatch acknowledging receipt
    INFO  2023-02-24T20:03:59.313Z queueing decrypted envelope [REDACTED]70e.1 > [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1)
    INFO  2023-02-24T20:03:59.313Z MessageReceiver.handleDataMessage [REDACTED]70e.1 > [REDACTED]da8 1677269039084 (cc0fb13c79ac4a3192bb63a62f2323c1)
    INFO  2023-02-24T20:03:59.313Z handleDataMessage/[REDACTED]70e ([REDACTED]a23) [REDACTED]70e.1 1677269039084: starting processing in queue
    INFO  2023-02-24T20:03:59.313Z handleDataMessage/[REDACTED]70e ([REDACTED]a23) [REDACTED]70e.1 1677269039084: duplicate check db lookup needed [REDACTED]a23.1-1677269039084
    INFO  2023-02-24T20:03:59.313Z MessageReceiver.decryptAndCacheBatch fully processed
    INFO  2023-02-24T20:03:59.315Z handleDataMessage/[REDACTED]70e ([REDACTED]a23) [REDACTED]70e.1 1677269039084: Batching save
    INFO  2023-02-24T20:03:59.316Z changedConvoBatcher: deduped 2 into 1
    INFO  2023-02-24T20:03:59.385Z src/core/call_manager.rs:413 CallManager: Dropping last reference.
    INFO  2023-02-24T20:03:59.390Z saveNewMessageBatcher 1
    INFO  2023-02-24T20:03:59.399Z Message saved 1677269039084
    INFO  2023-02-24T20:03:59.399Z NotificationService: adding a notification and requesting an update
    INFO  2023-02-24T20:03:59.408Z changedConvoBatcher: deduped 2 into 1
    INFO  2023-02-24T20:03:59.440Z markConversationRead {"conversationId":"[REDACTED]70e ([REDACTED]a23)","newestSentAt":1677269039084,"newestUnreadAt":1677221028566,"unreadMessages":1,"unreadReactions":0}
    INFO  2023-02-24T20:03:59.440Z NotificationService#removeBy: conversation ID matches
    INFO  2023-02-24T20:03:59.440Z NotificationService: clearing notification and requesting an update
    INFO  2023-02-24T20:03:59.445Z Sending 1 read syncs
    INFO  2023-02-24T20:03:59.445Z JobQueueDatabaseStore adding job [REDACTED]feb to queue "read sync"
    INFO  2023-02-24T20:03:59.445Z JobQueueDatabaseStore adding job [REDACTED]1e2 to queue "read receipts"
    INFO  2023-02-24T20:03:59.447Z read sync job queue: added new job [REDACTED]feb
    INFO  2023-02-24T20:03:59.447Z read sync job queue: enqueuing job [REDACTED]feb
    INFO  2023-02-24T20:03:59.447Z read sync job queue: running job [REDACTED]feb, attempt 1 of 110
->  INFO  2023-02-24T20:03:59.447Z read sync job queue, job ID [REDACTED]feb, attempt 1: sending readSync(s) for timestamp(s) 1677269039084
    INFO  2023-02-24T20:03:59.447Z read sync job queue, job ID [REDACTED]feb, attempt 1: sleeping for 0
    INFO  2023-02-24T20:03:59.447Z read receipts job queue: added new job [REDACTED]1e2
    INFO  2023-02-24T20:03:59.447Z read receipts job queue: enqueuing job [REDACTED]1e2
    INFO  2023-02-24T20:03:59.447Z read receipts job queue: running job [REDACTED]1e2, attempt 1 of 110
    INFO  2023-02-24T20:03:59.447Z read receipts job queue, job ID [REDACTED]1e2, attempt 1: sleeping for 0
    INFO  2023-02-24T20:03:59.448Z Sender certificate service found a valid yes-E164 certificate in storage; skipping fetch
    INFO  2023-02-24T20:03:59.449Z commitZoneChanges(storeSession): pending sender keys 0, pending sessions 1, pending unprocessed 0
    INFO  2023-02-24T20:03:59.449Z commitZoneChanges(storeSession): pending sender keys 0, pending sessions 1, pending unprocessed 0
    INFO  2023-02-24T20:03:59.449Z commitZoneChanges(storeSession): pending sender keys 0, pending sessions 1, pending unprocessed 0
    INFO  2023-02-24T20:03:59.449Z commitZoneChanges(storeSession): pending sender keys 0, pending sessions 1, pending unprocessed 0
    INFO  2023-02-24T20:03:59.449Z changedConvoBatcher: deduped 1 into 1
    INFO  2023-02-24T20:03:59.457Z PUT (WS) https://chat.signal.org/v1/messages/[REDACTED]da8?story=false
    INFO  2023-02-24T20:03:59.458Z PUT (WS) https://chat.signal.org/v1/messages/[REDACTED]70e?story=false (unauth)
    INFO  2023-02-24T20:03:59.585Z PUT (WS) https://chat.signal.org/v1/messages/[REDACTED]70e?story=false (unauth) 200 Success
    INFO  2023-02-24T20:03:59.587Z read receipts job queue: job [REDACTED]1e2 succeeded on attempt 1
    INFO  2023-02-24T20:03:59.603Z PUT (WS) https://chat.signal.org/v1/messages/[REDACTED]da8?story=false 200 Success
    INFO  2023-02-24T20:03:59.605Z read sync job queue: job [REDACTED]feb succeeded on attempt 1
    INFO  2023-02-24T20:03:59.611Z changedConvoBatcher: deduped 1 into 1
    INFO  2023-02-24T20:03:59.814Z JobQueueDatabaseStore adding job [REDACTED]06e to queue "delivery receipts"
    INFO  2023-02-24T20:03:59.815Z delivery receipts job queue: added new job [REDACTED]06e
    INFO  2023-02-24T20:03:59.815Z delivery receipts job queue: enqueuing job [REDACTED]06e
    INFO  2023-02-24T20:03:59.816Z delivery receipts job queue: running job [REDACTED]06e, attempt 1 of 110
    INFO  2023-02-24T20:03:59.816Z delivery receipts job queue, job ID [REDACTED]06e, attempt 1: sleeping for 0
    INFO  2023-02-24T20:03:59.816Z Sender certificate service found a valid yes-E164 certificate in storage; skipping fetch
    INFO  2023-02-24T20:03:59.818Z commitZoneChanges(storeSession): pending sender keys 0, pending sessions 1, pending unprocessed 0
    INFO  2023-02-24T20:03:59.818Z commitZoneChanges(storeSession): pending sender keys 0, pending sessions 1, pending unprocessed 0
    INFO  2023-02-24T20:03:59.820Z PUT (WS) https://chat.signal.org/v1/messages/[REDACTED]70e?story=false (unauth)
    INFO  2023-02-24T20:03:59.964Z PUT (WS) https://chat.signal.org/v1/messages/[REDACTED]70e?story=false (unauth) 200 Success
    INFO  2023-02-24T20:03:59.966Z delivery receipts job queue: job [REDACTED]06e succeeded on attempt 1
    INFO  2023-02-24T20:04:00.441Z NotificationService not updating notifications. Notifications are enabled; app is focused; there is no notification data
    INFO  2023-02-24T20:04:00.447Z checkExpiringMessages: checking for expiring messages
    INFO  2023-02-24T20:04:00.448Z checkExpiringMessages: found no messages to expire

I think these snippets are relevant:

https://github.com/signalapp/Signal-Desktop/blob/5bcf71ef2c5f829b6c96c20cd288533b0582327b/ts/util/markConversationRead.ts#L133-L136

https://github.com/signalapp/Signal-Desktop/blob/5bcf71ef2c5f829b6c96c20cd288533b0582327b/ts/jobs/helpers/syncHelpers.ts#L90-L104

You have a lot more knowledge about signal-cli, from a first glance it doesn't seem like it implements readSync, do you think it's something we could ask for?

And what do you think about it all in general, does it all sound plausible?

[exquo]

Nice find!

I haven't fully studied the code, but the readSync events look like they might be responsible for this behavior.

Signal-cli doesn't have readSyncs AFAIK. Probably wouldn't hurt requesting this. Would be good to first understand what exactly it does though, so that to know what exactly to ask for :). But if it's not clear from the code, maybe AsamK could help figuring it out..

If you can determine what those read-syncs do from reading the code, that would definitely make implementing it in signal-cli easier. But feel free to ask in signal-cli tracker and to link to this discussion. I don't know whether it's possible to ask upstream someone who's familiar with signal-desktop code though: their repo does not even have Discussions; and the signal forums are mostly for feature requests (maybe worth a try?)..