Not receiving incoming msgs

demure commented 4 years ago

Hi,

Over the last few days @thefinn93 has troubleshoot and fixed some errors I was experiencing with signald, among which was one where "unidentified" (a term thefinn93 used) contacts' messages would not appear. Now that I can again see incoming messages in netcat, I find that libpurple-signald is not seeing the incoming messages, or at least not properly sending them to my irc client via bitlbee (which has worked for me in the past).

On receiving an incoming message in signal, I see the following in my journalctl at the same time stamp:

Dec 26 21:41:45 vps-of-doom bitlbee[24662]: purple_find_conversation_with_account: assertion 'name != NULL' failed

And I believe that the following may correspond with my received receipts (from me to other user):

Dec 26 21:43:53 vps-of-doom bitlbee[24662]: g_string_insert_len: assertion 'len == 0 || val != NULL' failed

Please let me know if there is any more information I could provide, or steps I could take to further troubleshoot.

hoehermann commented 4 years ago

@demure Thank you for the report.

Incoming messages

I suspect, signald cannot determine the sender for an "unidentified" source. The sender's name is probably null and purple does not know what to do with it. I am just guessing, though, as I fail to produce such a message on purpose. Can you post a the JSON representation of a problematic message taken from netcat?

Receipts

This looks like a bug in signald. I opened an issue here: https://gitlab.com/thefinn93/signald/issues/19

demure commented 4 years ago

Here are some examples:

Me to Me

{                                                                                                                                                                                                                                                                                 
  "type": "message",                                                                                                                                                                                                                                                              
  "data": {                                                                                                                                                                                                                                                                       
    "username": "+ME",                                                                                                                                                                                                                                                   
    "hasUuid": false,                                                                                                                                                                                                                                                             
    "hasSource": true,                                                                                                                                                                                                                                                            
    "source": "+ME",                                                                                                                                                                                                                                                     
    "hasSourceDevice": true,                                                                                                                                                                                                                                                      
    "sourceDevice": 3,                                                                                                                                                                                                                                                            
    "type": 1,                                                                                                                                                                                                                                                                    
    "hasRelay": false,                                                                                                                                                                                                                                                            
    "timestamp": 1577414420777,                                                                                                                                                                                                                                                   
    "timestampISO": "2019-12-27T02:40:20.777Z",                                                                                                                                                                                                                                   
    "serverTimestamp": 1577414404252,                                                                                                                                                                                                                                             
    "hasLegacyMessage": false,                                                                                                                                                                                                                                                    
    "hasContent": true,                                                                                                                                                                                                                                                           
    "isSignalMessage": false,                                                                                                                                                                                                                                                     
    "isPrekeySignalMessage": false,                                                                                                                                                                                                                                               
    "isReceipt": false,                                                                                                                                                                                                                                                           
    "isUnidentifiedSender": false,                                                                                                                                                                                                                                                
    "syncMessage": {                                                                                                                                                                                                                                                              
      "sentMessage": {                                                                                                                                                                                                                                                            
        "timestamp": 1577414420777,                                                                                                                                                                                                                                               
        "message": "test4",                                                                                                                                                                                                                                                       
        "expiresInSeconds": 0,                                                                                                                                                                                                                                                    
        "attachments": []                                                                                                                                                                                                                                                         
      },                                                                                                                                                                                                                                                                          
      "contactsComplete": false                                                                                                                                                                                                                                                   
    }                                                                                                                                                                                                                                                                             
  }                                                                                                                                                                                                                                                                               
}

Me to Them

{                                                                                                                                                                                                                                                                                 
  "type": "message",                                                                                                                                                                                                                                                              
  "data": {                                                                                                                                                                                                                                                                       
    "username": "+ME",                                                                                                                                                                                                                                                   
    "hasUuid": false,                                                                                                                                                                                                                                                             
    "hasSource": true,                                                                                                                                                                                                                                                            
    "source": "+ME",                                                                                                                                                                                                                                                     
    "hasSourceDevice": true,                                                                                                                                                                                                                                                      
    "sourceDevice": 3,                                                                                                                                                                                                                                                            
    "type": 1,                                                                                                                                                                                                                                                                    
    "hasRelay": false,                                                                                                                                                                                                                                                            
    "timestamp": 1577415398206,                                                                                                                                                                                                                                                   
    "timestampISO": "2019-12-27T02:56:38.206Z",                                                                                                                                                                                                                                   
    "serverTimestamp": 1577415381909,                                                                                                                                                                                                                                             
    "hasLegacyMessage": false,                                                                                                                                                                                                                                                    
    "hasContent": true,                                                                                                                                                                                                                                                           
    "isSignalMessage": false,                                                                                                                                                                                                                                                     
    "isPrekeySignalMessage": false,                                                                                                                                                                                                                                               
    "isReceipt": false,                                                                                                                                                                                                                                                           
    "isUnidentifiedSender": false,                                                                                                                                                                                                                                                
    "syncMessage": {                                                                                                                                                                                                                                                              
      "sentMessage": {                                                                                                                                                                                                                                                            
        "timestamp": 1577415398206,                                                                                                                                                                                                                                               
        "message": "blah blah blah blah blah.",                                                                                                                                                                                    
        "expiresInSeconds": 0,                                                                                                                                                                                                                                                    
        "attachments": []                                                                                                                                                                                                                                                         
      },                                                                                                                                                                                                                                                                          
      "contactsComplete": false                                                                                                                                                                                                                                                   
    }                                                                                                                                                                                                                                                                             
  }                                                                                                                                                                                                                                                                               
}

