[asterisk-bugs] [JIRA] (ASTERISK-25793) incoming SIP packets ignored

Sun Feb 14 21:07:33 CST 2016

Paul Sandys created ASTERISK-25793:
--------------------------------------

             Summary:  incoming SIP packets ignored
                 Key: ASTERISK-25793
                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-25793
             Project: Asterisk
          Issue Type: Bug
      Security Level: None
          Components: Channels/chan_sip/General
    Affects Versions: 13.7.2, 1.8.23.1
         Environment: Tried on both CentOS 5,  FreeBSD 10.2.

1900 SIP peers. FreeBSD behaves slightly worse.
            Reporter: Paul Sandys
            Severity: Critical

under load, the server starts ignoring incoming SIP packets. Here's a sample tcpdump and debug of a single peer:

sample tcpdump after 'sip reload':

21:48:23.388137 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 619
21:48:23.438331 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 344
21:48:26.875782 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 619
21:48:26.894757 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 344
21:48:27.230656 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 563
21:48:27.317277 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 341
21:48:27.428144 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 619
21:48:27.473680 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 344
21:48:28.229868 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 563
21:48:28.238773 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 341
21:48:28.875076 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 619
21:48:28.892387 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 344
21:48:32.875728 IP 216.139.145.228.5060 > 10.9.0.8.5062: SIP, length: 619
21:48:32.884182 IP 10.9.0.8.5062 > 216.139.145.228.5060: SIP, length: 344

All the SIP packets get replies from the 10.9.0.8 SIP peer.

However, asterisk sends upto 5 retries before it actually notices an incoming SIP packet back from 10.9.0.8:

[Feb 14 21:48:23] VERBOSE[100143] chan_sip.c: Reliably Transmitting (NAT) to 10.9.0.8:5062:
NOTIFY sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK3712732d;rport
Max-Forwards: 70
Route: <sip:uniti-203 at 10.9.0.8:5062>
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as71b74687
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1945212930
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 93048308 at 10.9.0.8
CSeq: 110 NOTIFY
User-Agent: USA-Connect SIP
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 95

Messages-Waiting: no
Message-Account: sip:asterisk at 216.139.145.228
Voice-Message: 0/0 (0/0)

[Feb 14 21:48:26] VERBOSE[100143] chan_sip.c: Retransmitting #1 (NAT) to 10.9.0.8:5062:
NOTIFY sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK3712732d;rport
Max-Forwards: 70
Route: <sip:uniti-203 at 10.9.0.8:5062>
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as71b74687
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1945212930
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 93048308 at 10.9.0.8
CSeq: 110 NOTIFY
User-Agent: USA-Connect SIP
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 95

Messages-Waiting: no
Message-Account: sip:asterisk at 216.139.145.228
Voice-Message: 0/0 (0/0)

---
[Feb 14 21:48:27] VERBOSE[100143] chan_sip.c: Reliably Transmitting (NAT) to 10.9.0.8:5062:
OPTIONS sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK36492eae;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as12d9c8a7
To: <sip:uniti-203 at 10.9.0.8:5062>
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 30aa358b55e4cd031dad502075c8d2e0 at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: USA-Connect SIP
Date: Mon, 15 Feb 2016 02:48:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---
NOTIFY sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK3712732d;rport
Max-Forwards: 70
Route: <sip:uniti-203 at 10.9.0.8:5062>
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as71b74687
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1945212930
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 93048308 at 10.9.0.8
CSeq: 110 NOTIFY
User-Agent: USA-Connect SIP
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 95

Messages-Waiting: no
Message-Account: sip:asterisk at 216.139.145.228
Voice-Message: 0/0 (0/0)

---
[Feb 14 21:48:28] VERBOSE[100143] chan_sip.c: Retransmitting #1 (NAT) to 10.9.0.8:5062:
OPTIONS sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK36492eae;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as12d9c8a7
To: <sip:uniti-203 at 10.9.0.8:5062>
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 30aa358b55e4cd031dad502075c8d2e0 at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: USA-Connect SIP
Date: Mon, 15 Feb 2016 02:48:27 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---
[Feb 14 21:48:28] VERBOSE[100143] chan_sip.c:
<--- SIP read from UDP:10.9.0.8:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK36492eae;rport
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as12d9c8a7
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=3502137553
Call-ID: 30aa358b55e4cd031dad502075c8d2e0 at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: Yealink SIP-W52P 25.73.0.40
Content-Length: 0

