Menu

#216 SIPE Stops working on Mavericks

OBSOLETE_(1.17.x)
closed-invalid
nobody
None
Adium
5
2016-04-23
2013-10-16
Jon Anhold
No

Upgraded to Mavericks, now get an "Error: Read error" when trying to connect to OCS.

Related

Bugs: #235
Bugs: #295
Release Notes: 2014/01/pidgin-sipe-release-1180

Discussion

1 2 3 > >> (Page 1 of 3)
  • Stefan Becker

    Stefan Becker - 2013-10-16
    • status: open --> closed-invalid
     
  • Stefan Becker

    Stefan Becker - 2013-10-16

    You mean Ubuntu 10.10?

    No log provided. So I'm assuming this is FAQ issue.

    Closing as INVALID.

     
  • Jon Anhold

    Jon Anhold - 2013-10-16

    No, Mac OS X 10.9. Here's a log:

    11:55:53: -[AIAccount(Abstract) retrievePasswordThenConnect]:448: Retrieving <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM's password (promptOption 2)
    11:55:53: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: isOnline
    11:55:53: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: Enabled
    11:55:53: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: FullNameAttr
    11:55:53: -[CBPurpleAccount setAccountUserImage:withData:]:2717: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Setting icon data of length 0
    11:55:53: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: User Icon
    11:55:53: Adium: Connect: USER.NAME@DOMAIN.COM initiating connection using status state <AIStatus: 449660="" <span="">[Available]> ((null)).
    11:55:53: Setting status on 343b20 (USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME): ID available, isActive 1, attributes {
    }
    11:55:53: (GLib): (11:55:53) account: Connecting to account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME.
    11:55:53: (Libpurple: account) Connecting to account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME.
    11:55:53: (GLib): (11:55:53) connection: Connecting. gc = 0x608007ab3860
    11:55:53: (Libpurple: connection) Connecting. gc = 0x608007ab3860
    11:55:53: (GLib : general): CRITICAL: purple_notify_close_with_handle: assertion handle != NULL' failed 11:55:53: (GLib : general): CRITICAL: purple_request_close_with_handle: assertionhandle != NULL' failed
    11:55:53: void adiumPurpleRequestClose(PurpleRequestType, void *):416: (null) (0)
    11:55:57: (GLib): (11:55:57) sipe: sipe_purple_login: username 'USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME'
    11:55:57: (Libpurple: sipe) sipe_purple_login: username 'USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME'
    11:55:57: (GLib): (11:55:57) sipe: sipe_purple_login: login 'ROSETTA\USER.NAME'
    11:55:57: (Libpurple: sipe) sipe_purple_login: login 'ROSETTA\USER.NAME'
    11:55:57: (GLib): (11:55:57) sipe: sipe_purple_login: auth domain 'ROSETTA' user 'USER.NAME'
    11:55:57: (Libpurple: sipe) sipe_purple_login: auth domain 'ROSETTA' user 'USER.NAME'
    11:55:57: (GLib): (11:55:57) sipe: sipe_core_allocate: SIPE version 1.16.1 signin_name 'USER.NAME@DOMAIN.COM'
    11:55:57: (Libpurple: sipe) sipe_core_allocate: SIPE version 1.16.1 signin_name 'USER.NAME@DOMAIN.COM'
    11:55:57: (GLib): (11:55:57) sipe: sipe_core_allocate: user 'USER.NAME' domain 'DOMAIN.COM'
    11:55:57: (Libpurple: sipe) sipe_core_allocate: user 'USER.NAME' domain 'DOMAIN.COM'
    11:55:57: Connecting: gc=0x7ab3860 (Connecting) 1 / 2
    11:55:57: (GLib): (11:55:57) sipe: sipe_core_connect: user specified SIP server rosetta_pool1.DOMAIN.COM:5061
    11:55:57: (Libpurple: sipe) sipe_core_connect: user specified SIP server rosetta_pool1.DOMAIN.COM:5061
    11:55:57: (GLib): (11:55:57) sipe: transport_connect - hostname: rosetta_pool1.DOMAIN.COM port: 5061
    11:55:57: (Libpurple: sipe) transport_connect - hostname: rosetta_pool1.DOMAIN.COM port: 5061
    11:55:57: (GLib): (11:55:57) sipe: using SSL
    11:55:57: (Libpurple: sipe) using SSL
    11:55:57: (GLib): (11:55:57) dnsquery: Performing DNS lookup for rosetta_pool1.DOMAIN.COM
    11:55:57: (Libpurple: dnsquery) Performing DNS lookup for rosetta_pool1.DOMAIN.COM
    11:55:57: ** USER.NAME@DOMAIN.COM --step-- 1
    11:55:57: -[AdiumPurpleDnsRequest startLookup]:198: Performing DNS resolve: rosetta_pool1.DOMAIN.COM:5061
    11:55:57: DNS resolve complete for rosetta_pool1.DOMAIN.COM:5061; 1 addresses returned
    11:55:57: (GLib): (11:55:57) dnsquery: IP resolved for rosetta_pool1.DOMAIN.COM
    11:55:57: (Libpurple: dnsquery) IP resolved for rosetta_pool1.DOMAIN.COM
    11:55:57: (GLib): (11:55:57) proxy: Attempting connection to 10.98.10.173
    11:55:57: (Libpurple: proxy) Attempting connection to 10.98.10.173
    11:55:57: (GLib): (11:55:57) proxy: Connecting to rosetta_pool1.DOMAIN.COM:5061 with no proxy
    11:55:57: (Libpurple: proxy) Connecting to rosetta_pool1.DOMAIN.COM:5061 with no proxy
    11:55:57: (GLib): (11:55:57) proxy: Connection in progress
    11:55:57: (Libpurple: proxy) Connection in progress
    11:55:57: (GLib): (11:55:57) proxy: Connecting to rosetta_pool1.DOMAIN.COM:5061.
    11:55:57: (Libpurple: proxy) Connecting to rosetta_pool1.DOMAIN.COM:5061.
    11:55:57: (GLib): (11:55:57) proxy: Connected to rosetta_pool1.DOMAIN.COM:5061.
    11:55:57: (Libpurple: proxy) Connected to rosetta_pool1.DOMAIN.COM:5061.
    11:55:57: (GLib): (11:55:57) cdsa: Connecting
    11:55:57: (Libpurple: cdsa) Connecting
    11:55:57: (GLib): (11:55:57) cdsa: Connecting
    11:55:57: (Libpurple: cdsa) Connecting
    11:55:57: (GLib): (11:55:57) cdsa: Connecting
    11:55:57: (Libpurple: cdsa) Connecting
    11:55:57: (GLib): (11:55:57) cdsa: Connecting
    11:55:57: (Libpurple: cdsa) Connecting
    11:55:57: (GLib): (11:55:57) cdsa: SSL_connect: verifying certificate
    11:55:57: (Libpurple: cdsa) SSL_connect: verifying certificate
    11:55:57: (GLib): (11:55:57) cdsa: SSL_connect complete
    11:55:57: (Libpurple: cdsa) SSL_connect complete
    11:55:57: (GLib): (11:55:57) stun: using server
    11:55:57: (Libpurple: stun) using server
    11:55:57: (GLib): (11:55:57) stun: using server
    11:55:57: (Libpurple: stun) using server
    11:55:57: (GLib): (11:55:57) stun: using server
    11:55:57: (Libpurple: stun) using server
    11:55:57: (GLib): (11:55:57) sipe: sipe_schedule_allocate timeouts count 1 after addition
    11:55:57: (Libpurple: sipe) sipe_schedule_allocate timeouts count 1 after addition
    11:55:57: (GLib): (11:55:57) sipe: scheduling action <transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><1 REGISTER> timeout 60 seconds
    11:55:57: (Libpurple: sipe) scheduling action <transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><1 REGISTER> timeout 60 seconds
    11:55:57: (GLib): (11:55:57) sipe: SIP transactions count:1 after addition
    11:55:57: (Libpurple: sipe) SIP transactions count:1 after addition
    11:55:57: (GLib): (11:55:57) sipe:
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:55:57.897228Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49347;branch=z9hG4bK6BEDCCB854E446706C6D
    From: sip:USER.NAME@DOMAIN.COM;tag=4329640604;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 1 REGISTER
    User-Agent: Purple/2.10.7 Sipe/1.16.1 (macosx-x86_64; )
    Call-ID: 7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x
    Contact: <sip:127.94.0.1:49347;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:55:57.897228Z
    11:55:57: (Libpurple: sipe)
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:55:57.897228Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49347;branch=z9hG4bK6BEDCCB854E446706C6D
    From: sip:USER.NAME@DOMAIN.COM;tag=4329640604;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 1 REGISTER
    User-Agent: Purple/2.10.7 Sipe/1.16.1 (macosx-x86_64; )
    Call-ID: 7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x
    Contact: <sip:127.94.0.1:49347;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:55:57.897228Z
    11:55:57: (GLib): (11:55:57) cdsa: Using cipher 2f.
    11:55:57: (Libpurple: cdsa) Using cipher 2f.
    11:55:57: (GLib): (11:55:57) sipe: transport_input_common: new buffer length 4096
    11:55:57: (Libpurple: sipe) transport_input_common: new buffer length 4096
    11:55:57: (GLib): (11:55:57) sipe:
    MESSAGE START <<<<<<<<<< SIP - 2013-10-16T15:55:57.946654Z
    SIP/2.0 401 Unauthorized
    Date: Wed, 16 Oct 2013 15:55:57 GMT
    WWW-Authenticate: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    WWW-Authenticate: Kerberos realm="SIP Communications Service", targetname="sip/SWP00OCS00E.DOMAIN.COM", version=4
    From: sip:USER.NAME@DOMAIN.COM;tag=4329640604;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM;tag=E5D48C0E0B7CCB7C54C72D07BD67C9AA
    Call-ID: 7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x
    CSeq: 1 REGISTER
    Via: SIP/2.0/tls 127.94.0.1:49347;branch=z9hG4bK6BEDCCB854E446706C6D;received=10.4.37.17;ms-received-port=49347;ms-received-cid=5E95A00
    Content-Length: 0

    MESSAGE END <<<<<<<<<< SIP - 2013-10-16T15:55:57.946654Z
    11:55:57: (Libpurple: sipe)
    MESSAGE START <<<<<<<<<< SIP - 2013-10-16T15:55:57.946654Z
    SIP/2.0 401 Unauthorized
    Date: Wed, 16 Oct 2013 15:55:57 GMT
    WWW-Authenticate: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    WWW-Authenticate: Kerberos realm="SIP Communications Service", targetname="sip/SWP00OCS00E.DOMAIN.COM", version=4
    From: sip:USER.NAME@DOMAIN.COM;tag=4329640604;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM;tag=E5D48C0E0B7CCB7C54C72D07BD67C9AA
    Call-ID: 7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x
    CSeq: 1 REGISTER
    Via: SIP/2.0/tls 127.94.0.1:49347;branch=z9hG4bK6BEDCCB854E446706C6D;received=10.4.37.17;ms-received-port=49347;ms-received-cid=5E95A00
    Content-Length: 0

    MESSAGE END <<<<<<<<<< SIP - 2013-10-16T15:55:57.946654Z
    11:55:57: (GLib): (11:55:57) sipe: process_input_message: msg->response(401),msg->method(REGISTER)
    11:55:57: (Libpurple: sipe) process_input_message: msg->response(401),msg->method(REGISTER)
    11:55:57: (GLib): (11:55:57) sipe: process_input_message: RE-REGISTER CSeq: 1
    11:55:57: (Libpurple: sipe) process_input_message: RE-REGISTER CSeq: 1
    11:55:57: (GLib): (11:55:57) sipe: process_input_message: we have a transaction callback
    11:55:57: (Libpurple: sipe) process_input_message: we have a transaction callback
    11:55:57: (GLib): (11:55:57) sipe: process_register_response: got response to REGISTER; expires = 0
    11:55:57: (Libpurple: sipe) process_register_response: got response to REGISTER; expires = 0
    11:55:57: (GLib): (11:55:57) sipe: process_register_response: REGISTER retries 1
    11:55:57: (Libpurple: sipe) process_register_response: REGISTER retries 1
    11:55:57: (GLib): (11:55:57) sipe: process_register_response: Auth header: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    11:55:57: (Libpurple: sipe) process_register_response: Auth header: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    11:55:57: (GLib): (11:55:57) stun: using server
    11:55:57: (Libpurple: stun) using server
    11:55:57: (GLib): (11:55:57) stun: using server
    11:55:57: (Libpurple: stun) using server
    11:55:57: (GLib): (11:55:57) sipe: sip_sec_create_context: type: 2, Single Sign-On: no, protocol: SIP
    11:55:57: (Libpurple: sipe) sip_sec_create_context: type: 2, Single Sign-On: no, protocol: SIP
    11:55:57: (GLib): (11:55:57) sipe: sip_sec_init_sec_contextntlm: in use
    11:55:57: (Libpurple: sipe) sip_sec_init_sec_context
    ntlm: in use
    11:55:57: (GLib): (11:55:57) sipe: sipe_schedule_allocate timeouts count 2 after addition
    11:55:57: (Libpurple: sipe) sipe_schedule_allocate timeouts count 2 after addition
    11:55:57: (GLib): (11:55:57) sipe: scheduling action <transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><2 REGISTER> timeout 60 seconds
    11:55:57: (Libpurple: sipe) scheduling action <transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><2 REGISTER> timeout 60 seconds
    11:55:57: (GLib): (11:55:57) sipe: SIP transactions count:2 after addition
    11:55:57: (Libpurple: sipe) SIP transactions count:2 after addition
    11:55:57: (GLib): (11:55:57) sipe:
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:55:57.951625Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49347;branch=z9hG4bK0D49631BA136F2F61790
    From: sip:USER.NAME@DOMAIN.COM;tag=48436955;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 2 REGISTER
    User-Agent: Purple/2.10.7 Sipe/1.16.1 (macosx-x86_64; )
    Call-ID: 7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x
    Contact: <sip:127.94.0.1:49347;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0
    Authorization: NTLM qop="auth", realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", gssapi-data="", version=4

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:55:57.951625Z
    11:55:57: (Libpurple: sipe)
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:55:57.951625Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49347;branch=z9hG4bK0D49631BA136F2F61790
    From: sip:USER.NAME@DOMAIN.COM;tag=48436955;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 2 REGISTER
    User-Agent: Purple/2.10.7 Sipe/1.16.1 (macosx-x86_64; )
    Call-ID: 7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x
    Contact: <sip:127.94.0.1:49347;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0
    Authorization: NTLM qop="auth", realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", gssapi-data="", version=4

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:55:57.951625Z
    11:55:57: (GLib): (11:55:57) sipe: process_input_message: removing CSeq 2
    11:55:57: (Libpurple: sipe) process_input_message: removing CSeq 2
    11:55:57: (GLib): (11:55:57) sipe: SIP transactions count:1 after removal
    11:55:57: (Libpurple: sipe) SIP transactions count:1 after removal
    11:55:57: (GLib): (11:55:57) sipe: sipe_schedule_remove: action name=<transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><1 REGISTER>
    11:55:57: (Libpurple: sipe) sipe_schedule_remove: action name=<transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><1 REGISTER>
    11:55:58: (GLib): (11:55:58) cdsa: receive failed (-9806): Connection reset by peer
    11:55:58: (Libpurple: cdsa) receive failed (-9806): Connection reset by peer
    11:55:58: (GLib): (11:55:58) sipe: Read error: Connection reset by peer (54)
    11:55:58: (Libpurple: sipe) Read error: Connection reset by peer (54)
    11:55:58: (GLib): (11:55:58) connection: Connection error on 0x608007ab3860 (reason: 0 description: Read error)
    11:55:58: (Libpurple: connection) Connection error on 0x608007ab3860 (reason: 0 description: Read error)
    11:55:58: Connection Disconnected: gc=7ab3860 (Read error)
    11:55:58: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM accountConnectionReportDisconnect: Read error
    11:55:58: (GLib): (11:55:58) account: Disconnecting account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME (0x608000343b20)
    11:55:58: (Libpurple: account) Disconnecting account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME (0x608000343b20)
    11:55:58: (GLib): (11:55:58) connection: Disconnecting connection 0x608007ab3860
    11:55:58: (Libpurple: connection) Disconnecting connection 0x608007ab3860
    11:55:58: (GLib): (11:55:58) sipe: SIP transactions count:0 after removal
    11:55:58: (Libpurple: sipe) SIP transactions count:0 after removal
    11:55:58: (GLib): (11:55:58) sipe: sipe_schedule_remove: action name=<transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><2 REGISTER>
    11:55:58: (Libpurple: sipe) sipe_schedule_remove: action name=<transaction timeout=""><7072g5D0CaCB71iA7A8m416Ft1D55bDB80xC6F6x><2 REGISTER>
    11:55:58: (GLib : GLib): CRITICAL: g_hash_table_destroy: assertion hash_table != NULL' failed 11:55:58: (GLib): (11:55:58) sipe: sipe_purple_dns_query_cancel_all: entered 11:55:58: (Libpurple: sipe) sipe_purple_dns_query_cancel_all: entered 11:55:58: (GLib): (11:55:58) sipe: sipe_purple_transport_close_all: entered 11:55:58: (Libpurple: sipe) sipe_purple_transport_close_all: entered 11:55:58: Disconnected: gc=7ab3860 11:55:58: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Telling the core we disconnected 11:55:58: -[AIContactObserverManager endListObjectNotificationsDelaysImmediately]:144: 11:55:58: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Disconnected ("Read error"): Automatically reconnecting in 5.000000 seconds (0 attempts performed) 11:55:58: (GLib): (11:55:58) connection: Destroying connection 0x608007ab3860 11:55:58: (Libpurple: connection) Destroying connection 0x608007ab3860 11:55:58: (GLib): (11:55:58) util: Writing file accounts.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple 11:55:58: (Libpurple: util) Writing file accounts.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple 11:55:58: (GLib): (11:55:58) util: Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml 11:55:58: (Libpurple: util) Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml 11:55:58: (GLib): (11:55:58) util: Writing file blist.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple 11:55:58: (Libpurple: util) Writing file blist.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple 11:55:58: (GLib): (11:55:58) util: Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml 11:55:58: (Libpurple: util) Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml 11:55:58: gboolean adium_source_remove(guint):63: Source info for 107 not found 11:55:59: gboolean adium_source_remove(guint):63: Source info for 114 not found 11:55:59: gboolean adium_source_remove(guint):63: Source info for 116 not found 11:56:00: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: isOnline 11:56:00: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: Enabled 11:56:00: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: FullNameAttr 11:56:57: -[CBPurpleAccount setAccountUserImage:withData:]:2717: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Setting icon data of length 0 11:56:57: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: User Icon 11:56:57: -[CBPurpleAccount setAccountUserImage:withData:]:2717: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Setting icon data of length 0 11:56:57: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: User Icon 11:56:57: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: FullNameAttr 11:56:57: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: Check Mail 11:56:59: -[AIAccount(Abstract) retrievePasswordThenConnect]:448: Retrieving <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM's password (promptOption 2) 11:56:59: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: isOnline 11:56:59: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: Enabled 11:56:59: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: FullNameAttr 11:56:59: -[CBPurpleAccount setAccountUserImage:withData:]:2717: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Setting icon data of length 0 11:56:59: <ESPurpleSIPEAccount:30610a0 4>:USER.NAME@DOMAIN.COM: Updating status for key: User Icon 11:56:59: Adium: Connect: USER.NAME@DOMAIN.COM initiating connection using status state <AIStatus: 449660 [Available]> ((null)). 11:56:59: Setting status on 343b20 (USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME): ID available, isActive 1, attributes { } 11:56:59: (GLib): (11:56:59) account: Connecting to account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME. 11:56:59: (Libpurple: account) Connecting to account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME. 11:56:59: (GLib): (11:56:59) connection: Connecting. gc = 0x608006cae9a0 11:56:59: (Libpurple: connection) Connecting. gc = 0x608006cae9a0 11:56:59: (GLib : general): CRITICAL: purple_notify_close_with_handle: assertionhandle != NULL' failed
    11:56:59: (GLib : general): CRITICAL: purple_request_close_with_handle: assertion `handle != NULL' failed
    11:56:59: void adiumPurpleRequestClose(PurpleRequestType, void *):416: (null) (0)
    11:57:03: (GLib): (11:57:03) util: Writing file accounts.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple
    11:57:03: (Libpurple: util) Writing file accounts.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple
    11:57:03: (GLib): (11:57:03) util: Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml
    11:57:03: (Libpurple: util) Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml
    11:57:04: (GLib): (11:57:04) sipe: sipe_purple_login: username 'USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME'
    11:57:04: (Libpurple: sipe) sipe_purple_login: username 'USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME'
    11:57:04: (GLib): (11:57:04) sipe: sipe_purple_login: login 'ROSETTA\USER.NAME'
    11:57:04: (Libpurple: sipe) sipe_purple_login: login 'ROSETTA\USER.NAME'
    11:57:04: (GLib): (11:57:04) sipe: sipe_purple_login: auth domain 'ROSETTA' user 'USER.NAME'
    11:57:04: (Libpurple: sipe) sipe_purple_login: auth domain 'ROSETTA' user 'USER.NAME'
    11:57:04: (GLib): (11:57:04) sipe: sipe_core_allocate: SIPE version 1.16.1 signin_name 'USER.NAME@DOMAIN.COM'
    11:57:04: (Libpurple: sipe) sipe_core_allocate: SIPE version 1.16.1 signin_name 'USER.NAME@DOMAIN.COM'
    11:57:04: (GLib): (11:57:04) sipe: sipe_core_allocate: user 'USER.NAME' domain 'DOMAIN.COM'
    11:57:04: (Libpurple: sipe) sipe_core_allocate: user 'USER.NAME' domain 'DOMAIN.COM'
    11:57:04: Connecting: gc=0x6cae9a0 (Connecting) 1 / 2
    11:57:04: (GLib): (11:57:04) sipe: sipe_core_connect: user specified SIP server rosetta_pool1.DOMAIN.COM:5061
    11:57:04: (Libpurple: sipe) sipe_core_connect: user specified SIP server rosetta_pool1.DOMAIN.COM:5061
    11:57:04: (GLib): (11:57:04) sipe: transport_connect - hostname: rosetta_pool1.DOMAIN.COM port: 5061
    11:57:04: (Libpurple: sipe) transport_connect - hostname: rosetta_pool1.DOMAIN.COM port: 5061
    11:57:04: (GLib): (11:57:04) sipe: using SSL
    11:57:04: (Libpurple: sipe) using SSL
    11:57:04: (GLib): (11:57:04) dnsquery: Performing DNS lookup for rosetta_pool1.DOMAIN.COM
    11:57:04: (Libpurple: dnsquery) Performing DNS lookup for rosetta_pool1.DOMAIN.COM
    11:57:04: ** USER.NAME@DOMAIN.COM --step-- 1
    11:57:05: (GLib): (11:57:05) util: Writing file blist.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple
    11:57:05: (Libpurple: util) Writing file blist.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple
    11:57:05: (GLib): (11:57:05) util: Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml
    11:57:05: (Libpurple: util) Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/blist.xml
    11:57:05: -[AdiumPurpleDnsRequest startLookup]:198: Performing DNS resolve: rosetta_pool1.DOMAIN.COM:5061
    11:57:05: DNS resolve complete for rosetta_pool1.DOMAIN.COM:5061; 1 addresses returned
    11:57:05: (GLib): (11:57:05) dnsquery: IP resolved for rosetta_pool1.DOMAIN.COM
    11:57:05: (Libpurple: dnsquery) IP resolved for rosetta_pool1.DOMAIN.COM
    11:57:05: (GLib): (11:57:05) proxy: Attempting connection to 10.98.10.173
    11:57:05: (Libpurple: proxy) Attempting connection to 10.98.10.173
    11:57:05: (GLib): (11:57:05) proxy: Connecting to rosetta_pool1.DOMAIN.COM:5061 with no proxy
    11:57:05: (Libpurple: proxy) Connecting to rosetta_pool1.DOMAIN.COM:5061 with no proxy
    11:57:05: (GLib): (11:57:05) proxy: Connection in progress
    11:57:05: (Libpurple: proxy) Connection in progress
    11:57:05: (GLib): (11:57:05) proxy: Connecting to rosetta_pool1.DOMAIN.COM:5061.
    11:57:05: (Libpurple: proxy) Connecting to rosetta_pool1.DOMAIN.COM:5061.
    11:57:05: (GLib): (11:57:05) proxy: Connected to rosetta_pool1.DOMAIN.COM:5061.
    11:57:05: (Libpurple: proxy) Connected to rosetta_pool1.DOMAIN.COM:5061.
    11:57:05: (GLib): (11:57:05) cdsa: Connecting
    11:57:05: (Libpurple: cdsa) Connecting
    11:57:05: (GLib): (11:57:05) cdsa: Connecting
    11:57:05: (Libpurple: cdsa) Connecting
    11:57:05: (GLib): (11:57:05) cdsa: Connecting
    11:57:05: (Libpurple: cdsa) Connecting
    11:57:05: (GLib): (11:57:05) cdsa: Connecting
    11:57:05: (Libpurple: cdsa) Connecting
    11:57:05: (GLib): (11:57:05) cdsa: SSL_connect: verifying certificate
    11:57:05: (Libpurple: cdsa) SSL_connect: verifying certificate
    11:57:05: (GLib): (11:57:05) cdsa: SSL_connect complete
    11:57:05: (Libpurple: cdsa) SSL_connect complete
    11:57:05: (GLib): (11:57:05) stun: using server
    11:57:05: (Libpurple: stun) using server
    11:57:05: (GLib): (11:57:05) stun: using server
    11:57:05: (Libpurple: stun) using server
    11:57:05: (GLib): (11:57:05) stun: using server
    11:57:05: (Libpurple: stun) using server
    11:57:05: (GLib): (11:57:05) sipe: sipe_schedule_allocate timeouts count 1 after addition
    11:57:05: (Libpurple: sipe) sipe_schedule_allocate timeouts count 1 after addition
    11:57:05: (GLib): (11:57:05) sipe: scheduling action <transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><1 REGISTER> timeout 60 seconds
    11:57:05: (Libpurple: sipe) scheduling action <transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><1 REGISTER> timeout 60 seconds
    11:57:05: (GLib): (11:57:05) sipe: SIP transactions count:1 after addition
    11:57:05: (Libpurple: sipe) SIP transactions count:1 after addition
    11:57:05: (GLib): (11:57:05) sipe:
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:57:05.495850Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49504;branch=z9hG4bKD1E664D5DF5BD907682D
    From: sip:USER.NAME@DOMAIN.COM;tag=2706624879;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 1 REGISTER
    User-Agent: UCCAPI/3.5.6907.0 OC/3.5.6907.206
    Call-ID: 8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx
    Contact: <sip:127.94.0.1:49504;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:57:05.495850Z
    11:57:05: (Libpurple: sipe)
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:57:05.495850Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49504;branch=z9hG4bKD1E664D5DF5BD907682D
    From: sip:USER.NAME@DOMAIN.COM;tag=2706624879;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 1 REGISTER
    User-Agent: UCCAPI/3.5.6907.0 OC/3.5.6907.206
    Call-ID: 8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx
    Contact: <sip:127.94.0.1:49504;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:57:05.495850Z
    11:57:05: (GLib): (11:57:05) cdsa: Using cipher 2f.
    11:57:05: (Libpurple: cdsa) Using cipher 2f.
    11:57:05: (GLib): (11:57:05) sipe: transport_input_common: new buffer length 4096
    11:57:05: (Libpurple: sipe) transport_input_common: new buffer length 4096
    11:57:05: (GLib): (11:57:05) sipe:
    MESSAGE START <<<<<<<<<< SIP - 2013-10-16T15:57:05.525397Z
    SIP/2.0 401 Unauthorized
    Date: Wed, 16 Oct 2013 15:57:05 GMT
    WWW-Authenticate: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    WWW-Authenticate: Kerberos realm="SIP Communications Service", targetname="sip/SWP00OCS00E.DOMAIN.COM", version=4
    From: sip:USER.NAME@DOMAIN.COM;tag=2706624879;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM;tag=E5D48C0E0B7CCB7C54C72D07BD67C9AA
    Call-ID: 8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx
    CSeq: 1 REGISTER
    Via: SIP/2.0/tls 127.94.0.1:49504;branch=z9hG4bKD1E664D5DF5BD907682D;received=10.4.37.17;ms-received-port=49504;ms-received-cid=5E96100
    Content-Length: 0

    MESSAGE END <<<<<<<<<< SIP - 2013-10-16T15:57:05.525397Z
    11:57:05: (Libpurple: sipe)
    MESSAGE START <<<<<<<<<< SIP - 2013-10-16T15:57:05.525397Z
    SIP/2.0 401 Unauthorized
    Date: Wed, 16 Oct 2013 15:57:05 GMT
    WWW-Authenticate: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    WWW-Authenticate: Kerberos realm="SIP Communications Service", targetname="sip/SWP00OCS00E.DOMAIN.COM", version=4
    From: sip:USER.NAME@DOMAIN.COM;tag=2706624879;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM;tag=E5D48C0E0B7CCB7C54C72D07BD67C9AA
    Call-ID: 8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx
    CSeq: 1 REGISTER
    Via: SIP/2.0/tls 127.94.0.1:49504;branch=z9hG4bKD1E664D5DF5BD907682D;received=10.4.37.17;ms-received-port=49504;ms-received-cid=5E96100
    Content-Length: 0

    MESSAGE END <<<<<<<<<< SIP - 2013-10-16T15:57:05.525397Z
    11:57:05: (GLib): (11:57:05) sipe: process_input_message: msg->response(401),msg->method(REGISTER)
    11:57:05: (Libpurple: sipe) process_input_message: msg->response(401),msg->method(REGISTER)
    11:57:05: (GLib): (11:57:05) sipe: process_input_message: RE-REGISTER CSeq: 1
    11:57:05: (Libpurple: sipe) process_input_message: RE-REGISTER CSeq: 1
    11:57:05: (GLib): (11:57:05) sipe: process_input_message: we have a transaction callback
    11:57:05: (Libpurple: sipe) process_input_message: we have a transaction callback
    11:57:05: (GLib): (11:57:05) sipe: process_register_response: got response to REGISTER; expires = 0
    11:57:05: (Libpurple: sipe) process_register_response: got response to REGISTER; expires = 0
    11:57:05: (GLib): (11:57:05) sipe: process_register_response: REGISTER retries 1
    11:57:05: (Libpurple: sipe) process_register_response: REGISTER retries 1
    11:57:05: (GLib): (11:57:05) sipe: process_register_response: Auth header: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    11:57:05: (Libpurple: sipe) process_register_response: Auth header: NTLM realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", version=4
    11:57:05: (GLib): (11:57:05) stun: using server
    11:57:05: (Libpurple: stun) using server
    11:57:05: (GLib): (11:57:05) stun: using server
    11:57:05: (Libpurple: stun) using server
    11:57:05: (GLib): (11:57:05) sipe: sip_sec_create_context: type: 2, Single Sign-On: no, protocol: SIP
    11:57:05: (Libpurple: sipe) sip_sec_create_context: type: 2, Single Sign-On: no, protocol: SIP
    11:57:05: (GLib): (11:57:05) sipe: sip_sec_init_sec_contextntlm: in use
    11:57:05: (Libpurple: sipe) sip_sec_init_sec_context
    ntlm: in use
    11:57:05: (GLib): (11:57:05) sipe: sipe_schedule_allocate timeouts count 2 after addition
    11:57:05: (Libpurple: sipe) sipe_schedule_allocate timeouts count 2 after addition
    11:57:05: (GLib): (11:57:05) sipe: scheduling action <transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><2 REGISTER> timeout 60 seconds
    11:57:05: (Libpurple: sipe) scheduling action <transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><2 REGISTER> timeout 60 seconds
    11:57:05: (GLib): (11:57:05) sipe: SIP transactions count:2 after addition
    11:57:05: (Libpurple: sipe) SIP transactions count:2 after addition
    11:57:05: (GLib): (11:57:05) sipe:
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:57:05.529701Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49504;branch=z9hG4bK044ECCD36D02B405DE2B
    From: sip:USER.NAME@DOMAIN.COM;tag=476631583;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 2 REGISTER
    User-Agent: UCCAPI/3.5.6907.0 OC/3.5.6907.206
    Call-ID: 8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx
    Contact: <sip:127.94.0.1:49504;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0
    Authorization: NTLM qop="auth", realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", gssapi-data="", version=4

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:57:05.529701Z
    11:57:05: (Libpurple: sipe)
    MESSAGE START >>>>>>>>>> SIP - 2013-10-16T15:57:05.529701Z
    REGISTER sip:DOMAIN.COM SIP/2.0
    Via: SIP/2.0/tls 127.94.0.1:49504;branch=z9hG4bK044ECCD36D02B405DE2B
    From: sip:USER.NAME@DOMAIN.COM;tag=476631583;epid=dc64ee5e686e
    To: sip:USER.NAME@DOMAIN.COM
    Max-Forwards: 70
    CSeq: 2 REGISTER
    User-Agent: UCCAPI/3.5.6907.0 OC/3.5.6907.206
    Call-ID: 8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx
    Contact: <sip:127.94.0.1:49504;transport=tls;ms-opaque=d3470f2e1d>;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER, BENOTIFY";proxy=replace;+sip.instance="<urn:uuid:93c325df-9305-5a6b-a1e6-cc666cf1fe84>"
    Supported: gruu-10, adhoclist, msrtc-event-categories, com.microsoft.msrtc.presence
    Event: registration
    Allow-Events: presence
    ms-keep-alive: UAC;hop-hop=yes
    Content-Length: 0
    Authorization: NTLM qop="auth", realm="SIP Communications Service", targetname="SWP00OCS00E.DOMAIN.COM", gssapi-data="", version=4

    MESSAGE END >>>>>>>>>> SIP - 2013-10-16T15:57:05.529701Z
    11:57:05: (GLib): (11:57:05) sipe: process_input_message: removing CSeq 2
    11:57:05: (Libpurple: sipe) process_input_message: removing CSeq 2
    11:57:05: (GLib): (11:57:05) sipe: SIP transactions count:1 after removal
    11:57:05: (Libpurple: sipe) SIP transactions count:1 after removal
    11:57:05: (GLib): (11:57:05) sipe: sipe_schedule_remove: action name=<transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><1 REGISTER>
    11:57:05: (Libpurple: sipe) sipe_schedule_remove: action name=<transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><1 REGISTER>
    11:57:05: (GLib): (11:57:05) cdsa: receive failed (-9806): Connection reset by peer
    11:57:05: (Libpurple: cdsa) receive failed (-9806): Connection reset by peer
    11:57:05: (GLib): (11:57:05) sipe: Read error: Connection reset by peer (54)
    11:57:05: (Libpurple: sipe) Read error: Connection reset by peer (54)
    11:57:05: (GLib): (11:57:05) connection: Connection error on 0x608006cae9a0 (reason: 0 description: Read error)
    11:57:05: (Libpurple: connection) Connection error on 0x608006cae9a0 (reason: 0 description: Read error)
    11:57:05: Connection Disconnected: gc=6cae9a0 (Read error)
    11:57:05: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM accountConnectionReportDisconnect: Read error
    11:57:05: (GLib): (11:57:05) account: Disconnecting account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME (0x608000343b20)
    11:57:05: (Libpurple: account) Disconnecting account USER.NAME@DOMAIN.COM,ROSETTA\USER.NAME (0x608000343b20)
    11:57:05: (GLib): (11:57:05) connection: Disconnecting connection 0x608006cae9a0
    11:57:05: (Libpurple: connection) Disconnecting connection 0x608006cae9a0
    11:57:05: (GLib): (11:57:05) sipe: SIP transactions count:0 after removal
    11:57:05: (Libpurple: sipe) SIP transactions count:0 after removal
    11:57:05: (GLib): (11:57:05) sipe: sipe_schedule_remove: action name=<transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><2 REGISTER>
    11:57:05: (Libpurple: sipe) sipe_schedule_remove: action name=<transaction timeout=""><8E3FgEB2Ea5764iA26Bm3C1Ft26A2b92A9xD6DFx><2 REGISTER>
    11:57:05: (GLib : GLib): CRITICAL: g_hash_table_destroy: assertion `hash_table != NULL' failed
    11:57:05: (GLib): (11:57:05) sipe: sipe_purple_dns_query_cancel_all: entered
    11:57:05: (Libpurple: sipe) sipe_purple_dns_query_cancel_all: entered
    11:57:05: (GLib): (11:57:05) sipe: sipe_purple_transport_close_all: entered
    11:57:05: (Libpurple: sipe) sipe_purple_transport_close_all: entered
    11:57:05: Disconnected: gc=6cae9a0
    11:57:05: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Telling the core we disconnected
    11:57:05: -[AIContactObserverManager endListObjectNotificationsDelaysImmediately]:144:
    11:57:05: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Disconnected ("Read error"): Automatically reconnecting in 5.000000 seconds (0 attempts performed)
    11:57:05: (GLib): (11:57:05) connection: Destroying connection 0x608006cae9a0
    11:57:05: (Libpurple: connection) Destroying connection 0x608006cae9a0
    11:57:08: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: isOnline
    11:57:08: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: Enabled
    11:57:08: <ESPurpleSIPEAccount:30610a0 4="">:USER.NAME@DOMAIN.COM: Updating status for key: FullNameAttr
    11:57:09: (GLib): (11:57:09) util: Writing file accounts.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple
    11:57:09: (Libpurple: util) Writing file accounts.xml to directory /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple
    11:57:09: (GLib): (11:57:09) util: Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml
    11:57:09: (Libpurple: util) Writing file /Users/USER.NAME/Library/Application Support/Adium 2.0/Users/Default/libpurple/accounts.xml

     
  • Stefan Becker

    Stefan Becker - 2013-10-16

    IMHO another FAQ issue.

    Unfortunately Adium log doesn't seem to show the Adium version.

     
  • Jon Anhold

    Jon Anhold - 2013-10-16

    Adium 1.5.8, sipe 1.17.0. What other information can I provide? Worked fine on OSX 10.8, not on 10.9.

     
  • Stefan Becker

    Stefan Becker - 2013-10-16

    Well, the problem isn't caused by SIPE. It only reports the error generated by a lower layer (CDSA):

    11:55:58: (GLib): (11:55:58) cdsa: receive failed (-9806): Connection reset by peer
    11:55:58: (GLib): (11:55:58) sipe: Read error: Connection reset by peer (54)
    

    As far as I understand the information provided by Apple, CDSA is not based on NSS. But it could be that they, despite the fact that they declared CDSA deprecated, have added a fix for CVE-2011-3389 that uses the same technical solution as the one in NSS. If that is the case then with Mac OS X 10.9 you would be affected by the same M$ SSL server code bug (see FAQ)

    Please check the CVE URL. There are several links to Apple KB documents and security update announcements (don't click on the links: due to the Government Shutdown NIST web services are down and therefore the redirects don't work). Maybe one of them points to changes in CDSA and maybe has a hint how to disable the fix.

    The only other option is to request updating of the M$ SSL server code. They have obviously fixed it, because not everyone is affected by this issue anymore.

     
  • Stefan Becker

    Stefan Becker - 2013-10-16

    I have added this issue to the FAQ.

     
  • Jon Anhold

    Jon Anhold - 2013-10-17

    This may be some issue with the autodiscover code. It works fine for me when I am off our corporate network, but not when on the corporate LAN.

     
    • Stefan Becker

      Stefan Becker - 2013-10-17

      The log does not show an auto-discover failure, i.e. it is already connected to the server, trying to REGISTER. The lower (most probably SSL on te server side) layer drops the connection during the REGISTER handshake.

      In both cases you are talking to different servers, e.g. outside the intranet you are talking to a frontend server visible on the Internet. I can only guess that the servers have different SW release/patch level, i.e. the one facing the internet does have the fixed SSL code.

       
  • Chris LUff

    Chris LUff - 2013-10-25

    I have the same behaviour; OSX 10.9, Adium 1.5.8 and SIPE 1.16.1. It connects fine over the internet, but over VPN and LAN it fails.

    However, if I change the authentication method to Kerberos (I have a ticket) then I can log in.

     

    Last edit: Chris LUff 2013-10-25
  • Bryan Seitz

    Bryan Seitz - 2013-10-28

    I can confirm this is an issue with me as well. Mine sits there for 30 seconds then asks for my password then fails authentication. Any help would be appreciated. Where do I find / enable the debug log ?

     
  • Stefan Becker

    Stefan Becker - 2013-10-28

    Let me re-state: this is not a bug in SIPE. The SSL connection is aborted from the lower level that handles the SSL connection. This abort presents itself to SIPE as Read Error.

    There is currently no known workaround.

    There is currently only a guess what could be the cause of the problem: BEAST security fix in Apples CDSA stack.

    I don't have a Mac. I don't have an account that connects to a server that is barfing on BEAST-fixed SSL connections. I would appreciate if some affected Mac user could run a tcpdump/wireshark trace on the IP address SIPE tries to connect to. A look at this network trace could determine if the SSL connection is using the BEAST-fix. [if you restrict the filter to that one SSL connection, then no other information about your computer/network will be leaked to the log]

     
    • Chris LUff

      Chris LUff - 2013-10-29

      Is this helpful;

      1 1 0.1186 (0.1186) C>S Handshake
      ClientHello
      Version 3.3
      cipher suites
      Unknown value 0xff
      Unknown value 0xc024
      Unknown value 0xc023
      Unknown value 0xc00a
      Unknown value 0xc009
      Unknown value 0xc007
      Unknown value 0xc008
      Unknown value 0xc028
      Unknown value 0xc027
      Unknown value 0xc014
      Unknown value 0xc013
      Unknown value 0xc011
      Unknown value 0xc012
      Unknown value 0xc026
      Unknown value 0xc025
      Unknown value 0xc02a
      Unknown value 0xc029
      Unknown value 0xc005
      Unknown value 0xc004
      Unknown value 0xc002
      Unknown value 0xc003
      Unknown value 0xc00f
      Unknown value 0xc00e
      Unknown value 0xc00c
      Unknown value 0xc00d
      Unknown value 0x2f
      TLS_RSA_WITH_RC4_128_SHA
      TLS_RSA_WITH_RC4_128_MD5
      Unknown value 0x35
      TLS_RSA_WITH_3DES_EDE_CBC_SHA
      Unknown value 0x33
      Unknown value 0x39
      TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA
      compression methods
      NULL
      1 2 0.7090 (0.5903) C>S Handshake
      Certificate
      1 3 1.0400 (0.3310) C>S Handshake
      ClientKeyExchange
      1 4 1.0400 (0.0000) C>S ChangeCipherSpec
      1 5 1.0400 (0.0000) C>S Handshake
      1 6 1.1837 (0.1436) C>S application_data
      1 7 1.3295 (0.1458) C>S application_data
      1 8 1.6510 (0.3215) C>S application_data
      1 9 1.6510 (0.0000) C>S application_data
      1 10 1.6510 (0.0000) C>S application_data

       
      • Stefan Becker

        Stefan Becker - 2013-10-29

        I guess this is from tcpdump? Care to attach the raw dump so that I can analyze it with wireshark, i.e. tcpdump -w sipe.dump

         
        • Chris LUff

          Chris LUff - 2013-10-29

          It was ssldump; will see what I can do.

           
  • Chris LUff

    Chris LUff - 2013-10-29
     

    Last edit: Chris LUff 2013-10-29
  • Stefan Becker

    Stefan Becker - 2013-10-29

    How about ssldump -Ad ..your parameters? The important information I'm looking for is the length of the first two encrypted application data messages send by the client.

    When using NSS and tcpdump the first application data package looks like this:

    • without the BEAST fix: one data packet of N clear text bytes -> M encrypted bytes
    • with BEAST fix: one data packet of 1 clear text byte -> 32 encrypted bytes plus one data packet of N-1 clear text bytes -> <M encrypted bytes.

    This N -> 1/N-1 split is the fix for the BEAST attack and the reason why the SSL code on the server side drops the SSL connection.

     
  • Stefan Becker

    Stefan Becker - 2013-10-29

    Here is a ssldump -Ad example I took with NSS on a Linux box:

    Without NSS BEAST fix (i.e. NSS_SSL_CBC_RANDOM_IV=0):

    1 6  0.1781 (0.0487)  S>C V3.1(1)  ChangeCipherSpec
    1 7  0.1781 (0.0000)  S>C V3.1(48)  Handshake
    1 8  0.2535 (0.0753)  C>S V3.1(816)  application_data
    1 9  0.3134 (0.0599)  S>C V3.1(544)  application_data
    1 10 0.3137 (0.0003)  C>S V3.1(32)  Alert
    

    With NSS BEAST fix (i.e. NSS_SSL_CBC_RANDOM_IV=1):

    2 6  0.1788 (0.0487)  S>C V3.1(1)  ChangeCipherSpec
    2 7  0.1788 (0.0000)  S>C V3.1(48)  Handshake
    2 8  0.2417 (0.0628)  C>S V3.1(32)  application_data
    2 9  0.2417 (0.0000)  C>S V3.1(816)  application_data
    2 10 0.3036 (0.0619)  S>C V3.1(544)  application_data
    2 11 0.3040 (0.0004)  C>S V3.1(32)  Alert
    

    Notice the extra 32 bytes application_data packet after the handshake.

     
  • Andre

    Andre - 2013-10-29

    Herewith an ssldump from a Mavericks machine running Adium 1.5.8 with SIPE 1.17.1


    51 83 58 be 3f 6d c7 fb da 03 21 cb 6a 16 19 4e
    0a f0 ad 84 ca 5d 94 b3 5a 76 f7 61
    ServerHelloDone
    1 3 0.1747 (0.0468) C>SV3.1(262) Handshake
    ClientKeyExchange
    1 4 0.5381 (0.3634) C>SV3.1(1) ChangeCipherSpec
    1 5 0.5381 (0.0000) C>SV3.1(48) Handshake
    1 6 0.5783 (0.0401) S>CV3.1(1) ChangeCipherSpec
    1 7 0.5783 (0.0000) S>CV3.1(48) Handshake
    1 8 5.6434 (5.0650) C>SV3.1(848) application_data
    1 9 5.6934 (0.0500) S>CV3.1(624) application_data
    1 10 5.6942 (0.0007) C>SV3.1(32) application_data
    1 11 5.9218 (0.2276) C>SV3.1(224) application_data
    1 12 5.9218 (0.0000) C>SV3.1(32) application_data
    1 13 5.9218 (0.0000) C>SV3.1(800) application_data
    1 5.9614 (0.0395) S>C TCP RST

    and this is with an unsupported authentication method (kerberos) - just for kicks.


    0a f0 ad 84 ca 5d 94 b3 5a 76 f7 61
    ServerHelloDone
    2 3 0.2005 (0.0714) C>SV3.1(262) Handshake
    ClientKeyExchange
    2 4 0.4453 (0.2448) C>SV3.1(1) ChangeCipherSpec
    2 5 0.4453 (0.0000) C>SV3.1(48) Handshake
    2 6 0.4848 (0.0394) S>CV3.1(1) ChangeCipherSpec
    2 7 0.4848 (0.0000) S>CV3.1(48) Handshake
    2 8 0.4853 (0.0004) C>SV3.1(848) application_data
    2 9 0.5364 (0.0511) S>CV3.1(624) application_data
    2 10 0.5453 (0.0089) C>SV3.1(32) Alert
    2 0.5454 (0.0001) C>S TCP FIN
    2 0.5841 (0.0386) S>C TCP RST

     
  • Stefan Becker

    Stefan Becker - 2013-10-30

    Hmm, doesn't look so clear as my test with NSS, but I'm guessing that those two might be BEAST fixed packages. The package sent after that shows that the server aborts the SSL connection (your second example shows how the client correctly closes a SSL connection at the end):

    1 10 5.6942 (0.0007) C>SV3.1(32) application_data
    1 11 5.9218 (0.2276) C>SV3.1(224) application_data
    1 12 5.9218 (0.0000) C>SV3.1(32) application_data
    1 13 5.9218 (0.0000) C>SV3.1(800) application_data
    1 5.9614 (0.0395) S>C TCP RST
    

    To be 100% sure: can somebody provide a ssldump from 10.8 to the same server? I.e. where the SSL connection is working fine?

     
  • Bryan Seitz

    Bryan Seitz - 2013-11-05

    Can you please re-open this ticket, it is very much a valid bug and is still broken for many people.

     
    • Stefan Becker

      Stefan Becker - 2013-11-05

      Why? It's not a bug in SIPE.

      If somebody adds information how to disable SSL BEAST security fix on Mac OS X 10.9, then I'll update the FAQ.

       
  • Stefan Becker

    Stefan Becker - 2013-11-05

    Finally some confirmation that Mac OS X 10.9 includes a SSL BEAST fix and has it enabled by default. It looks like the code was already there in 10.8, but disabled by default. It also verifies my hunch that Apple has chosen a slightly different approach from NSS, which explains why the ssldump from OS X 10.9 looks different.

    Quote from the source code:

     /* 0 = disabled, 1 = split every write, 2 = split second and subsequent writes */
     /* Enabled by default, this make cause some interop issues, see <rdar://problem/12307662> and <rdar://problem/12323307> */
    

    In 10.8 the default for SSLWriteSplit was 0, in 10.9 it is 2. Unfortunately those Apple Radar numbers are for internal tickets, i.e. they are not visible on Open Radar. Would be interesting to know what "interop" issues Apple has listed there.

    To fix the problem on 10.9 you will have to run the following command.

    PLEASE NOTE: This is a global setting and therefore has security implications for every SSL connection created from your machine. You have been warned, use at your own risk!

    $ sudo defaults write /Library/Preferences/com.apple.security SSLWriteSplit -integer 0
    
     

    Last edit: Stefan Becker 2013-11-05
  • dondky

    dondky - 2013-11-05

    Stefan, thanks for a solution, other than disabling a global security fix, what other methods can be taken to fix this issue?

     
  • Stefan Becker

    Stefan Becker - 2013-11-05

    Does the solution actually work? I don't have a Mac to verify.

    I'm no Mac developer, but from the source code I would guess that only this global preference setting is available. I don't see anything on the defaults man page how preferences can be restricted to a specific application or user.

    Another option is to update the SSL component (SChannel AFAIK) on the M$ server side.

     

    Last edit: Stefan Becker 2013-11-05
1 2 3 > >> (Page 1 of 3)

Log in to post a comment.