Mac Messenger 5.1.1 problem with Communicator

Article
09/11/2006

After working on this issue I am not sure I can truly say I am a Mac novice but for the purposes of this audience I will mention that I do not use the Mac on a daily basis. Although the new iMac 24" with Bootcamp and Parallels for Vista is being discussed with my financial advisor (wife) :)

Ok so onto the problem - There can be many different behaviors reported and include:
1) Windows workstations with Office Communicator are unable to send an IM successfully to the Mac Messenger workstation. The Mac Messenger client will never receive the IM and Office Communicator will generate an error about not delivering the IM between 1-3 minutes.
2) The Mac client can send the OC client an IM and the OC client will receive it but be unable to reply. The experience will be a one way conversation where OC receives all IMs sent from the MAC and the MAC will receive no replies.
3) We did see other behaviors when testing that could not be duplicate and that included an initial IM from the MAC received by Communicator with out the actual text. The IM "toast" (small popup at the bottom of the screen) included the text but the IM conversation window did not.
4) Intermittent IM between the MAC and OC clients in which some of the OC messages were received by the MAC user but not all.

The resolution is easy enough - wait and watch for the Mac Messenger 6.0 release. Thanks to Michele and Eric for their patience and diligence in working with me and providing the necessary information to reproduce this issue. Included below is the technical analysis of the issue with the root cause.

As the issue was not affecting all Mac Workstations we focused on what made these few workstations unique. The root cause of this problem appeared to be the customer's IP scheme which placed the problem Mac Messenger 5.1.1 systems on a supernet of IP and Subnet. The issues have all been resolved, at the time of this writing, with the beta version of Mac Messenger 6.0. There is always the rare possibility that between now and the RTM of the client this issue could reoccur (I hope not).

Below is the analyzed LCS Server logs for a failed IM from the OC client to the Mac Messenger client -
Invite received at the LCS Server from Communicator client

$$begin_record
LogType: protocol
Date: 2006/08/18 14:20:52
Direction: Incoming
Peer: 128.244.3.172:3786
Message-Type: Request
Start-Line: INVITE sip:mac-user@contoso.local SIP/2.0
To: <sip:mac-user@contoso.local>
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 INVITE
Contact: <sip:oc-user@contoso.local:3786;maddr=128.244.3.172;transport=tls>proxy=replace
Via: SIP/2.0/TLS 128.244.3.172:3786
Max-Forwards: 70
Content-Length: 126
Content-Type: application/sdp
Other-Headers: User-Agent: LCC/1.3
Other-Headers: Ms-Conversation-ID: 32D6496A-67A3-469C-8725-F08D53E6B33C
Other-Headers: Ms-Text-Format: text/plain; charset=UTF-8;msgr=WAAtAE0ATQBTAC0ASQBNAC0ARgBvAHIAbQBhAHQAOgAgAEYATgA9AE0AaQBjAHIAbwBzAG8AZgB0ACUAMgAwAFMAYQBuAHMAJQAyADAAUwBlAHIAaQBmADsAIABFAEYAPQBCADsAIABDAE8APQA4ADAAOAAwADAAMAA7ACAAQwBTAD0AMAA7ACAAUABGAD0AMgAyAA0ACgANAAoA;ms-body=MQ==
Other-Headers: Supported: ms-delayed-accept
Other-Headers: Supported: ms-renders-gif
Other-Headers: Roster-Manager: sip:oc-user@contoso.local
Other-Headers: EndPoints: "Office Communicator" <sip:oc-user@contoso.local>, <sip:mac-user@contoso.local>
Other-Headers: Supported: com.microsoft.rtc-multiparty
Other-Headers: Proxy-Authorization: Kerberos qop="auth", realm="SIP Communications Service", opaque="83A4EBBE", crand="eee6f6c1", cnum="174", targetname="sip/lcsserver.contoso.local", response="602306092a864886f71201020201011100ffffffffdc9c0c5e2de239e852186353977bb739"
Message-Body: v=0\no=- 0 0 IN IP4 128.244.3.172\ns=session\nc=IN IP4 128.244.3.172\nt=0 0\nm=message 5060 sip sip:oc-user@contoso.local
$$end_record

