[Home]

Summary:ASTERISK-03708: Polycom 600 hangup generates Internal Server Error from phone
Reporter:wjchan (wjchan)Labels:
Date Opened:2005-03-19 12:16:42.000-0600Date Closed:2008-01-15 15:27:56.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) polycom-hangup.txt
( 1) polycom-hangup-xlite.txt
( 2) scenario2-1.676.txt
( 3) scenario2-1.676-full.txt
( 4) scenario2-1.678.txt
( 5) scenario2-1.678-full.txt
Description:When the Polycom 600 receives a call and then I hang up the 600 first, the 600 returns 500 Internal Server Error.  *POLYCOM 600 INITIATED CALLS ARE FINE*

2 Scenarios:

1) TDM400P call to Polycom 600
600 hangs up first, 600 generates Internal Server Error

2) X-Lite call to Polycom 600
600 hangs up first, X-Lite still thinks it's connected, then I hang up X-Lite and 600 generates Internal Server Error

****** ADDITIONAL INFORMATION ******

Scenario 1 debug log attached
Comments:By: wjchan (wjchan) 2005-03-19 12:23:43.000-0600

Added Scenario 2 debug log: xlite calls polycom, pickup polycom, hang up polycom, then hang up xlite.
By: wjchan (wjchan) 2005-03-19 12:31:55.000-0600

Both scenarios are the same.  In Scenario 1, the TDM400P-connected phone is still connected after the 600 hangs up.
By: Kevin P. Fleming (kpfleming) 2005-03-19 12:36:12.000-0600

OK, Asterisk is ignoring the BYE requests sent by your Polycom phone, and then sending its own BYE later when the other end hangs up. Since the IP600 has already "forgotten" about the call, receiving a BYE for it generates an error message on the phone.

Interestingly, the IP600 is sending BYE with "CSeq: 1 BYE" even though the sequence number of the dialog is much higher than that. Without re-reading the RFC I'm not sure if that's kosher, but I suspect it's not. Then again, it worked before the recent changes to chan_sip :-)

As a comparison, look at the BYE from X-Lite...it has a CSeq number one higher than the previous request in the dialog, which is correct.

edited on: 03-19-05 12:37
By: wjchan (wjchan) 2005-03-19 12:41:06.000-0600

I rolled chan_sip.c back to 1.676 and the Polycom 600 hangup works fine.  So it's definitely something new.
By: Kevin P. Fleming (kpfleming) 2005-03-19 12:44:45.000-0600

OK, I'll go take a look.
By: Mark Spencer (markster) 2005-03-19 12:45:59.000-0600

Should already be fixed in CVS head.  Please confirm that it's already fixed in latest CVS head as of this morning.
By: Kevin P. Fleming (kpfleming) 2005-03-19 12:51:30.000-0600

Mark, he already posted that he's testing against chan_sip 1.678, which is what you committed this morning. This also does not look like the same problem, this is not Asterisk transmitting incorrectly, it's ignoring a packet from the phone.
By: Kevin P. Fleming (kpfleming) 2005-03-19 13:19:23.000-0600

OK, there are some debug lines in chan_sip that we need to see... can you re-run scenario 2 with both "sip debug" and "set debug 255" enabled?
By: Kevin P. Fleming (kpfleming) 2005-03-19 14:50:43.000-0600

Grrr... thanks for the files, but we're fighting the inconsistent debug output methods here.

The lines I'm looking for actually are going into the "debug" log via the logger, not the CLI. Specifically, I want to ensure that chan_sip is correctly parsing the BYE request and getting into the handle_request_bye function.
By: Olle Johansson (oej) 2005-03-19 15:18:09.000-0600

Please change the console logging in logger.conf to include the debug output...
By: Olle Johansson (oej) 2005-03-19 15:18:43.000-0600

Btw, the Polycom *should* answer "Call leg does not exist" :-)
By: Olle Johansson (oej) 2005-03-19 15:30:29.000-0600

...also waiting for a complete SIP debug output...
By: wjchan (wjchan) 2005-03-19 15:37:40.000-0600