Delivery?

{                                                                                                                                                                                                                                                                                 
  "type": "message",                                                                                                                                                                                                                                                              
  "data": {                                                                                                                                                                                                                                                                       
    "username": "+ME",                                                                                                                                                                                                                                                   
    "hasUuid": false,                                                                                                                                                                                                                                                             
    "hasSource": false,                                                                                                                                                                                                                                                           
    "hasSourceDevice": false,                                                                                                                                                                                                                                                     
    "sourceDevice": 0,                                                                                                                                                                                                                                                            
    "type": 6,                                                                                                                                                                                                                                                                    
    "hasRelay": false,                                                                                                                                                                                                                                                            
    "timestamp": 1577415449463,                                                                                                                                                                                                                                                   
    "timestampISO": "2019-12-27T02:57:29.463Z",                                                                                                                                                                                                                                   
    "serverTimestamp": 1577415450077,                                                                                                                                                                                                                                             
    "hasLegacyMessage": false,                                                                                                                                                                                                                                                    
    "hasContent": true,                                                                                                                                                                                                                                                           
    "isSignalMessage": false,                                                                                                                                                                                                                                                     
    "isPrekeySignalMessage": false,                                                                                                                                                                                                                                               
    "isReceipt": false,                                                                                                                                                                                                                                                           
    "isUnidentifiedSender": false,                                                                                                                                                                                                                                                
    "receipt": {                                                    
      "type": "DELIVERY",                                           
      "timestamps": [                                               
        1577415398206                                               
      ],                                                            
      "when": 1577415449463                                         
    }                                                               
  }                                                                 
}

Them to Me

{                                                                   
  "type": "message",                                                
  "data": {                                                         
    "username": "+ME",                                     
    "hasUuid": false,                                               
    "hasSource": false,                                             
    "hasSourceDevice": false,                                       
    "sourceDevice": 0,                                              
    "type": 6,                                                      
    "hasRelay": false,                                              
    "timestamp": 1577415486352,                                     
    "timestampISO": "2019-12-27T02:58:06.352Z",
    "serverTimestamp": 1577415486708,
    "hasLegacyMessage": false,                                      
    "hasContent": true,                                             
    "isSignalMessage": false,                                       
    "isPrekeySignalMessage": false,
    "isReceipt": false,                                             
    "isUnidentifiedSender": false,                                  
    "dataMessage": {                                                
      "timestamp": 1577415486352,                                   
      "message": "some message here",                                      
      "expiresInSeconds": 0,                                        
      "attachments": []                                             
    }                                                               
  }                                                                 
}
{                                                                   
  "type": "message",                                                
  "data": {                                                         
    "username": "+ME",                                     
    "hasUuid": false,                                               
    "hasSource": true,                                              
    "source": "+ME",                                       
    "hasSourceDevice": true,                                        
    "sourceDevice": 1,                                              
    "type": 1,                                                      
    "hasRelay": false,                                              
    "timestamp": 1577415523992,                                     
    "timestampISO": "2019-12-27T02:58:43.992Z",
    "serverTimestamp": 1577415524971,
    "hasLegacyMessage": false,                                      
    "hasContent": true,                                             
    "isSignalMessage": false,                                       
    "isPrekeySignalMessage": false,
    "isReceipt": false,                                             
    "isUnidentifiedSender": false,                                  
    "syncMessage": {                                                
      "contactsComplete": false,                                    
      "readMessages": [                                             
        {                                                           
          "sender": "+THEM",
          "timestamp": 1577415486352
        }                                                           
      ]                                                             
    }                                                               
  }                                                                 
}

