Menu ▾ ▴

#316 Adium SIPE crashes on Unlock of macOS Sierra

OBSOLETE_1.21.x
closed-invalid
nobody
None
Adium
5
2018-12-11
2016-10-21
Joe
No

Hello,

I'm using Adium version 1.5.11hgr5892 (27/07/14). And the SIPE 1.21.1 downloaded from the sourceforge.net.

It was working previously with OSX. Now I upgraded to macOS Sierra, and Adium wih SIPE still works. However, it seems that when I lock my Mac and then when I unlock most of the times, SIPE/Adium crashes.

You can find the

Adium Debug Log - http://pastebin.com/VZgvRESY - around line 697 - it seems to fail. Note that till the update of macOS, everything was working smoothly.

This is the log for the crash as reported by macOS - http://pastebin.com/uRfvUMZT

Please suggest.

Thanks,
Joe.

Discussion

  • Stefan Becker

    Stefan Becker - 2016-10-21

    Doesn't look like a SIPE crash. The log shows the last SIPE debug message at 11:26:47, whereas the crash happens somewhere during/after Adium prefs saving at 11:26:52.

    My guess this is either binary incompatibility issue (if you use pre-compiled binaries) or Adium problem on macOS Sierra.

    I leaning toward closing this as NOTABUG.

     

  • Stefan Becker

    Stefan Becker - 2016-10-21

    If I understand the crash log correctly then Adium is trying to request a password and that crashes because of a nil key:

    Crashing on exception: *** setObjectForKey: key cannot be nil
...
0   CoreFoundation                      0x00007fffbc3fb7bb __exceptionPreprocess + 171
1   libobjc.A.dylib                     0x00007fffd0b68a2a objc_exception_throw + 48
2   CoreFoundation                      0x00007fffbc2fbe55 -[__NSDictionaryM setObject:forKey:] + 1061
3   Adium                               0x00000001000f812b +[ESAccountPasswordPromptController showPasswordPromptForAccount:password:notifyingTarget:selector:context:] + 260
4   Adium                               0x00000001000f6e94 -[AdiumPasswords retrievedPassword:] + 295

    The only information in the crash log about SIPE is that you seem to have two SIPE plugins installed: 1,18,4 and 1,21.1:

           0x1068b6000 -        0x10692dff7 +net.sourceforge.sipe.SIPEAdiumPlugin ("pidgin-sipe 1.18.4" - "1.18.4") <D3283B8B-6DFD-37BD-BEBB-AB31C4302A86> /Users/USER/Library/Application Support/Adium 2.0/*/SIPEAdiumPlugin
       0x106947000 -        0x1069c6ff7 +net.sourceforge.sipe.SIPEAdiumPlugin ("pidgin-sipe 1.21.1" - "1.21.1") <E1ABF94D-B03E-3E16-BCBA-CA9FC5D7B50A> /Users/USER/Library/Application Support/Adium 2.0/*/SIPEAdiumPlugin

    I would try to find the old plugin and de-install it. Or de-install both and then re-install 1.21.1.

     

    Last edit: Stefan Becker 2016-10-21

  • Stefan Becker

    Stefan Becker - 2016-11-01
    • status: open --> closed-invalid
     

  • Stefan Becker

    Stefan Becker - 2016-11-01

    No further updates from reporter that would indicate that SIPE is causing this crash.

    Closing as NOTABUG for now...

     

  • Joe

    Joe - 2017-01-02

    Hi Stefan, Sorry I was tinkering with recompiling Adium as you had suggested. Eventually I succeded in doing it, but still the crash happened.

    So now I took the log again. This time I see a different crash report

    http://pastebin.com/HbtK55SW

    What I see is:

    MESSAGE END >>>>>>>>>> SIP - 2017-01-02T10:11:59.033971Z
11:11:59: (Libpurple: sipe) De-register from server. Flushing outstanding messages.
11:11:59: (Libpurple: cdsa) send got a premature termination
11:11:59: (Libpurple: sipe) Write error: Operation timed out (60)
11:11:59: (Libpurple: connection) Connection error on 0x6000020bec60 (reason: 0 description: Write error)
11:11:59: Connection Disconnected: gc=20bec60 (Write error)
11:11:59: <ESPurpleSIPEAccount:3052da50 11>:joe@us.mailserver.com accountConnectionReportDisconnect: Server has disconnected

    and

    11:11:59: (Libpurple: sipe) sipe_purple_transport_close_all: entered
11:11:59: Disconnected: gc=20bec60
11:11:59: <ESPurpleSIPEAccount:3052da50 11>:joe@us.mailserver.com: Telling the core we disconnected
11:11:59: -[AIContactObserverManager endListObjectNotificationsDelaysImmediately]:144: 
11:11:59: <ESPurpleSIPEAccount:3052da50 11>:joe@us.mailserver.com: Disconnected ("Server has disconnected"): Automatically reconnecting in 5.000000 seconds (0 attempts performed)
11:11:59: (Libpurple: connection) Destroying connection 0x6000020bec60

    This is what I have been seeing all along. It is diconnecting and reconnecting. I'm not able to exactly determine when this happens, but this keeps happening constantly.

    Any idea why this could happen.

     

  • Stefan Becker

    Stefan Becker - 2017-01-02

    Where is the "crash" in the log? I don't see any.

    The log only starts at the screen lock, so I can't see when the last message was sent from SIPE to the server (or vice versa). A minute after the unlock you start a chat:

    11:10:08: -[AIAutomaticStatus notificationHandler:]:254: Screenlock (start) detected.
