[asterisk-users] SIP OPTIONS response from the peer is ignored - peer becomes UNREACHABLE

Thu Mar 25 12:29:23 CDT 2010

----- "Asterisk" <asterisk at abraxas.si> wrote:

> Hi Steve,
> 
> Yes, that's true. It seems that Asterisk gets it with great delay. For
> instance:
> 
> Asterisk says:
> ==============
> 
> Mar 25 11:26:54 VERBOSE[1385] logger.c: Reliably Transmitting (no NAT)
> to 172.11.11.2:5060:
> OPTIONS sip:MyTestPhone at 172.11.11.2 SIP/2.0
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>
> Contact: <sip:asterisk at 172.11.0.201>
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> CSeq: 102 OPTIONS
> User-Agent: Asterisk PBX
> Max-Forwards: 70
> Date: Thu, 25 Mar 2010 10:26:54 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Content-Length: 0
> 
> 
> ---
> Mar 25 11:26:58 VERBOSE[1385] logger.c: Retransmitting #1 (no NAT) to
> 172.11.11.2:5060:
> OPTIONS sip:MyTestPhone at 172.11.11.2 SIP/2.0
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>
> Contact: <sip:asterisk at 172.11.0.201>
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> CSeq: 102 OPTIONS
> User-Agent: Asterisk PBX
> Max-Forwards: 70
> Date: Thu, 25 Mar 2010 10:26:54 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Content-Length: 0
> 
> 
> ---
> Mar 25 11:26:58 NOTICE[1385] chan_sip.c: Peer 'MyTestPhone' is now
> UNREACHABLE!  Last qualify: 52
> Mar 25 11:26:58 VERBOSE[1385] logger.c: Destroying call
> '5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201'
> 
> === WEIRD: Asterisk logs two responses reposnses then (last one at
> 11:27:02 eventhough last OPTIONS request was sent by Asterisk at
> 11:26:58):
> 
> Mar 25 11:26:58 VERBOSE[1385] logger.c:
> <-- SIP read from 172.11.11.2:5060: 
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>;tag=CD9ADC40-8CECD6C3
> CSeq: 102 OPTIONS
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> Contact: <sip:MyTestPhone at 172.11.11.2>
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE,
> NOTIFY, PRACK, UPDATE, REFER
> User-Agent: PolycomSoundPointIP-SPIP_601-UA/2.2.0.0047
> Content-Length: 0
> 
> 
> Mar 25 11:26:58 VERBOSE[1385] logger.c: --- (10 headers 0 lines) ---
> Mar 25 11:27:02 VERBOSE[1385] logger.c: 
> <-- SIP read from 172.11.11.2:5060: 
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>;tag=CD9ADC40-8CECD6C3
> CSeq: 102 OPTIONS
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> Contact: <sip:MyTestPhone at 172.11.11.2>
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE,
> NOTIFY, PRACK, UPDATE, REFER
> User-Agent: PolycomSoundPointIP-SPIP_601-UA/2.2.0.0047
> Content-Length: 0
> 
> 
> But Wireshark for the same conversation says:
> =============================================
> 
> >> Sent by Asterisk at 11:26:54.047483000
> -----------------------------------------
> OPTIONS sip:MyTestPhone at 172.11.11.2 SIP/2.0
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>
> Contact: <sip:asterisk at 172.11.0.201>
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> CSeq: 102 OPTIONS
> User-Agent: Asterisk PBX
> Max-Forwards: 70
> Date: Thu, 25 Mar 2010 10:26:54 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Content-Length: 0
> 
> << Received from the phone at 11:26:54.097936000
> ------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>;tag=CD9ADC40-8CECD6C3
> CSeq: 102 OPTIONS
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> Contact: <sip:MyTestPhone at 172.11.11.2>
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE,
> NOTIFY, PRACK, UPDATE, REFER
> User-Agent: PolycomSoundPointIP-SPIP_601-UA/2.2.0.0047
> Content-Length: 0
> 
> >> Sent by Asterisk at 11:26:58.486339000
> -----------------------------------------
> OPTIONS sip:MyTestPhone at 172.11.11.2 SIP/2.0
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>
> Contact: <sip:asterisk at 172.11.0.201>
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> CSeq: 102 OPTIONS
> User-Agent: Asterisk PBX
> Max-Forwards: 70
> Date: Thu, 25 Mar 2010 10:26:54 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Content-Length: 0
> 
> << Received from the phone at 11:26:58.524907000
> ------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 172.11.0.201:5060;branch=z9hG4bK41333ebd;rport
> From: "asterisk" <sip:asterisk at 172.11.0.201>;tag=as5e2d8165
> To: <sip:MyTestPhone at 172.11.11.2>;tag=CD9ADC40-8CECD6C3
> CSeq: 102 OPTIONS
> Call-ID: 5bf37c2d2d25a9346cc272d71c3a86e2 at 172.11.0.201
> Contact: <sip:MyTestPhone at 172.11.11.2>
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE,
> NOTIFY, PRACK, UPDATE, REFER
> User-Agent: PolycomSoundPointIP-SPIP_601-UA/2.2.0.0047
> Content-Length: 0
> 
> 
> Hmmmmm, what could be causing such delay between Wireshark getting the
> data and Asterisk logging it?
> 
> Regards,
> Alex
> 
> -----Original Message-----
> From: asterisk-users-bounces at lists.digium.com
> [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Steve
> Howes
> Sent: Thursday, March 25, 2010 11:35 AM
> To: Asterisk Users Mailing List - Non-Commercial Discussion
> Subject: Re: [asterisk-users] SIP OPTIONS response from the peer is
> ignored - peer becomes UNREACHABLE
> 
> On 25 Mar 2010, at 10:18, Asterisk wrote:
> > How is it possible that the peer becames UNREACHABLE eventhough
> Wireshark logged its proper response? 
> 
> Wireshark received it, doesn't mean Asterisk did. what does a sip
> debug in Asterisk show?
> 
> S

This is interesting as I am seeing the same issue with Snom 360s and M3s on Asterisk 1.6.1.14 and 1.6.2.6.  I have also received a report from a colleague who sees a similar issue with Polycoms on Microsoft OCS.
-- 
Thanks, Phil