[asterisk-bugs] [JIRA] (ASTERISK-25793) chan_sip: Incoming SIP packets ignored

Paul Sandys (JIRA) noreply at issues.asterisk.org
Mon Feb 15 09:47:32 CST 2016


    [ https://issues.asterisk.org/jira/browse/ASTERISK-25793?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=229493#comment-229493 ] 

Paul Sandys commented on ASTERISK-25793:
----------------------------------------

It seems it's related to the chan_sip thread unable to process the UDP packets quick enough and they start dropping out of the system UDP buffers.

LInux UDP packet receive errors counter increases dramatically under load.

Before 'sip reload':

#netstat -s -u
Udp:
    90610147 packets received
    560701 packets to unknown port received.
    376701 packet receive errors
    82532640 packets sent

After 'sip reload':
Udp:
    90673068 packets received
    560705 packets to unknown port received.
    387273 packet receive errors
    82605540 packets sent



> chan_sip: 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: 1.8.23.1, 13.7.2
>         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)



More information about the asterisk-bugs mailing list