[Home]

Summary:ASTERISK-22791: asterisk sends Re-INVITE after receiving a BYE
Reporter:not here (looserouting)Labels:
Date Opened:2013-10-29 08:29:31Date Closed:2014-10-12 03:17:31
Priority:TrivialRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/General Channels/chan_sip/T.38 Resources/res_fax
Versions:11.6.0 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) debug
( 1) messages
( 2) scrubed_messages
( 3) sip.conf
Description:i am receiving faxes with receiveFAX().
after transmitting the document with t38 asterisk changes back to g711.

Sometimes it happens that even after receiving a BYE asterisk is sending these Re-INVITEs.

i can provide a sip trace but i don't wanna share it in public.
Comments:By: Matt Jordan (mjordan) 2013-10-29 09:11:36.228-0500

If the reason you do not want to share the log files is due to IP address disclosure, you can always scrub a DEBUG log containing 'sip set debug on' traces before attaching it to the issue. Such a log file would be required to debug and - if there is a bug - fix the issue.

If a pcap is necessary as well, we can lock the issue down; however, locking an issue is done only as a last resort. It prevents others from assisting in the troubleshooting sharing in the solution, so we would prefer not to do that.

By: not here (looserouting) 2013-10-29 10:19:42.627-0500

i may have changed the ip addresses and the domain in my debug log


By: not here (looserouting) 2013-10-29 10:22:18.281-0500

i should mention there is a re-INVITE race.

By: Rusty Newton (rnewton) 2013-11-20 18:40:58.577-0600

The debug file alone isn't clear enough. Please attach a debug log along with VERBOSE turned up to 5, and "sip set debug on". As Matt mentioned, sanitize the log of IP addresses if you are concerned about that aspect. Thanks!

By: not here (looserouting) 2013-11-21 07:53:37.139-0600

I was able to hit the race conditon again.
Here is the new log

By: Matt Jordan (mjordan) 2013-11-21 09:40:41.880-0600

Unfortunately, this log file doesn't show the actual SIP messages. Please reproduce the problem with 'sip set debug on'.

That aside, you definitely have something odd being sent to you:
{noformat}
[Oct 29 15:53:53] DEBUG[5379] chan_sip.c: Done building SDP. Settling with this capability: (alaw)
[Oct 29 15:53:53] DEBUG[5379] chan_sip.c: Initializing already initialized SIP dialog 526FCBDC-0032023B@DDUS0_PCU-251 (presumably reinvite)
[Oct 29 15:53:53] DEBUG[5379] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.0.0.71:5060
[Oct 29 15:53:53] DEBUG[5379] chan_sip.c: = Looking for  Call ID: 526FCBDC-0032023B@DDUS0_PCU-251 (Checking To) --From tag 526FCBDC-68828A0-3E86ED98 --To-tag as2b19629d  
[Oct 29 15:53:53] DEBUG[5379] chan_sip.c: That's odd...  Got a response on a call we don't know about. Callid 526FCBDC-0032023B@DDUS0_PCU-251
[Oct 29 15:53:53] DEBUG[5379] chan_sip.c: Invalid SIP message - rejected , no callid, len 358
{noformat}

We'll see what the actual messages are, but getting invalid SIP messages is not a good start.

By: not here (looserouting) 2013-11-22 06:46:28.422-0600

Hi Jordan,

i forgot to log the verbose messages.

as you can see in the debug log the line "That's "odd..." appears after the BYE. That's the reason asterisk dont' know about the call.




By: not here (looserouting) 2013-11-22 06:50:08.839-0600

messages+verbose

By: not here (looserouting) 2013-11-22 06:50:44.491-0600

i am pretty sure all SIP pakets are fine

By: Walter Doekes (wdoekes) 2013-11-22 07:45:22.834-0600

Ok, so you're:

- sending a re-invite
- receiving a 491 glare
- sending an ack to the 491
- receiving a bye
- sending a 200 to the bye

- destroying the call

- sending the re-invite that was delayed because of the 491
- receiving a 100 and 481 which doesn't match any call because it was destroyed
...

That sounds like something we should be able to reproduce.

By: not here (looserouting) 2013-11-22 10:15:23.736-0600

Hi Walter,

that's what I see looking at the log.

