[Home]

Summary:ASTERISK-13512: dead SIP channels get not cleared though in status SIP_NEEDDESTROY thus are blocking ports
Reporter:pguido (pguido)Labels:
Date Opened:2009-02-04 07:52:54.000-0600Date Closed:2011-06-07 14:02:59
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) sip_call_out_of_sync.txt
Description:The number of dead channels continuesly increases which then requires a restart of asterisk to clean up the locked channels and udp ports. The channels look like:

<client ip>     <phone_nr>   5078a9a7133  00102/00001  0x0 (nothing)    No  (d)  Rx: BYE                  
<client ip>     <phone_nr>   1ebd5e2f7fb  00102/00001  0x0 (nothing)    No  (d)  Rx: BYE

It seems the qualify=yes option with the sip OPTIONS packet disrupts the sequence of the call as can be seen in the following trace.

After an INVITE the called phone answers with multiple SDP packets, which aren't forwarded by asterisk. Instead asterisk sends the OPTION packet to the calling phone. Only after this handshake is acknowledged asterisk continues with the call handshake sequence. But during this time the called phone has already timed out and terminated the call with BYE. Nevertheless the hold back SDP packets are now forwarded too late to the calling party.

Both phones are within the same client IP behind a NAT Router.
Phone 490 has port 1126. The calling phone has port 1186.


|Time     | <IP A>          |   <Server IP>     |
|3200,079 |         Request: INVITE sip           |SIP/SDP: Request: INVITE sip:490@<Server IP>;transport=udp, with session description
|         |(1186)   ------------------>  (5060)   |
|3200,080 |         Status: 100 Trying            |SIP: Status: 100 Trying
|         |(1186)   <------------------  (5060)   |
|3200,093 |         Request: INVITE sip           |SIP/SDP: Request: INVITE sip:490@<IP A>:1126;transport=udp, with session description
|         |(1126)   <------------------  (5060)   |
|3200,251 |         Status: 180 Ringing           |SIP: Status: 180 Ringing
|         |(1126)   ------------------>  (5060)   |
|3200,251 |         Status: 180 Ringing           |SIP: Status: 180 Ringing
|         |(1186)   <------------------  (5060)   |
|3210,135 |         Status: 200 OK, wit           |SIP/SDP: Status: 200 OK, with session description
|         |(1126)   ------------------>  (5060)   |
|3210,627 |         Status: 200 OK, wit           |SIP/SDP: Status: 200 OK, with session description
|         |(1126)   ------------------>  (5060)   |
|3211,628 |         Status: 200 OK, wit           |SIP/SDP: Status: 200 OK, with session description
|         |(1126)   ------------------>  (5060)   |
|3213,039 |         Request: OPTIONS si           |SIP: Request: OPTIONS sip:458@<IP A>:1186;transport=udp
|         |(1186)   <------------------  (5060)   |
|3213,100 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1186)   ------------------>  (5060)   |
|3213,627 |         Status: 200 OK, wit           |SIP/SDP: Status: 200 OK, with session description
|         |(1126)   ------------------>  (5060)   |
|3217,627 |         Status: 200 OK, wit           |SIP/SDP: Status: 200 OK, with session description
|         |(1126)   ------------------>  (5060)   |
|3219,213 |         Request: BYE sip:06           |SIP: Request: BYE sip:458@<Server IP>
|         |(1126)   ------------------>  (5060)   |
|3219,213 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1126)   <------------------  (5060)   |
|3219,500 |         Status: 180 Ringing           |SIP: Status: 180 Ringing
|         |(1186)   <------------------  (5060)   |
|3221,021 |         Status: 200 OK, wit           |SIP/SDP: Status: 200 OK, with session description
|         |(1186)   <------------------  (5060)   |
|3221,137 |         Request: ACK sip:49           |SIP: Request: ACK sip:490@<Server IP>
|         |(1186)   ------------------>  (5060)   |
|3259,499 |         Request: OPTIONS si           |SIP: Request: OPTIONS sip:490@<IP A>:1126;transport=udp
|         |(1126)   <------------------  (5060)   |
|3259,636 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1126)   ------------------>  (5060)   |
|3273,099 |         Request: OPTIONS si           |SIP: Request: OPTIONS sip:458@<IP A>:1186;transport=udp
|         |(1186)   <------------------  (5060)   |
|3273,172 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1186)   ------------------>  (5060)   |
|3319,635 |         Request: OPTIONS si           |SIP: Request: OPTIONS sip:490@<IP A>:1126;transport=udp
|         |(1126)   <------------------  (5060)   |
|3319,707 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1126)   ------------------>  (5060)   |
|3333,171 |         Request: OPTIONS si           |SIP: Request: OPTIONS sip:458@<IP A>:1186;transport=udp
|         |(1186)   <------------------  (5060)   |
|3333,241 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1186)   ------------------>  (5060)   |
|3346,921 |         Request: BYE sip:06           |SIP: Request: BYE sip:458@<IP A>:1186;transport=udp
|         |(1186)   <------------------  (5060)   |
|3346,986 |         Status: 200 OK                |SIP: Status: 200 OK
|         |(1186)   ------------------>  (5060)   |