Them to Me Quoting Me

{                                                                                                                                                                                                                                                                                 
  "type": "message",                                                                                                                                                                                                                                                              
  "data": {                                                                                                                                                                                                                                                                       
    "username": "+ME",                                                                                                                                                                                                                                                   
    "hasUuid": false,                                               
    "hasSource": false,                                             
    "hasSourceDevice": false,                                       
    "sourceDevice": 0,                                              
    "type": 6,                                                      
    "hasRelay": false,                                              
    "timestamp": 1577415602953,                                     
    "timestampISO": "2019-12-27T03:00:02.953Z",
    "serverTimestamp": 1577415603313,
    "hasLegacyMessage": false,                                      
    "hasContent": true,                                             
    "isSignalMessage": false,                                       
    "isPrekeySignalMessage": false,
    "isReceipt": false,                                             
    "isUnidentifiedSender": false,                                  
    "dataMessage": {                                                
      "timestamp": 1577415602953,                                   
      "message": "Haha I suppose that's true",
      "expiresInSeconds": 0,                                        
      "attachments": [],                                            
      "quote": {                                                    
        "id": 1577415543169,                                        
        "author": {                                                 
          "e164number": "+ME",
          "relay": {                                                
            "present": false                                        
          },                                                        
          "number": "+ME"                                  
        },                                                          
        "text": "If it gets fixed, things will be tasty again",
        "attachments": []                                           
      }                                                             
    }                                                               
  }                                                                 
}  
{                                                                   
  "type": "message",                                                
  "data": {                                                         
    "username": "+ME",                                     
    "hasUuid": false,                                               
    "hasSource": true,                                              
    "source": "+ME",                                       
    "hasSourceDevice": true,                                        
    "sourceDevice": 1,                                              
    "type": 1,                                                      
    "hasRelay": false,                                              
    "timestamp": 1577415621949,                                     
    "timestampISO": "2019-12-27T03:00:21.949Z",
    "serverTimestamp": 1577415623735,
    "hasLegacyMessage": false,                                      
    "hasContent": true,                                             
    "isSignalMessage": false,                                       
    "isPrekeySignalMessage": false,
    "isReceipt": false,                                             
    "isUnidentifiedSender": false,                                  
    "syncMessage": {                                                
      "contactsComplete": false,                                    
      "readMessages": [                                             
        {                                                           
          "sender": "+THEM",
          "timestamp": 1577415602953
        }                                                           
      ]                                                             
    }                                                               
  }                                                                 
}

thefinn93 commented 4 years ago

Hey there, thanks for filing the bug on signald, parsing these messages is pretty confusing. I just wanted to clear a few things up:

UnidentifiedAccess/Sealed Sender is a feature of signal where clients can send messages without identifying/authenticating themselves to the Signal server. Here's a blog post about it. Sealed sender should not affect signald receiving messages (please let me know if you're able to find some evidence to the contrary, I need to test this further).
Most of these messages are generated directly or indirectly from Signal objects, and they aren't always the most straight forward.
As best I can tell, dataMessage is an "actual" message, ie. has a sender and a receiver and a body and maybe attachments and whatever else. syncMessage is some sort of meta message like group changes, message delivered/read, and syncing of preferences/contacts/other stuff between devices on the same account.

I created a page wiki page document this sort of thing yesterday, I'll try to expand it as I get time. The Signal protocol is pretty confusing and seems to change somewhat frequently.

hoehermann commented 4 years ago

@thefinn93 Thank you for the explanation.

@demure Thank you for the snippets. They are very insightful. Many of those messages do not have a "source" field. As @thefinn93 explains, there is not much we can do about it. Without a source, I do not know from which contact the message originates and I cannot do anything useful with it. I decided to assign those messages to a fake "unknown" contact. A binary is located here: https://ssl.hehoe.de/temp/libsignald_x86_64.so It works just as good as the previous version for everything I do. It would be great if you could test it, too.

demure commented 4 years ago

@hoehermann I've renamed and placed the linked libsinald.so into my /usr/lib/purple-2 (I'm using the debian sid distribution of bitlbee-libpurple), and have not seen incoming messages in bitlbee after words. Though I've only really been talking with one contact today.

thefinn93 commented 4 years ago

After investigating further, I noticed that signald does not properly support all of the possible types of sync messages, including the SentTranscriptMessage type, which is what I think we're seeing here. I'm hoping to get this fixed ASAP.

thefinn93 commented 4 years ago

Okay, I just pushed a fix for the SentTranscriptMessage, so you should now be able to see the destination of the message correctly. It should look like this.