it is strange that the SBC sends the 491 to the asterisk because there wasn't any other request on this side of the call. Maybe the SBC received the BYE from the other side and sends the 491 while processing it. now i am asking myself if this behaviour is conform with the RFC.

But this should't change the fact that asterisk should't send the re-INVITEs after the hangup.

By: not here (looserouting) 2013-12-09 07:40:37.498-0600

I tested the latest svn because ASTERISK-21242 was solved and I thought maybe this issue was related.
But it isn't. Same issue with r403450

By: Rusty Newton (rnewton) 2013-12-10 19:20:12.522-0600

Looks like a bug to me. Can you attach your scrubbed complete sip.conf as well?

By: not here (looserouting) 2013-12-11 05:56:54.403-0600

There it is. nothing fancy. it's just a test system.

By: Walter Doekes (wdoekes) 2014-08-13 02:42:01.602-0500

I just ran into this (in conjunction with ASTERISK-20784).

By: Walter Doekes (wdoekes) 2014-10-09 02:27:26.421-0500

Paolo could you test this?
https://reviewboard.asterisk.org/r/4056/

Test case for the asterisk test suite is here:
https://reviewboard.asterisk.org/r/4055/

By: not here (looserouting) 2014-10-09 14:57:33.471-0500

I got problems with the test case for asterisk test suite.
my sipp version fails whe sending the reINVITE with "media_port keyword with no audio or video on the current line (m=image )."

looks like sipp only knows video and audio type. Do you use a patched sipp ?

By: Walter Doekes (wdoekes) 2014-10-09 15:08:08.797-0500

Good question. I think I'm using the latest github version: https://github.com/SIPp/sipp/commits/master

But I see the problem. I'm running without pcapplay:
{noformat}
#ifdef PCAPPLAY
           char *begin = dest;
           while (begin > msg_buffer) {
               if (*begin == '\n') {
                   break;
               }
               begin--;
           }
           if (begin == msg_buffer) {
               ERROR("Can not find beginning of a line for the media port!\n");
           }
           if (strstr(begin, "audio")) {
               if (media_ip_is_ipv6) {
                   (_RCAST(struct sockaddr_in6 *, &(play_args_a.from)))->sin6_port = port;
               } else {
                   (_RCAST(struct sockaddr_in *, &(play_args_a.from)))->sin_port = port;
               }
           } else if (strstr(begin, "video")) {
               if (media_ip_is_ipv6) {
                   (_RCAST(struct sockaddr_in6 *, &(play_args_v.from)))->sin6_port = port;
               } else {
                   (_RCAST(struct sockaddr_in *, &(play_args_v.from)))->sin_port = port;
               }
           } else {
               ERROR("media_port keyword with no audio or video on the current line (%s)", begin);
           }
#endif
{noformat}

No pcapplay, no problem. I'll see if I can get that fixed.

Could you try the asterisk patch in the mean time?

By: Walter Doekes (wdoekes) 2014-10-09 16:19:00.850-0500

Ok. I have updated r4055 to play nice with PCAPPLAY.

By: not here (looserouting) 2014-10-10 06:17:20.414-0500

i can confirm that my asterisk with applied patch passes the test in r4055

sadly i have no access to my old test scenario, so i can't confirm that it will work in this case.

I want to try something similar to what r4055 was doing first( sipp without pcapplay). But instead of Bob I want to use faxreceive() in extension.conf.

alice INVITE -> asterisk
asterisk 200 OK  -> alice
alice reINVITE with t38 -> asterisk
asterisk 200OK -> alice
the fax transmission will  fail because there is no stream and asterisk would switch back to audio (befor ending the call) right ? So
asterisk reINVITE -> alice
alice 491 -> asterisk
alice BYE -> asterisk
Wait for asterisks behaviour

What do you think ?

i am going in vacation in a couple of hours and will return in one week. You probably won't hear anything from me until I return.










By: Walter Doekes (wdoekes) 2014-10-12 03:08:54.053-0500

Lovely. But I'm going to commit it. I expect this to fix the rare issues I've been seeing.

If it doesn't, we can reopen.

Thanks for testing the testcase!

By: not here (looserouting) 2014-10-21 06:40:31.625-0500

asterisk passes my testcase too. thank you !