$$begin_record
LogType: diagnostic
Date: 2006/08/18 14:20:52
Severity: information
Text: Response successfully routed
SIP-Start-Line: SIP/2.0 100 Trying
SIP-Call-ID: 8ade0e910e814353abb38a91dac0de3a
SIP-CSeq: 1 INVITE
Peer: 128.244.3.172:3786
$$end_record

LCS Server replying to Communicator user workstation with 100 trying (note IP address)

$$begin_record
LogType: protocol
Date: 2006/08/18 14:20:52
Direction: Outgoing
Origin: Local
Peer: 128.244.3.172:3786
Message-Type: Response
Start-Line: SIP/2.0 100 Trying
To: <sip:mac-user@contoso.local>
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 INVITE
Via: SIP/2.0/TLS 128.244.3.172:3786;ms-received-port=3786;ms-received-cid=4000
Content-Length: 0
Other-Headers: Authentication-Info: Kerberos rspauth="602306092A864886F71201020201011100FFFFFFFF37CA39454D553FFA4BA312C4A3B9692A", srand="A81AEFCF", snum="373", opaque="83A4EBBE", qop="auth", targetname="sip/lcsserver.contoso.local", realm="SIP Communications Service"
$$end_record

$$begin_record
LogType: diagnostic
Date: 2006/08/18 14:20:52
Severity: information
Text: Routed a request on behalf of APIEM
SIP-Start-Line: INVITE sip:128.244.153.234:50372;transport=tls;ms-received-cid=24C00 SIP/2.0
SIP-Call-ID: 8ade0e910e814353abb38a91dac0de3a
SIP-CSeq: 1 INVITE
Peer: 128.244.153.234:50372
$$end_record

LCS Server sending Invite to mac user workstation (note IP address)

$$begin_record
LogType: protocol
Date: 2006/08/18 14:20:52
Direction: Outgoing
Peer: 128.244.153.234:50372
Message-Type: Request
Start-Line: INVITE sip:128.244.153.234:50372;transport=tls;ms-received-cid=24C00 SIP/2.0
To: <sip:mac-user@contoso.local>epid=0cb058af1a
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 INVITE
Contact: <sip:oc-user@contoso.local:3786;maddr=128.244.3.172;transport=tls;ms-received-cid=4000>
Via: SIP/2.0/TLS 128.244.198.22:5061;branch=z9hG4bKE31744A0.D6BB86C4;branched=FALSE;ms-internal-info="cajr5x1Tczx6BVg_53FGSW0odPQTsA"
Via: SIP/2.0/TLS 128.244.3.172:3786;ms-received-port=3786;ms-received-cid=4000
Max-Forwards: 69
Content-Length: 126
Content-Type: application/sdp
Other-Headers: Authentication-Info: NTLM rspauth="01000000682E08737855AFF764000000", srand="3C7DC434", snum="13", opaque="4252F741", qop="auth", targetname="lcsserver.contoso.local", realm="SIP Communications Service"
Other-Headers: Record-Route: <sip:lcsserver.contoso.local:5061;transport=tls;lr;ms-route-sig=cahdKz7QJ46fNofDr-EoVUodVA6qes>tag=AEF3CEF743455F6E8E381050237A9AEE
Other-Headers: User-Agent: LCC/1.3
Other-Headers: Ms-Conversation-ID: 32D6496A-67A3-469C-8725-F08D53E6B33C
Other-Headers: Ms-Text-Format: text/plain; charset=UTF-8;msgr=WAAtAE0ATQBTAC0ASQBNAC0ARgBvAHIAbQBhAHQAOgAgAEYATgA9AE0AaQBjAHIAbwBzAG8AZgB0ACUAMgAwAFMAYQBuAHMAJQAyADAAUwBlAHIAaQBmADsAIABFAEYAPQBCADsAIABDAE8APQA4ADAAOAAwADAAMAA7ACAAQwBTAD0AMAA7ACAAUABGAD0AMgAyAA0ACgANAAoA;ms-body=MQ==
Other-Headers: Supported: ms-delayed-accept
Other-Headers: Supported: ms-renders-gif
Other-Headers: Roster-Manager: sip:oc-user@contoso.local
Other-Headers: EndPoints: "Office Communicator" <sip:oc-user@contoso.local>, <sip:mac-user@contoso.local>
Other-Headers: Supported: com.microsoft.rtc-multiparty
Message-Body: v=0\no=- 0 0 IN IP4 128.244.3.172\ns=session\nc=IN IP4 128.244.3.172\nt=0 0\nm=message 5060 sip sip:oc-user@contoso.local
$$end_record