Are the -full.txt files complete enough.  Sorry, newbie here.
By: wjchan (wjchan) 2005-03-19 17:03:44.000-0600

This fixes it but it's a total hack job:

--- chan_sip-1.680.c    2005-03-19 15:00:19.345388222 -0800
+++ chan_sip.c  2005-03-19 14:56:30.198366450 -0800
@@ -8621,7 +8621,7 @@
       if (option_debug > 2)
               ast_log(LOG_DEBUG, "**** Received %s (%d) - Command in SIP %s\n", sip_methods[p->method].text, sip_methods[p->method].id, cmd);

-       if (p->icseq && (p->icseq > seqno)) {
+       if (p->icseq && (p->icseq > seqno) && strcasecmp(cmd, "BYE")) {
               ast_log(LOG_DEBUG, "Ignoring too old SIP packet packet %d (expecting >= %d)\n", seqno, p->icseq);
               return -1;
       } else if (p->icseq && (p->icseq == seqno) && (strcasecmp(cmd, "CANCEL") || ast_test_flag(p, SIP_ALREADYGONE))) {
By: Mark Spencer (markster) 2005-03-19 17:14:24.000-0600

This is not a bug in Asterisk.  the "BYE" is received with seqno "1" while the "INVITE" was with "102", violating SIP protocol (they MUST use increasing sequence numbers).
By: Kevin P. Fleming (kpfleming) 2005-03-19 17:30:29.000-0600

I do not believe that is a correct interpretation of the RFC, and I don't believe the IP600 is doing anything wrong here.

The CSeq value of 102 for the INVITE was generated at the Asterisk end, but that does not control the CSeq value that the IP600 should be using for requests that it generates, only for responses it sends to Asterisk's requests. Each end has their own separate sequence number and they do not have any bearing on each other.

Since the BYE is the _first_ request the IP600 has generated during the SIP dialog that was initiated by Asterisk's INVITE, it is free to use _any_ initial value for the sequence number that it deems useful.

Quoting the RFC, section 12.2.1.1:

Requests within a dialog MUST contain strictly monotonically
increasing and contiguous CSeq sequence numbers (increasing-by-one)
in each direction (excepting ACK and CANCEL of course, whose numbers
equal the requests being acknowledged or cancelled). Therefore, if
the local sequence number is not empty, the value of the local
sequence number MUST be incremented by one, and this value MUST be
placed into the CSeq header field. If the local sequence number is
empty, an initial value MUST be chosen using the guidelines of
Section 8.1.1.5.

Section 8.1.1.5:

The CSeq header field serves as a way to identify and order
transactions. It consists of a sequence number and a method. The
method MUST match that of the request. For non-REGISTER requests
outside of a dialog, the sequence number value is arbitrary. The
sequence number value MUST be expressible as a 32-bit unsigned
integer and MUST be less than 2**31. As long as it follows the above
guidelines, a client may use any mechanism it would like to select
CSeq header field values.
By: Olle Johansson (oej) 2005-03-19 17:44:01.000-0600

A BYE is a new transaction, but still a request within a dialog. See 12.2.1.

On the other hand, the example in 24.2 show a new cseq for the bye, exactly like the polycom here.

I guess what kpfleming says, is that client and server has separate cseqs for the same dialog, right?
By: Mark Spencer (markster) 2005-03-19 17:45:23.000-0600

You are correct, this is another side effect of OEJ's request patch!  We increment the icseq only on REQUEST not on RESPONSE.  Fixed in CVS head.

OEJ: If you still think SIP is a good protocol, let me know.
By: Digium Subversion (svnbot) 2008-01-15 15:27:56.000-0600

Repository: asterisk
Revision: 5208

U   trunk/channels/chan_sip.c

------------------------------------------------------------------------
r5208 | markster | 2008-01-15 15:27:56 -0600 (Tue, 15 Jan 2008) | 2 lines

icseq increments only on requests, not responses (bug ASTERISK-3708)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=5208