GSConnect / gnome-shell-extension-gsconnect

KDE Connect implementation for GNOME
GNU General Public License v2.0
3.23k stars 259 forks source link

When an SMS message fails to send, it is discarded #1355

Open matthijskooijman opened 2 years ago

matthijskooijman commented 2 years ago

Describe the bug

I tried to send an SMS using the messaging app. The message appeared greyed out at first and then disappeared (presumably because the connection to my phone failed for whatever reason).

This bug report is not about the sending failure (it worked fine on the second try), but it is about how the failure is handled. I had spent some time writing the message, which was then discarded and I had to write it again (saving it in the clipboard this time, but that should really not be necessary). Also, there was no error message of any kind.

Steps To Reproduce:

  1. Go to Messaging
  2. Write a message
  3. Disable wifi on your phone
  4. Quickly press enter in the messaging window (before gsconnect realizes the connection is down)
  5. The message is shown grayed out, and stays like that (possibly indefinitely)
  6. Enable wifi on your phone
  7. The message silently disappears from the Messaging window, and is not sent or shown on the phone.

Expected behavior

In step 5 or 7, the message could time out with an error message, but still be shown so you can recover the message text. Alternatively, the message could just be retried when it fails in step 7.

Support Log

Please generate a support log (Instructions) and paste any messages related to this issue between the two ``` lines below.

I've pruned the log, removing unrelated lines/events about cell connectivity, contact list, third-party app notifications, battery level, audio volumes, and I redacted some (possibly) sensitive information.

mei 13 13:41:40 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442100696,
                                                              "type": "kdeconnect.sms.request",
                                                              "body": {
                                                                "sendSms": true,
                                                                "phoneNumber": "[redacted]",
                                                                "messageBody": "Test"
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/core.js:readPacket/</<:233]: FP2: Error receiving data: Connection reset by peer
                                                            readPacket/</<@/home/matthijs/.local/share/gnome-shell/extensions/gsconnect@andyholmes.github.io/service/core.js:233:45
                                                            @/home/matthijs/.local/share/gnome-shell/extensions/gsconnect@andyholmes.github.io/service/daemon.js:727:17
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/backends/lan.js:close:820]: "lan://192.168.1.223:1716 ([redacted])"
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/backends/lan.js:_onIdentity:343]: {
                                                              "id": 1652442116169,
                                                              "type": "kdeconnect.identity",
                                                              "body": {
                                                                "deviceId": "[redacted]",
                                                                "deviceName": "FP2",
                                                                "protocolVersion": 7,
                                                                "deviceType": "phone",
                                                                "incomingCapabilities": [
                                                                  "kdeconnect.telephony.request_mute",
                                                                  "kdeconnect.notification",
                                                                  "kdeconnect.ping",
                                                                  "kdeconnect.notification.reply",
                                                                  "kdeconnect.notification.action",
                                                                  "kdeconnect.share.request",
                                                                  "kdeconnect.bigscreen.stt",
                                                                  "kdeconnect.clipboard.connect",
                                                                  "kdeconnect.runcommand",
                                                                  "kdeconnect.connectivity_report.request",
                                                                  "kdeconnect.contacts.request_all_uids_timestamps",
                                                                  "kdeconnect.sms.request_conversations",
                                                                  "kdeconnect.telephony.request",
                                                                  "kdeconnect.mpris",
                                                                  "kdeconnect.sms.request_conversation",
                                                                  "kdeconnect.findmyphone.request",
                                                                  "kdeconnect.sms.request_attachment",
                                                                  "kdeconnect.systemvolume",
                                                                  "kdeconnect.mousepad.keyboardstate",
                                                                  "kdeconnect.sftp.request",
                                                                  "kdeconnect.share.request.update",
                                                                  "kdeconnect.notification.request",
                                                                  "kdeconnect.mousepad.request",
                                                                  "kdeconnect.photo.request",
                                                                  "kdeconnect.sms.request",
                                                                  "kdeconnect.contacts.request_vcards_by_uid",
                                                                  "kdeconnect.mpris.request",
                                                                  "kdeconnect.battery.request",
                                                                  "kdeconnect.battery",
                                                                  "kdeconnect.clipboard"
                                                                ],
                                                                "outgoingCapabilities": [
                                                                  "kdeconnect.telephony",
                                                                  "kdeconnect.notification",
                                                                  "kdeconnect.contacts.response_uids_timestamps",
                                                                  "kdeconnect.ping",
                                                                  "kdeconnect.share.request",
                                                                  "kdeconnect.bigscreen.stt",
                                                                  "kdeconnect.clipboard.connect",
                                                                  "kdeconnect.connectivity_report",
                                                                  "kdeconnect.sftp",
                                                                  "kdeconnect.sms.attachment_file",
                                                                  "kdeconnect.systemvolume.request",
                                                                  "kdeconnect.sms.messages",
                                                                  "kdeconnect.mpris",
                                                                  "kdeconnect.findmyphone.request",
                                                                  "kdeconnect.mousepad.keyboardstate",
                                                                  "kdeconnect.contacts.response_vcards",
                                                                  "kdeconnect.notification.request",
                                                                  "kdeconnect.mousepad.echo",
                                                                  "kdeconnect.mousepad.request",
                                                                  "kdeconnect.presenter",
                                                                  "kdeconnect.photo",
                                                                  "kdeconnect.runcommand.request",
                                                                  "kdeconnect.mpris.request",
                                                                  "kdeconnect.battery.request",
                                                                  "kdeconnect.battery",
                                                                  "kdeconnect.clipboard"
                                                                ],
                                                                "tcpPort": 1716,
                                                                "tcpHost": "192.168.1.223"
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/backends/lan.js:open:799]: "lan://192.168.1.223:1716 ([redacted])"
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/backends/lan.js:_onIdentity:343]: {
                                                              "id": 1652442116169,
                                                              "type": "kdeconnect.identity",
                                                              "body": {
                                                                "deviceId": "[redacted]",
                                                                "deviceName": "FP2",
                                                                "protocolVersion": 7,
                                                                "deviceType": "phone",
                                                                "incomingCapabilities": [
                                                                  "kdeconnect.telephony.request_mute",
                                                                  "kdeconnect.notification",
                                                                  "kdeconnect.ping",
                                                                  "kdeconnect.notification.reply",
                                                                  "kdeconnect.notification.action",
                                                                  "kdeconnect.share.request",
                                                                  "kdeconnect.bigscreen.stt",
                                                                  "kdeconnect.clipboard.connect",
                                                                  "kdeconnect.runcommand",
                                                                  "kdeconnect.connectivity_report.request",
                                                                  "kdeconnect.contacts.request_all_uids_timestamps",
                                                                  "kdeconnect.sms.request_conversations",
                                                                  "kdeconnect.telephony.request",
                                                                  "kdeconnect.mpris",
                                                                  "kdeconnect.sms.request_conversation",
                                                                  "kdeconnect.findmyphone.request",
                                                                  "kdeconnect.sms.request_attachment",
                                                                  "kdeconnect.systemvolume",
                                                                  "kdeconnect.mousepad.keyboardstate",
                                                                  "kdeconnect.sftp.request",
                                                                  "kdeconnect.share.request.update",
                                                                  "kdeconnect.notification.request",
                                                                  "kdeconnect.mousepad.request",
                                                                  "kdeconnect.photo.request",
                                                                  "kdeconnect.sms.request",
                                                                  "kdeconnect.contacts.request_vcards_by_uid",
                                                                  "kdeconnect.mpris.request",
                                                                  "kdeconnect.battery.request",
                                                                  "kdeconnect.battery",
                                                                  "kdeconnect.clipboard"
                                                                ],
                                                                "outgoingCapabilities": [
                                                                  "kdeconnect.telephony",
                                                                  "kdeconnect.notification",
                                                                  "kdeconnect.contacts.response_uids_timestamps",
                                                                  "kdeconnect.ping",
                                                                  "kdeconnect.share.request",
                                                                  "kdeconnect.bigscreen.stt",
                                                                  "kdeconnect.clipboard.connect",
                                                                  "kdeconnect.connectivity_report",
                                                                  "kdeconnect.sftp",
                                                                  "kdeconnect.sms.attachment_file",
                                                                  "kdeconnect.systemvolume.request",
                                                                  "kdeconnect.sms.messages",
                                                                  "kdeconnect.mpris",
                                                                  "kdeconnect.findmyphone.request",
                                                                  "kdeconnect.mousepad.keyboardstate",
                                                                  "kdeconnect.contacts.response_vcards",
                                                                  "kdeconnect.notification.request",
                                                                  "kdeconnect.mousepad.echo",
                                                                  "kdeconnect.mousepad.request",
                                                                  "kdeconnect.presenter",
                                                                  "kdeconnect.photo",
                                                                  "kdeconnect.runcommand.request",
                                                                  "kdeconnect.mpris.request",
                                                                  "kdeconnect.battery.request",
                                                                  "kdeconnect.battery",
                                                                  "kdeconnect.clipboard"
                                                                ],
                                                                "tcpPort": 1716,
                                                                "tcpHost": "192.168.1.223"
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116848,
                                                              "type": "kdeconnect.contacts.request_all_uids_timestamps",
                                                              "body": {}
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116849,
                                                              "type": "kdeconnect.mousepad.keyboardstate",
                                                              "body": {
                                                                "state": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116850,
                                                              "type": "kdeconnect.mpris.request",
                                                              "body": {
                                                                "requestPlayerList": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116851,
                                                              "type": "kdeconnect.mpris",
                                                              "body": {
                                                                "playerList": [],
                                                                "supportAlbumArtPayload": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116851,
                                                              "type": "kdeconnect.notification.request",
                                                              "body": {
                                                                "request": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116852,
                                                              "type": "kdeconnect.runcommand",
                                                              "body": {
                                                                "commandList": "{}"
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116852,
                                                              "type": "kdeconnect.runcommand.request",
                                                              "body": {
                                                                "requestCommandList": true
                                                              }
                                                            }
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116853,
                                                              "type": "kdeconnect.sftp.request",
                                                              "body": {
                                                                "startBrowsing": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116853,
                                                              "type": "kdeconnect.sms.request_conversations",
                                                              "body": {}
                                                            }
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 gnome-shell[3120]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:_readLoop:341]: FP2: {
                                                              "id": 1652442116332,
                                                              "type": "kdeconnect.mpris",
                                                              "body": {
                                                                "playerList": []
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:_readLoop:341]: FP2: {
                                                              "id": 1652442116352,
                                                              "type": "kdeconnect.clipboard.connect",
                                                              "body": {
                                                                "timestamp": 0
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:_readLoop:341]: FP2: {
                                                              "id": 1652442116391,
                                                              "type": "kdeconnect.mpris.request",
                                                              "body": {
                                                                "requestPlayerList": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116935,
                                                              "type": "kdeconnect.mpris",
                                                              "body": {
                                                                "playerList": [],
                                                                "supportAlbumArtPayload": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:_readLoop:341]: FP2: {
                                                              "id": 1652442116392,
                                                              "type": "kdeconnect.runcommand.request",
                                                              "body": {
                                                                "requestCommandList": true
                                                              }
                                                            }
mei 13 13:41:56 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:sendPacket:449]: FP2: {
                                                              "id": 1652442116937,
                                                              "type": "kdeconnect.runcommand",
                                                              "body": {
                                                                "commandList": "{}"
                                                              }
                                                            }
mei 13 13:41:57 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:_readLoop:341]: FP2: {
                                                              "id": 1652442116446,
                                                              "type": "kdeconnect.mpris",
                                                              "body": {
                                                                "playerList": []
                                                              }
                                                            }
mei 13 13:41:57 org.gnome.Shell.Extensions.GSConnect[3389]: [/service/device.js:_readLoop:341]: FP2: {
                                                              "id": 1652442116467,
                                                              "type": "kdeconnect.sftp",
                                                              "body": {
                                                                "ip": "192.168.1.223",
                                                                "port": 1746,
                                                                "user": "kdeconnect",
                                                                "password": "[redacted]",
                                                                "path": "/",
                                                                "multiPaths": [
                                                                  "/primary"
                                                                ],
                                                                "pathNames": [
                                                                  "primary"
                                                                ]
                                                              }
                                                            }
mei 13 13:41:57 gjs[3389]: JS ERROR: FP2: Gio.IOErrorEnum: Connection failed
                           _handleMount/</<@/home/matthijs/.local/share/gnome-shell/extensions/gsconnect@andyholmes.github.io/service/plugins/sftp.js:253:38
                           @/home/matthijs/.local/share/gnome-shell/extensions/gsconnect@andyholmes.github.io/service/daemon.js:727:17

System Details (please complete the following information):

GSConnect environment (if applicable):

andyholmes commented 2 years ago

Thanks for reporting!

Unfortunately there is no confirmation of a sent SMS message, so this would be difficult to fix in a robust way. The "pending" message itself is already a hack, so I'm not sure the UX could easily be improved there without causing other problems.

Contributions are always welcome of course :)

matthijskooijman commented 2 years ago

Unfortunately there is no confirmation of a sent SMS message

You mean that you cannot know if the phone actually sent the message? In this case, however, the message does not actually reaches the phone. I think that can be detected reliably, right? There is even an error message about this in the journal?

andyholmes commented 2 years ago

You mean that you cannot know if the phone actually sent the message?

When an Android phone completes sending a message it will move it from the "outbox" category to the "sent" category and should then send us an update for that message's thread.

However, there is no connection between the request we send and a database update we receive. GSConnect simply adds the "pending" message to the window and later if a database update includes a matching message it is removed. If the device disconnects all pending messages are cleared from the window (if they succeeded, we'll find out when we reconnect).

Of course sending a message could fail on the phone itself (eg. no service, bugs, etc), in which case we'll just never know.

In this case, however, the message does not actually reaches the phone. I think that can be detected reliably, right?

It can't, actually. Even if our function call has succeeded (no error), the packet may actually just be in an output buffer of GIO or the kernel, etc. It's also possible the remote device has the packet in its input buffer when the device disconnects.

There is even an error message about this in the journal?

If you mean this error:

[/service/core.js:readPacket/</<:233]: FP2: Error receiving data: Connection reset by peer
readPacket/</<@/home/matthijs/.local/share/gnome-shell/extensions/gsconnect@andyholmes.github.io/service/core.js:233:45
@/home/matthijs/.local/share/gnome-shell/extensions/gsconnect@andyholmes.github.io/service/daemon.js:727:17

This is a read error, which is the probably the most common way we find out a connection is closed. You'll notice there's no other error from attempting to send the packet since it was probably buffered.

So the only real datapoints we have are whether the device disconnects and elapsed time. A timer could be added, and after some period of time with no response the attempt could be considered failed, but that would require some guesswork about the connection state (ie. are we connected or are we just waiting for the keepalive to timeout? maybe the device or connection is just slow?).

I'm open to suggestions of how to handle this situation, I just don't see a reliable way to do that :slightly_smiling_face:

matthijskooijman commented 2 years ago

It can't, actually. Even if our function call has succeeded (no error), the packet may actually just be in an output buffer of GIO or the kernel, etc. It's also possible the remote device has the packet in its input buffer when the device disconnects.

Right, so the KDE connect protocol has no acks on individual messages? And I guess even if it has, then no ack does not always mean the message has not reached the phone...

Anyway, thanks for explaining how this all works, I can see how this is tricky to handle..

I'm open to suggestions of how to handle this situation, I just don't see a reliable way to do that

I can imagine that simply not clearing the pending message on disconnect could be helpful - then you at least preserve the text so the user can try again manually. Then things are a bit confusing when a message that is really lost in transmission is still shown as "pending", which could make the user believe that it is still trying to send it (possibly retrying) when it is really lost...

Maybe a part of this could be mitigated by checking if the message is present in the outbox and if (after a timeout, or maybe after a reconnect) it is not in the outbox (and not in sent either), mark it as failed (or maybe "Might have failed" to at least have some info)?

andyholmes commented 2 years ago

Sorry it took me awhile to respond, I've been fairly bust lately.

I can imagine that simply not clearing the pending message on disconnect could be helpful

Turns out I was wrong about that, it's actually cleared on re-connect. I'm guessing I did that because after reconnect, we are expecting an incoming database update.

https://github.com/GSConnect/gnome-shell-extension-gsconnect/blob/29456f27391fa61493121a53d82ba50bcf535e04/src/service/ui/messaging.js#L446-L449

Maybe a part of this could be mitigated by checking if the message is present in the outbox

Unfortunately we don't get updates for the "outbox" category, only the "sent" and "inbox" categories are included. The code for matching messages is also a lot simpler than I thought:

https://github.com/GSConnect/gnome-shell-extension-gsconnect/blob/29456f27391fa61493121a53d82ba50bcf535e04/src/service/ui/messaging.js#L667-L671

So isn't matching message text, instead it's assuming the next "sent" message in the database will either be the pending message (success) or a different sent message (failure).

It's possible to add a label to each pending message when the device disconnects, to the effect of "This message may have failed to send", but on reconnect I'm not sure about leaving them. I guess either way it's not the best UX for the user.

matthijskooijman commented 2 years ago

Sorry it took me awhile to respond, I've been fairly bust lately.

Same here ;-)

So isn't matching message text, instead it's assuming the next "sent" message in the database will either be the pending message (success) or a different sent message (failure).

Right, so that only works while still connected, since you trigger on on "new" message. After a reconnect, the message might have been sent already (while disconnected), so y

matthijskooijman commented 2 years ago

(w00ps, clicked comment too soon, here's the complete message):

Sorry it took me awhile to respond, I've been fairly bust lately.

Same here ;-)

So isn't matching message text, instead it's assuming the next "sent" message in the database will either be the pending message (success) or a different sent message (failure).

Right, so that only works while still connected, since you trigger on on "new" message. After a reconnect, the message might have been sent already (while disconnected). So to keep pending messages across a reconnect, you will indeed need to match based on text (and maybe also message time or index or so, to prevent matching a pending message against an old already sent message that happens to have the same text).

It's possible to add a label to each pending message when the device disconnects, to the effect of "This message may have failed to send", but on reconnect I'm not sure about leaving them. I guess either way it's not the best UX for the user.

I would say that losing data is worse UX than having an extra pending message that will never be sent.

Given the limitations you described, I think the best UX would be:

andyholmes commented 2 years ago

Okay, so I've pushed a PR which does the following:

Since I don't use GSConnect myself anymore, or have an easy way test changes like these, that's about as far as I'm comfortable going. The PR will still need user testing and a review, but I hope that improves the UX a little bit at least!