This is in the latest master

hoehermann commented 4 years ago

https://ssl.hehoe.de/temp/libsignald_x86_64.so has been updated. No functional change for me, but maybe it now works better for @demure.

@thefinn93 I see these happening:

[socketlistener] ERROR io.finn.signald.SocketHandler - Catching
java.nio.channels.OverlappingFileLockException: null
    at sun.nio.ch.FileLockTable.checkList(FileLockTable.java:229) ~[?:?]
    at sun.nio.ch.FileLockTable.add(FileLockTable.java:123) ~[?:?]
    at sun.nio.ch.FileChannelImpl.tryLock(FileChannelImpl.java:1154) ~[?:?]
    at java.nio.channels.FileChannel.tryLock(FileChannel.java:1165) ~[?:?]
    at io.finn.signald.Manager.openFileChannel(Manager.java:262) ~[signald.jar:unspecified]
    at io.finn.signald.Manager.load(Manager.java:288) ~[signald.jar:unspecified]
    at io.finn.signald.Manager.init(Manager.java:271) ~[signald.jar:unspecified]
    at io.finn.signald.SocketHandler.getManager(SocketHandler.java:354) ~[signald.jar:unspecified]
    at io.finn.signald.SocketHandler.listContacts(SocketHandler.java:504) ~[signald.jar:unspecified]
    at io.finn.signald.SocketHandler.handleRequest(SocketHandler.java:188) [signald.jar:unspecified]
    at io.finn.signald.SocketHandler.run(SocketHandler.java:125) [signald.jar:unspecified]
    at java.lang.Thread.run(Thread.java:834) [?:?]

They do not seem to be harmful, though.

thefinn93 commented 4 years ago

I've seen that happen sometimes, I'm not sure what causes it, I'm hoping that an upcoming refactor will improve handling around file locking and storage access.

demure commented 4 years ago

Ok, with the most recent pull of signald and the linked .so I have some progress :)

{
  "type": "message",
  "data": {
    "username": "+ME",
    "hasUuid": false,
    "hasSource": false,
    "hasSourceDevice": false,
    "sourceDevice": 0,
    "type": 6,
    "hasRelay": false,
    "timestamp": 1577658901874,
    "timestampISO": "2019-12-29T22:35:01.874Z",
    "serverTimestamp": 1577658903127,
    "hasLegacyMessage": false,
    "hasContent": true,
    "isSignalMessage": false,
    "isPrekeySignalMessage": false,
    "isReceipt": false,
    "isUnidentifiedSender": false,
    "dataMessage": {
      "timestamp": 1577658901874,
      "message": "redacted conversation text",
      "expiresInSeconds": 0,
      "attachments": []
    }
  }
}
{
  "type": "message",
  "data": {
    "username": "+ME",
    "hasUuid": false,
    "hasSource": true,
    "source": "+ME",
    "hasSourceDevice": true,
    "sourceDevice": 3,
    "type": 1,
    "hasRelay": false,
    "timestamp": 1577658976609,
    "timestampISO": "2019-12-29T22:36:16.609Z",
    "serverTimestamp": 1577658959455,
    "hasLegacyMessage": false,
    "hasContent": true,
    "isSignalMessage": false,
    "isPrekeySignalMessage": false,
    "isReceipt": false,
    "isUnidentifiedSender": false,
    "syncMessage": {
      "contactsComplete": false,
      "readMessages": [
        {
          "sender": "+THEM",
          "timestamp": 1577658901874
        }
      ],
      "stickerPackOperations": []
    }
  }
}

The second json was a bit delayed, and in bitlbee displayed the contact (nick) as "unknown". No errors in journalctl from bitlbee

hoehermann commented 4 years ago

The "unknown" contact is inconvenient, but as long as the data.source is not existent, there is nothing I can do. At least the message is not lost. This is as good as it gets right now.

demure commented 4 years ago

It looks like @thefinn93 's modifications from last night to signald have allowed by to again see incoming messages in bitlbee via libpurple-signald.