LCS server receiving 100 trying from mac user workstation

$$begin_record
LogType: protocol
Date: 2006/08/18 14:20:52
Direction: Incoming
Peer: 128.244.153.234:50372
Message-Type: Response
Start-Line: SIP/2.0 100 Trying
To: <sip:mac-user@contoso.local>epid=0cb058af1a;tag=c0f5fe982ec411db8d2f0014510d30fe
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 INVITE
Via: SIP/2.0/TLS 128.244.198.22:5061;branch=z9hG4bKE31744A0.D6BB86C4;branched=FALSE;ms-internal-info="cajr5x1Tczx6BVg_53FGSW0odPQTsA"
Via: SIP/2.0/TLS 128.244.3.172:3786;ms-received-port=3786;ms-received-cid=4000
Content-Length: 0
Other-Headers: User-Agent: RTC/1.3
Other-Headers: Proxy-Authorization: NTLM qop="auth", realm="SIP Communications Service", opaque="4252F741", crand="43d57ff6", cnum="11", targetname="lcsserver.contoso.local", response="01000000ca284c89fc709a0064000000"
$$end_record

LCS server receiving 200 ok from mac user workstation

$$begin_record
LogType: protocol
Date: 2006/08/18 14:20:52
Direction: Incoming
Peer: 128.244.153.234:50372
Message-Type: Response
Start-Line: SIP/2.0 200 OK
To: <sip:mac-user@contoso.local>epid=0cb058af1a;tag=c0f5fe982ec411db8d2f0014510d30fe
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 INVITE
Contact: <sip:mac-user@contoso.local:50372;maddr=128.244.153.234;transport=tls>proxy=replac?
Via: SIP/2.0/TLS 128.244.198.22:5061;branch=z9hG4bKE31744A0.D6BB86C4;branched=FALSE;ms-internal-info="cajr5x1Tczx6BVg_53FGSW0odPQTsA"
Via: SIP/2.0/TLS 128.244.3.172:3786;ms-received-port=3786;ms-received-cid=4000
Record-Route: <sip:lcsserver.contoso.local:5061;transport=tls;lr;ms-route-sig=cahdKz7QJ46fNofDr-EoVUodVA6qes>tag=AEF3CEF743455F6E8E381050237A9AEE
Content-Length: 128
Content-Type: application/sdp
Other-Headers: User-Agent: RTC/1.3
Other-Headers: Supported: com.microsoft.rtc-multiparty
Other-Headers: Proxy-Authorization: NTLM qop="auth", realm="SIP Communications Service", opaque="4252F741", crand="5c6e7d9a", cnum="12", targetname="lcsserver.contoso.local", response="01000000b921c0335c4b850e64000000"
Message-Body: v=0\no=- 0 0 IN IP4 128.244.153.234\ns=session\nc=IN IP4 128.244.153.234\nt=0 0\nm=message 5060 sip sip:mac-user@contoso.local
$$end_record

Error processing the incoming 200 ok. No error back to Mac client, no response to Communicator client

$$begin_record
LogType: security
Date: 2006/08/18 14:20:52
Text: Error processing message
Result-Code: 0xc3ed1810 SIPPROXY_E_INVALID_CONTACT_PARAMS
SIP-Start-Line: SIP/2.0 200 OK
SIP-Call-ID: 8ade0e910e814353abb38a91dac0de3a
SIP-CSeq: 1 INVITE
$$end_record

LCS server receiving Bye from mac user workstation due to delay