This could be related to http://bugs.digium.com/view.php?id=13957
Comments:By: Tilghman Lesher (tilghman) 2009-02-05 01:03:52.000-0600

Please upgrade to 1.4.23.1 and try again.  This has already been fixed.
By: pguido (pguido) 2009-02-05 01:41:49.000-0600

A short term upgrade is not planned, could you please refer to the bugnote with it's fix?
By: Tilghman Lesher (tilghman) 2009-02-05 11:21:46.000-0600

http://svn.digium.com/view/asterisk?view=revision&revision=144420
By: pguido (pguido) 2009-02-06 01:45:26.000-0600

sip_show channels shows: ast_test_flag(&cur->flags[0], SIP_NEEDDESTROY)) which has value 2.

The change in revision 144420 looks for me that it only works if this flag is not set. Additionally this is related to a cancel message, which is not sent in the depicted message flow diagram.

Why does the scheduler not remove the channel? Is it because the dialog is partially gone? After sending 5 times a SDP A sends at 3219,213 a BYE, which is OKed by asterisk, so half of the call is gone.

Nevertheless Asterisk sends a RINGING and a SDP starting at 3219,500. So the second half of the call is just starting.

Does this lead to a situation where the scheduler cannot remove a channel?
By: Joshua C. Colp (jcolp) 2009-02-06 11:51:43.000-0600

Can you please upload a complete sip debug of this happening with core debug also turned on? (debug in logger.conf to console and core set debug 2)
By: pguido (pguido) 2009-02-09 08:34:39.000-0600

I have found identical calls and the behaviour is:

1) a terminal receives an INVITE
2) it sends back a RINGING
3) it then sends a BYE

then the channel get's stuck. We have this behaviour with different terminals.

This exactly fits for 5 of 5 patterns.

Sorry I can't give you sip debug or core debug as this is a production system.
By: Joshua C. Colp (jcolp) 2009-02-09 09:03:57.000-0600

That does indeed sound familiar and I think I fixed that awhile back or helped to fix it... so we really do need you to try the latest version. If that isn't possible we'll have to suspend this until you can.
By: pguido (pguido) 2009-02-10 00:48:42.000-0600

Probably it's the additional line

__sip_pretend_ack(p);

in the function handle_request_bye.

I will test this.
By: pguido (pguido) 2009-02-13 03:19:57.000-0600

Solution verified: With this minor change no more hanging SIP channels.
Maybe the solution also applies for: http://bugs.digium.com/view.php?id=13957
By: Joshua C. Colp (jcolp) 2009-02-13 08:36:08.000-0600

Closed per reporter, issue has already been fixed.