11:10:22: -[AIAutomaticStatus notificationHandler:]:286: Screenlock (end) detected.
...
11:11:55: [AIChat: 1d6260 initForAccount]
...
11:11:58: (Libpurple: sipe)
MESSAGE START >>>>>>>>>> SIP - 2017-01-02T10:11:58.669630Z

    But instead of receiving something from the server the lower transport layer just returns an error, saying that the connection has been dropped by the server (timeout?). This leads to the disconnect of the account:

    MESSAGE END >>>>>>>>>> SIP - 2017-01-02T10:11:58.669630Z
11:11:58: (Libpurple: cdsa) receive got a premature termination
11:11:58: (Libpurple: sipe) Server has disconnected
11:11:58: (Libpurple: connection) Connection error on 0x6000020bec60 (reason: 0 description: Server has disconnected)
...
11:11:59: <ESPurpleSIPEAccount:3052da50 11>:joe@us.mailserver.com: Disconnected ("Server has disconnected"): Automatically reconnecting in 5.000000 seconds (0 attempts performed)

    After 5 seconds Adium automatically reconnects the account (as it has announced in the log):

    11:12:04: (ESPurpleSIPEAccount) Configuring account: joe@us.mailserver.com,megatrends.com\joe
...
11:12:04: (Libpurple: sipe) sipe_core_allocate: SIPE version 1.21.1 ( signin_name 'joe@us.mailserver.com'

    The rest of the log (ends at 11:12:10) is standard account login stuff.

    What follows is pure speculation: If I take your log at face value I would guess that macOS terminates/blocks active network connections when screenlock gets activated. Maybe Adium needs an update so that active connections are kept alive during screen lock?

     

  • Joe

    Joe - 2017-01-02

    Hello

    Yes, my bad. There is no real crash. But my SIPE connection keeps disconnecting and reconnecting constantly, even when while I'm actively using the system.

    http://pastebin.com/TXAurkHT

    I see the message premature termination If you see 13:24:27, at this point I was actively using my system and it got disconnected and reconnected.

    Earlier I had enabled FIrewall, but now I have added an exception to Adium in my firewall. Despite that, this disconnect reconnect is constantly happening.

    The only last possibility is that my server is really disconnecting, but I do not see this problem with my email client or other connections.

    What are your thoughts..

     

  • Stefan Becker

    Stefan Becker - 2017-01-02

    That log makes more sense. It shows two disconnects, both caused by SIPE sending an empty keep-alive message, e.g.

    13:13:46: (Libpurple: sipe) sipe_core_schedule_execute: executing <+keepalive-timeout>
...13:13:46: (Libpurple: sipe)
MESSAGE START >>>>>>>>>> SIP - 2017-01-02T12:13:46.983562Z
...
13:13:47: (Libpurple: cdsa) receive got a premature termination
13:13:47: (Libpurple: sipe) Server has disconnected
...
MESSAGE START <<<<<<<<<< SIP - 2017-01-02T12:13:54.829309Z
SIP/2.0 200 OK
ms-keep-alive: UAS; tcp=no; hop-hop=yes; end-end=no; timeout=300
...
Expires: 7200
...
13:13:54: (Libpurple: sipe) process_register_response: got response to REGISTER; expires = 7200
...
13:13:54: (Libpurple: sipe) scheduling action <registration> timeout 7170 seconds
...
13:13:54: (Libpurple: sipe) process_register_response: authentication handshake completed successfully
...
13:13:54: (Libpurple: sipe) scheduling action <+reauthentication> timeout 28500 seconds
...
13:13:54: (Libpurple: sipe) process_register_response: server determined keep alive timeout is 300 seconds

    After successful registration there is an idle period longer than the server provided timeout of 300 seconds (12:19:27 -> 12:24:27), so SIPE sends out keep-alive:

    MESSAGE END >>>>>>>>>> SIP - 2017-01-02T12:19:27.200205Z
13:23:50: (Libpurple: sipe) sipe_core_schedule_execute: executing <+keepalive-timeout>
...
13:23:50: (Libpurple: sipe) scheduling action <+keepalive-timeout> timeout 37 seconds
13:24:27: (Libpurple: sipe) sipe_core_schedule_execute: executing <+keepalive-timeout>
...
13:24:27: (Libpurple: sipe) keepalive_timeout: expired 300
13:24:27: (Libpurple: sipe)
MESSAGE START >>>>>>>>>> SIP - 2017-01-02T12:24:27.556960Z
...
13:24:27: (Libpurple: cdsa) receive got a premature termination
13:24:27: (Libpurple: sipe) Server has disconnected

    But it seems that the server (or a network node in the path?) has already terminated the TCP connection. I'm guessing that you should probably be able to see a TCP RST in a network protocol tracing tool during those long idle periods. Maybe it is even caused by MacOS itself, then you would need to fix a timeout setting there.

    IMHO this has nothing to do with screen lock at all. Screen lock will of course cause long idle periods, thus triggering this issue.

    One way to make avoid long idle periods is to enable calendar data publishing. As calendar data is refreshed every 5 minutes it will prevent running into the keep alive timeout.

     

  • Joe

    Joe - 2017-01-12

    Thanks for the hint. As you had said, eventually we found that it was an issue with the firewall, which was dropping the connection when there is no activity.

    Finally, I can continue using Adium + SIPE :)

     

  • Stefan Becker

    Stefan Becker - 2017-01-12

    Yes, firewall connection tracking would have been my educated guess. Good that is working for you now.

     

  • Stefan Becker

    Stefan Becker - 2017-06-22

    Joe, another Mac user seems to have the same issue (private bug [bugs:#327]). Can you maybe add a message here detailing what you changed in the (macOS?) firewall? That information would be valuable for the FAQ too.

     

    Related

    Bugs: #327

Log in to post a comment.