<------------->
[Feb 14 21:48:28] VERBOSE[100143] chan_sip.c: Retransmitting #3 (NAT) to 10.9.0.8:5062:
NOTIFY sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK3712732d;rport
Max-Forwards: 70
Route: <sip:uniti-203 at 10.9.0.8:5062>
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as71b74687
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1945212930
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 93048308 at 10.9.0.8
CSeq: 110 NOTIFY
User-Agent: USA-Connect SIP
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 95

Messages-Waiting: no
Message-Account: sip:asterisk at 216.139.145.228
Voice-Message: 0/0 (0/0)

---
[Feb 14 21:48:32] VERBOSE[100143] chan_sip.c: Retransmitting #4 (NAT) to 10.9.0.8:5062:
NOTIFY sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK3712732d;rport
Max-Forwards: 70
Route: <sip:uniti-203 at 10.9.0.8:5062>
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as71b74687
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1945212930
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 93048308 at 10.9.0.8
CSeq: 110 NOTIFY
User-Agent: USA-Connect SIP
Event: message-summary
Content-Type: application/simple-message-summary
Subscription-State: active
Content-Length: 95

Messages-Waiting: no
Message-Account: sip:asterisk at 216.139.145.228
Voice-Message: 0/0 (0/0)

---
[Feb 14 21:48:32] VERBOSE[100143] chan_sip.c:
<--- SIP read from UDP:10.9.0.8:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK3712732d;rport
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as71b74687
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1945212930
Call-ID: 93048308 at 10.9.0.8
CSeq: 110 NOTIFY
Contact: <sip:uniti-203 at 10.9.0.8:5062>
User-Agent: Yealink SIP-W52P 25.73.0.40
Content-Length: 0

<------------->
[Feb 14 21:49:28] VERBOSE[100143] chan_sip.c: Reliably Transmitting (NAT) to 10.9.0.8:5062:
OPTIONS sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK6d13e65f;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as6e365fbd
To: <sip:uniti-203 at 10.9.0.8:5062>
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 4963151c7b4fdfe36e51774f3ab1a8fc at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: USA-Connect SIP
Date: Mon, 15 Feb 2016 02:49:28 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---
[Feb 14 21:49:28] VERBOSE[100143] chan_sip.c:
<--- SIP read from UDP:10.9.0.8:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK6d13e65f;rport
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as6e365fbd
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=1225053376
Call-ID: 4963151c7b4fdfe36e51774f3ab1a8fc at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: Yealink SIP-W52P 25.73.0.40
Content-Length: 0

<------------->
BOSE[100143] chan_sip.c: Reliably Transmitting (NAT) to 10.9.0.8:5062:
OPTIONS sip:uniti-203 at 10.9.0.8:5062 SIP/2.0
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK2c2eb044;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as56b2ef15
To: <sip:uniti-203 at 10.9.0.8:5062>
Contact: <sip:Unknown at 216.139.145.228:5060>
Call-ID: 43e5334f5b4ecfb266b8fa4968b66bd3 at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: USA-Connect SIP
Date: Mon, 15 Feb 2016 02:50:28 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---
[Feb 14 21:50:28] VERBOSE[100143] chan_sip.c:
<--- SIP read from UDP:10.9.0.8:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.139.145.228:5060;branch=z9hG4bK2c2eb044;rport
From: "Unknown" <sip:Unknown at 216.139.145.228>;tag=as56b2ef15
To: <sip:uniti-203 at 10.9.0.8:5062>;tag=2003778940
Call-ID: 43e5334f5b4ecfb266b8fa4968b66bd3 at 216.139.145.228:5060
CSeq: 102 OPTIONS
User-Agent: Yealink SIP-W52P 25.73.0.40
Content-Length: 0

<------------->

--
This message was sent by Atlassian JIRA
(v6.2#6252)