$$begin_record
LogType: protocol
Date: 2006/08/18 14:21:25
Direction: Incoming
Peer: 128.244.153.234:50372
Message-Type: Request
Start-Line: BYE sip:lcsserver.contoso.local:5061;transport=tls;lr;ms-route-sig=cahdKz7QJ46fNofDr-EoVUodVA6qes SIP/2.0
To: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
From: <sip:mac-user@contoso.local>epid=0cb058af1a;tag=c0f5fe982ec411db8d2f0014510d30fe
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 BYE
Via: SIP/2.0/TLS 128.244.153.234:50372
Route: <sip:oc-user@contoso.local:3786;maddr=128.244.3.172;transport=tls;ms-received-cid=4000>
Max-Forwards: 70
Content-Length: 0
Other-Headers: User-Agent: RTC/1.3
Other-Headers: Proxy-Authorization: NTLM qop="auth", realm="SIP Communications Service", opaque="4252F741", crand="4c75f6bf", cnum="13", targetname="lcsserver.contoso.local", response="01000000f6ca5eb6709b750064000000"
$$end_record

$$begin_record
LogType: diagnostic
Date: 2006/08/18 14:21:25
Severity: information
Text: Routed a request using signed route headers
SIP-Start-Line: BYE sip:oc-user@contoso.local:3786;maddr=128.244.3.172;transport=tls;ms-received-cid=4000 SIP/2.0
SIP-Call-ID: 8ade0e910e814353abb38a91dac0de3a
SIP-CSeq: 1 BYE
Peer: 128.244.3.172:3786
$$end_record

LCS sending Bye to Communicator user workstation

$$begin_record
LogType: protocol
Date: 2006/08/18 14:21:25
Direction: Outgoing
Peer: 128.244.3.172:3786
Message-Type: Request
Start-Line: BYE sip:oc-user@contoso.local:3786;maddr=128.244.3.172;transport=tls;ms-received-cid=4000 SIP/2.0
To: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
From: <sip:mac-user@contoso.local>epid=0cb058af1a;tag=c0f5fe982ec411db8d2f0014510d30fe
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 BYE
Via: SIP/2.0/TLS 128.244.198.22:5061;branch=z9hG4bK6A79BB21.93EB5D17;branched=FALSE;ms-internal-info="caLD7SdtVt-EY6ragkVNDUT4dPQTsA"
Via: SIP/2.0/TLS 128.244.153.234:50372;ms-received-port=50372;ms-received-cid=24c00
Max-Forwards: 69
Content-Length: 0
Other-Headers: Authentication-Info: Kerberos rspauth="602306092A864886F71201020201011100FFFFFFFF21F61AEE9B22E3197E9CB9CE3E60EA21", srand="D2A21167", snum="375", opaque="83A4EBBE", qop="auth", targetname="sip/lcsserver.contoso.local", realm="SIP Communications Service"
Other-Headers: User-Agent: RTC/1.3
$$end_record

LCS receives 481 as Communicator client does not have the call leg setup given the above failure with 200 ok (her workstation needed that 200 ok for the call to be established)

$$begin_record
LogType: protocol
Date: 2006/08/18 14:21:25
Direction: Incoming
Peer: 128.244.3.172:3786
Message-Type: Response
Start-Line: SIP/2.0 481 Call Leg/Transaction Does Not Exist
To: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
From: <sip:mac-user@contoso.local>epid=0cb058af1a;tag=c0f5fe982ec411db8d2f0014510d30fe
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 BYE
Via: SIP/2.0/TLS 128.244.198.22:5061;branch=z9hG4bK6A79BB21.93EB5D17;branched=FALSE;ms-internal-info="caLD7SdtVt-EY6ragkVNDUT4dPQTsA"
Via: SIP/2.0/TLS 128.244.153.234:50372;ms-received-port=50372;ms-received-cid=24c00
Content-Length: 0
Other-Headers: User-Agent: LCC/1.3
Other-Headers: Proxy-Authorization: Kerberos qop="auth", realm="SIP Communications Service", opaque="83A4EBBE", crand="f5aa6aee", cnum="175", targetname="sip/lcsserver.contoso.local", response="602306092a864886f71201020201011100ffffffffb07bcf5412d9bc0c14931cce04c827c6"
$$end_record

$$begin_record
LogType: diagnostic
Date: 2006/08/18 14:21:25
Severity: information
Text: Response successfully routed
SIP-Start-Line: SIP/2.0 481 Call Leg/Transaction Does Not Exist
SIP-Call-ID: 8ade0e910e814353abb38a91dac0de3a
SIP-CSeq: 1 BYE
Peer: 128.244.153.234:50372
$$end_record