It looks like I am not currently seeing reply's I make via another device, but I don't recall if I could before (and I have had other bitlbee plugins where you don't see your side before).

Them to Me

{
  "type": "message",
  "data": {
    "username": "+ME",
    "source": "+THEM",
    "sourceDevice": 0,
    "type": 6,
    "timestamp": 1577816692341,
    "timestampISO": "2019-12-31T18:24:52.341Z",
    "serverTimestamp": 1577816693388,
    "hasLegacyMessage": false,
    "hasContent": true,
    "isReceipt": false,
    "isUnidentifiedSender": true,
    "dataMessage": {
      "timestamp": 1577816692341,
      "message": "some talking here",
      "expiresInSeconds": 0,
      "attachments": []
    }
  }
}
{
  "type": "message",
  "data": {
    "username": "+ME",
    "source": "+ME",
    "sourceDevice": 1,
    "type": 1,
    "timestamp": 1577816703522,
    "timestampISO": "2019-12-31T18:25:03.522Z",
    "serverTimestamp": 1577816703250,
    "hasLegacyMessage": false,
    "hasContent": true,
    "isReceipt": false,
    "isUnidentifiedSender": false,
    "syncMessage": {
      "contactsComplete": false,
      "readMessages": [
        {
          "sender": "+THEM",
          "timestamp": 1577816692341
        }
      ],
      "stickerPackOperations": []
    }
  }
}

Me to Them via phone

{
  "type": "message",
  "data": {
    "username": "+ME",
    "source": "+ME",
    "sourceDevice": 1,
    "type": 1,
    "timestamp": 1577817224029,
    "timestampISO": "2019-12-31T18:33:44.029Z",
    "serverTimestamp": 1577817224058,
    "hasLegacyMessage": false,
    "hasContent": true,
    "isReceipt": false,
    "isUnidentifiedSender": false,
    "syncMessage": {
      "sent": {
        "destination": "+THEM",
        "timestamp": 1577817224029,
        "expirationStartTimestamp": 0,
        "message": {
          "timestamp": 1577817224029,
          "message": "me talking here",
          "expiresInSeconds": 0,
          "attachments": [],
          "quote": {
            "id": 1577816785360,
            "author": {
              "e164number": "+THEM",
              "relay": {
                "present": false
              },
              "number": "+THEM"
            },
            "text": "quoted text here",
            "attachments": []
          }
        },
        "unidentifiedStatus": {
          "+THEM": true
        },
        "isRecipientUpdate": false
      },
      "contactsComplete": false,
      "stickerPackOperations": []
    }
  }
}

hoehermann commented 4 years ago

@demure I just fed a copy of the "Me to Them via phone" JSON you supplied. It works fine for me in Pidgin. I cannot tell what happens differently in bitlbee. :( signald_demure_metothemviaphone

demure commented 4 years ago

Ok, after reverting to the git version of the so file (and pulling) I have regained the ability to see msgs from me that originated on other devices.

In it's place, I notice that the one signal group that I chat in (where I post a lot of pictures and am the sole talker normally) is now displayed with the litter name of '_' (underscore) as opposed to the long string name it had prior to the original issue.

{                                                                                                                                                                                                                 
  "type": "message",
  "data": {
    "username": "+ME",
    "source": "+ME",
    "sourceDevice": 1,
    "type": 1,
    "timestamp": 1578074823793,
    "timestampISO": "2020-01-03T18:07:03.793Z",
    "serverTimestamp": 1578074824905,
    "hasLegacyMessage": false,
    "hasContent": true,
    "isReceipt": false,
    "isUnidentifiedSender": false,
    "syncMessage": {
      "sent": {
        "destination": "",
        "timestamp": 1578074823793,
        "expirationStartTimestamp": 0,
        "message": {
          "timestamp": 1578074823793,
          "message": "Hoping this haven't been posted already https://imgur.com/gallery/xVedp6w",
          "expiresInSeconds": 0,
          "attachments": [],
          "groupInfo": {
            "groupId": "longStringHere",
            "name": "cute/wtf",
            "type": "DELIVER"
          },
          "previews": [
            {
              "url": "https://imgur.com/gallery/xVedp6w",
              "title": "Hoping this haven't been posted already",
              "attachment": {
                "contentType": "image/jpeg",
                "id": 5399600476783220000,
                "size": 115881,
                "width": 900,
                "height": 635,
                "voiceNote": false,
                "preview": {
                  "present": false
                },
                "key": "redacted",
                "digest": "redacted",
                "blurhash": "redacted"
              }
            }
          ]
        },
        "unidentifiedStatus": {
          "+THEM1": true,
          "+THEM2": false
        },
        "isRecipientUpdate": false
      },
      "contactsComplete": false,
      "stickerPackOperations": []
    }
  }
}

I suppose it would make sense to close the ticket now, as the original issue, and tangential issue, are now corrected.

hoehermann commented 4 years ago

@demure Thank you for the valuable input. With the data you supplied, I was able to add handling of group information for sync messages. :) https://ssl.hehoe.de/temp/libsignald_x86_64.so has been updated.

hoehermann / purple-signald