Can't get asterisk to answer other peer's OPTIONS keepalives

facha · November 4, 2010, 10:19am

Hello everyone.
I’m trying to establish a sip trunk with another peer. The problem is the other peer is sending OPTIONS keepalive packets and asterisk seems to ignore them.

This is what the other peer sends me (1.1.1.1 - the other peer, 2.2.2.2 - asterisk):
[size=85]10:59:23.490389 IP 1.1.1.1.5060 > 2.2.2.2.5060: SIP, length: 634 E....-@.9.,.>.(0...........:OPTIONS sip:2.2.2.2:5060 SIP/2.0 From: <sip:1.1.1.1:5060>;tag=c4-45026-d4e39b-17918e07-d4e39b To: <sip:2.2.2.2:5060> Call-ID: 4193b1e8-3028073e-13c4-d4e39b-3f99179e-9d0cad4f@1.1.1.1 CSeq: 2077373545 OPTIONS Via: SIP/2.0/UDP 1.1.1.1:5060;maddr=1.1.1.1;branch=z9hG4bK-d4e39b-3f99179e-44700184 User-agent: CS2000_NGSS/9.0 Max-Forwards: 70 Accept: multipart/mixed, application/isup, application/sdp, application/dtmf-relay, audio/telephone-event, application/simple-message-summary Allow: ACK,BYE,CANCEL,INVITE,OPTIONS,INFO,SUBSCRIBE,REFER,NOTIFY,PRACK,UPDATE Supported: 100rel Content-Length: 0[/size]

This is how the other peer is configured:

[size=85][some-peer] host=1.1.1.1 dtmfmode=inband insecure=invite,port type=peer nat=no qualify=1000 context=locals[/size]

Also I’ve found a similar question on the internet where this problem has been solved by configuring an “s” extension in the default context. I have it configured (exten=> s,1,Hangup), however the problem is still there. Asterisk doesn’t answer the other peer’s OPTIONS requests.

Please, help me sort this out.

david55 · November 4, 2010, 11:01am

sip set debug on output please, with appropriate debug and verbosity levels.

facha · November 4, 2010, 11:56am

This is what I see on console when I activate debugging. I guess those messages are OPTIONS requests that asterisk is sending to the other peer, not the ones that the other peer is sending.
asterisk -rvvvvvvvvvv -gggggggggg
[size=85][code]
CLI> sip set debug ip 1.1.1.1
SIP Debugging Enabled for IP: 1.1.1.1

Reliably Transmitting (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK2a5c5f0f;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as75134caa
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 6e9dc6c83cfb15ec55ec065f58e99ad8@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:34:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Retransmitting #1 (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK2a5c5f0f;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as75134caa
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 6e9dc6c83cfb15ec55ec065f58e99ad8@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:34:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Retransmitting #2 (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK2a5c5f0f;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as75134caa
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 6e9dc6c83cfb15ec55ec065f58e99ad8@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:34:59 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Reliably Transmitting (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK5612ad9b;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as68350bf8
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 19e63f5b0be91be91dc533b950717151@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:35:11 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Retransmitting #1 (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK5612ad9b;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as68350bf8
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 19e63f5b0be91be91dc533b950717151@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:35:11 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Retransmitting #2 (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK5612ad9b;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as68350bf8
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 19e63f5b0be91be91dc533b950717151@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:35:11 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Reliably Transmitting (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK64efc3f0;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as3cda0984
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 342f1b623e7031410f7f000b21bf5c2d@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:35:23 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

Retransmitting #1 (no NAT) to 1.1.1.1:5060:
OPTIONS sip:1.1.1.1 SIP/2.0
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK64efc3f0;rport
Max-Forwards: 70
From: “Unknown” sip:Unknown@2.2.2.2;tag=as3cda0984
To: sip:1.1.1.1
Contact: sip:Unknown@2.2.2.2
Call-ID: 342f1b623e7031410f7f000b21bf5c2d@2.2.2.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.0.25
Date: Thu, 04 Nov 2010 11:35:23 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

[/code][/size]

shmaize · November 18, 2010, 12:56pm

Well… I have the same problem

<--- SIP read from UDP:1.1.1.1:5080 ---> 
OPTIONS sip:2.2.2.2:5060 SIP/2.0
Call-ID: 7ee61f3291443916e4d631a411c231b5@1.1.1.1
CSeq: 100 OPTIONS
From: "Voxbone Monitoring" <sip:voxmon@1.1.1.1>;tag=95055
To: <sip:2.2.2.2:5060>
Max-Forwards: 30
Route: <sip:2.2.2.2:5060>
Via: SIP/2.0/UDP 1.1.1.1:5080;branch=z9hG4bKfabde850548854ad76efa0335e4bfe82
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
Looking for  in guests (domain 2.2.2.2:5060)

<--- Transmitting (no NAT) to 1.1.1.1:5080 ---> 
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 1.1.1.1:5080;branch=z9hG4bKfabde850548854ad76efa0335e4bfe82;received=1.1.1.1
From: "Voxbone Monitoring" <sip:voxmon@1.1.1.1>;tag=95055
To: <sip:2.2.2.2:5060>;tag=as5967e5ef
Call-ID: 7ee61f3291443916e4d631a411c231b5@1.1.1.1
CSeq: 100 OPTIONS
Server: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Accept: application/sdp
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '7ee61f3291443916e4d631a411c231b5@1.1.1.1' in 32000 ms (Method: OPTIONS)

My IP is 2.2.2.2 and the other server is 1.1.1.1.

shmaize · November 18, 2010, 2:43pm

This is the /var/log/asterisk/full with highest verbose and debug:

[Nov 18 16:38:05] DEBUG[6942] chan_sip.c: = Looking for  Call ID: 269dd7c535d89368dbb1770a86cd13df@1.1.1.1 (Checking From) --From tag 24178 --To-tag   
[Nov 18 16:38:05] DEBUG[6942] acl.c: For destination '1.1.1.1', our source address is '2.2.2.2'.
[Nov 18 16:38:05] DEBUG[6942] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 2.2.2.2:5060
[Nov 18 16:38:05] DEBUG[6942] chan_sip.c: Allocating new SIP dialog for 269dd7c535d89368dbb1770a86cd13df@1.1.1.1 - OPTIONS (No RTP) 
[Nov 18 16:38:05] DEBUG[6942] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS
[Nov 18 16:38:05] DEBUG[6942] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 1.1.1.1:5080
[Nov 18 16:38:05] DEBUG[6942] chan_sip.c: SIP message could not be handled, bad request: 269dd7c535d89368dbb1770a86cd13df@1.1.1.1

shmaize · November 22, 2010, 8:35am

Actually it seems like this is a bug in 1.8. In that line:

--- (9 headers 0 lines) ---
Looking for  in guests (domain 2.2.2.2:5060)

It should be “Looking for s in guests”. This is the default behavior, search for a “start” in the context=XX from sip.conf (general section) .

malcolmd · November 22, 2010, 10:16pm

Can someone reproduce this with 1.8 and then not reproduce it with 1.6.2.x?

Cheers.

shmaize · January 10, 2011, 11:55am

100% not working (reproduce) with 1.8 and 100% working (can’t reproduce) with 1.6.2

There’s an issue in the bug tracking system:
issues.asterisk.org/view.php?id=18348