LCS sends the Mac a 481 response from Communicator client

$$begin_record
LogType: protocol
Date: 2006/08/18 14:21:25
Direction: Outgoing
Peer: 128.244.153.234:50372
Message-Type: Response
Start-Line: SIP/2.0 481 Call Leg/Transaction Does Not Exist
To: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
From: <sip:mac-user@contoso.local>epid=0cb058af1a;tag=c0f5fe982ec411db8d2f0014510d30fe
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 BYE
Via: SIP/2.0/TLS 128.244.153.234:50372;ms-received-port=50372;ms-received-cid=24c00
Content-Length: 0
Other-Headers: Authentication-Info: NTLM rspauth="01000000898048FC93C8E6D464000000", srand="99E5A17D", snum="15", opaque="4252F741", qop="auth", targetname="lcsserver.contoso.local", realm="SIP Communications Service"
Other-Headers: User-Agent: LCC/1.3
$$end_record

LCS receives Cancel from Communicator user workstation (due to timeout I believe)

$$begin_record
LogType: protocol
Date: 2006/08/18 14:23:37
Direction: Incoming
Peer: 128.244.3.172:3786
Message-Type: Request
Start-Line: CANCEL sip:mac-user@contoso.local SIP/2.0
To: <sip:mac-user@contoso.local>
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 CANCEL
Via: SIP/2.0/TLS 128.244.3.172:3786
Max-Forwards: 70
Content-Length: 0
Other-Headers: User-Agent: LCC/1.3
Other-Headers: Proxy-Authorization: Kerberos qop="auth", realm="SIP Communications Service", opaque="83A4EBBE", crand="d918a105", cnum="176", targetname="sip/lcsserver.contoso.local", response="602306092a864886f71201020201011100ffffffff3e6fd0b7603791178c16ffe12b716a79"
$$end_record

$$begin_record
LogType: diagnostic
Date: 2006/08/18 14:23:37
Severity: information
Text: Response successfully routed
SIP-Start-Line: SIP/2.0 481 Call leg unavailable
SIP-Call-ID: 8ade0e910e814353abb38a91dac0de3a
SIP-CSeq: 1 CANCEL
Peer: 128.244.3.172:3786
$$end_record

LCS Server responds to Communicator client with 481 as the call-leg is no longer available due to the Bye sent by Mac

$$begin_record
LogType: protocol
Date: 2006/08/18 14:23:37
Direction: Outgoing
Origin: Local
Peer: 128.244.3.172:3786
Message-Type: Response
Start-Line: SIP/2.0 481 Call leg unavailable
To: <sip:mac-user@contoso.local>tag=AEF3CEF743455F6E8E381050237A9AEE
From: "Office Communicator" <sip:oc-user@contoso.local>tag=27b77a6f2b;epid=dffd569509
Call-ID: 8ade0e910e814353abb38a91dac0de3a
CSeq: 1 CANCEL
Via: SIP/2.0/TLS 128.244.3.172:3786;ms-received-port=3786;ms-received-cid=4000
Content-Length: 0
Other-Headers: Authentication-Info: Kerberos rspauth="602306092A864886F71201020201011100FFFFFFFFE58D11FFE9566CD206299D97C14A5D7A", srand="DE150E43", snum="376", opaque="83A4EBBE", qop="auth", targetname="sip/lcsserver.contoso.local", realm="SIP Communications Service"
$$end_record

C:\Program Files\Microsoft LC 2005\ResKit>lcserror 0xc3ed1810
0xc3ed1810 -> (SIPPROXY_E_INVALID_CONTACT_PARAMS) No description text found
0xc3ed1810 -> (SIPPROXY_E_INVALID_CONTACT_PARAMS) Bad request having an invalid contact parameter.

So for those of you out there with the Mac Messenger client, I hope that you can see how you can troubleshoot those clients with the LCS Server logging option and by using the same method of analysis to narrow the issue further.

TomL the MACKid :)

Mac Messenger 5.1.1 problem with Communicator

Additional resources