[Freeswitch-users] Freeswitch sends BYE, Receives 200 OK, but keeps sending BYE's ?!

Fri Nov 18 15:36:53 MSK 2011

Just to have it directly in the mail, the problematic BYE with subsequent received messages: 

2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:508 Sending BYE to sofia/external-test/01140039999 
send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:47.650139: 
------------------------------------------------------------------------ 
BYE sip:0231140039999 at 187.111.X.Z SIP/2.0 
Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc 
Route: <sip:187.111.X.Y;lr;ftag=NyvaUBt4440rF;did=32a.2352b454> 
Max-Forwards: 70 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 20466239 BYE 
Contact: <sip:USERNAME at 187.103.My.IP:5085;transport=udp;gw=airtel.net.br> 
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:47 sofia/external-test/01140039999 Standard HANGUP, cause: NORMAL_CLEARING 

Supported: 100rel, timer, precondition, path, replaces 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external-test/01140039999) State HANGUP going to sleep 
Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999 at 187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" 
Reason: Q.850;cause=16;text="NORMAL_CLEARING" 
Content-Length: 0 

------------------------------------------------------------------------ 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:393 (sofia/external-test/01140039999) State Change CS_HANGUP -> CS_REPORTING 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_REPORTING 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:662 (sofia/external-test/01140039999) State REPORTING 
2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:1332 sofia/external-test/01140039999 skip receive message [UNBRIDGE] (channel is hungup already) 
2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:1335 sofia/external/freeswitch at pbx.toolfactory.net skip receive message [UNBRIDGE] (channel is hungup already) 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:2261 sofia/external/freeswitch at pbx.toolfactory.net skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:417 (sofia/external/freeswitch at pbx.toolfactory.net) State EXECUTE going to sleep 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch at pbx.toolfactory.net) Running State Change CS_HANGUP 
2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_async.c:978 Stop recording file /usr/local/freeswitch/recordings/queues/2011-11-18-05-23-23.126.01140039999.94b27bf8-11be-11e1-be76-bfe92509c5c7.wav 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_media_bug.c:480 Removing BUG from sofia/external/freeswitch at pbx.toolfactory.net 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external/freeswitch at pbx.toolfactory.net) State HANGUP 
2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:459 sofia/external/freeswitch at pbx.toolfactory.net Overriding SIP cause 480 with 200 from the other leg 
2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:465 Channel sofia/external/freeswitch at pbx.toolfactory.net hanging up, cause: NORMAL_CLEARING 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:47 sofia/external/freeswitch at pbx.toolfactory.net Standard HANGUP, cause: NORMAL_CLEARING 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external/freeswitch at pbx.toolfactory.net) State HANGUP going to sleep 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:393 (sofia/external/freeswitch at pbx.toolfactory.net) State Change CS_HANGUP -> CS_REPORTING 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch at pbx.toolfactory.net [BREAK] 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch at pbx.toolfactory.net) Running State Change CS_REPORTING 
2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:662 (sofia/external/freeswitch at pbx.toolfactory.net) State REPORTING 
recv 461 bytes from udp/[187.111.X.Y]:5060 at 08:23:47.653748: 
------------------------------------------------------------------------ 
SIP/2.0 200 OK 
Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 2147483647 BYE 
Server: Airtel Gateway 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO 
Supported: replaces, timer 
Content-Length: 0 

------------------------------------------------------------------------ 
send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:48.652955: 
------------------------------------------------------------------------ 
BYE sip:0231140039999 at 187.111.X.Z SIP/2.0 
Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc 
Route: <sip:187.111.X.Y;lr;ftag=NyvaUBt4440rF;did=32a.2352b454> 
Max-Forwards: 70 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 20466239 BYE 
Contact: <sip:USERNAME at 187.103.My.IP:5085;transport=udp;gw=airtel.net.br> 
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY 
Supported: 100rel, timer, precondition, path, replaces 
Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999 at 187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" 
Reason: Q.850;cause=16;text="NORMAL_CLEARING" 
Content-Length: 0 

------------------------------------------------------------------------ 
recv 461 bytes from udp/[187.111.X.Y]:5060 at 08:23:48.656032: 
------------------------------------------------------------------------ 
SIP/2.0 200 OK 
Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 2147483647 BYE 
Server: Airtel Gateway 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO 
Supported: replaces, timer 
Content-Length: 0 

------------------------------------------------------------------------ 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:79 sofia/external-test/01140039999 Standard REPORTING, cause: NORMAL_CLEARING 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:662 (sofia/external-test/01140039999) State REPORTING going to sleep 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:387 (sofia/external-test/01140039999) State Change CS_REPORTING -> CS_DESTROY 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_session.c:1377 Session 11055 (sofia/external-test/01140039999) Locked, Waiting on external entities 
2011-11-18 05:23:49.328907 [NOTICE] switch_core_session.c:1395 Session 11055 (sofia/external-test/01140039999) Ended 
2011-11-18 05:23:49.328907 [NOTICE] switch_core_session.c:1397 Close Channel sofia/external-test/01140039999 [CS_DESTROY] 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:491 (sofia/external-test/01140039999) Callstate Change HANGUP -> DOWN 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:494 (sofia/external-test/01140039999) Running State Change CS_DESTROY 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:504 (sofia/external-test/01140039999) State DESTROY 
2011-11-18 05:23:49.328907 [DEBUG] mod_sofia.c:370 sofia/external-test/01140039999 SOFIA DESTROY 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:86 sofia/external-test/01140039999 Standard DESTROY 
2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:504 (sofia/external-test/01140039999) State DESTROY going to sleep 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:79 sofia/external/freeswitch at pbx.toolfactory.net Standard REPORTING, cause: NORMAL_CLEARING 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:662 (sofia/external/freeswitch at pbx.toolfactory.net) State REPORTING going to sleep 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:387 (sofia/external/freeswitch at pbx.toolfactory.net) State Change CS_REPORTING -> CS_DESTROY 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch at pbx.toolfactory.net [BREAK] 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_session.c:1377 Session 11054 (sofia/external/freeswitch at pbx.toolfactory.net) Locked, Waiting on external entities 
2011-11-18 05:23:49.508907 [NOTICE] switch_core_session.c:1395 Session 11054 (sofia/external/freeswitch at pbx.toolfactory.net) Ended 
2011-11-18 05:23:49.508907 [NOTICE] switch_core_session.c:1397 Close Channel sofia/external/freeswitch at pbx.toolfactory.net [CS_DESTROY] 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:491 (sofia/external/freeswitch at pbx.toolfactory.net) Callstate Change HANGUP -> DOWN 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:494 (sofia/external/freeswitch at pbx.toolfactory.net) Running State Change CS_DESTROY 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:504 (sofia/external/freeswitch at pbx.toolfactory.net) State DESTROY 
2011-11-18 05:23:49.508907 [DEBUG] mod_sofia.c:370 sofia/external/freeswitch at pbx.toolfactory.net SOFIA DESTROY 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:86 sofia/external/freeswitch at pbx.toolfactory.net Standard DESTROY 
2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:504 (sofia/external/freeswitch at pbx.toolfactory.net) State DESTROY going to sleep 
send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:50.653194: 
------------------------------------------------------------------------ 
BYE sip:0231140039999 at 187.111.X.Z SIP/2.0 
Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc 
Route: <sip:187.111.X.Y;lr;ftag=NyvaUBt4440rF;did=32a.2352b454> 
Max-Forwards: 70 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 20466239 BYE 
Contact: <sip:USERNAME at 187.103.My.IP:5085;transport=udp;gw=airtel.net.br> 
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY 
Supported: 100rel, timer, precondition, path, replaces 
Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999 at 187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" 
Reason: Q.850;cause=16;text="NORMAL_CLEARING" 
Content-Length: 0 

------------------------------------------------------------------------ 
recv 461 bytes from udp/[187.111.X.Y]:5060 at 08:23:50.656440: 
------------------------------------------------------------------------ 
SIP/2.0 200 OK 
Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 2147483647 BYE 
Server: Airtel Gateway 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO 
Supported: replaces, timer 
Content-Length: 0 

------------------------------------------------------------------------ 
send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:54.653194: 
------------------------------------------------------------------------ 
BYE sip:0231140039999 at 187.111.X.Z SIP/2.0 
Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc 
Route: <sip:187.111.X.Y;lr;ftag=NyvaUBt4440rF;did=32a.2352b454> 
Max-Forwards: 70 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 20466239 BYE 
Contact: <sip:USERNAME at 187.103.My.IP:5085;transport=udp;gw=airtel.net.br> 
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY 
Supported: 100rel, timer, precondition, path, replaces 
Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999 at 187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" 
Reason: Q.850;cause=16;text="NORMAL_CLEARING" 
Content-Length: 0 

------------------------------------------------------------------------ 
recv 494 bytes from udp/[187.111.X.Y]:5060 at 08:23:54.656920: 
------------------------------------------------------------------------ 
SIP/2.0 481 Call leg/transaction does not exist 
Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc 
From: "Heinrich III S" <sip:USERNAME at airtel.net.br;transport=udp>;tag=NyvaUBt4440rF 
To: <sip:01140039999 at airtel.net.br>;tag=as62aa2285 
Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 
CSeq: 2147483647 BYE 
Server: Airtel Gateway 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO 
Supported: replaces, timer 
Content-Length: 0 

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

----- Original Message ----- 

From: "Brian West" <brian at freeswitch.org> 
To: "FreeSWITCH Users Help" <freeswitch-users at lists.freeswitch.org> 
Cc: "freeswitch-users" <freeswitch-users at lists.freeswitch.org> 
Sent: Friday, November 18, 2011 1:16:38 PM 
Subject: Re: [Freeswitch-users] Freeswitch sends BYE, Receives 200 OK, but keeps sending BYE's ?! 

That would indicate the dialog is not matching or the network path is not right! 

/b 

Sent from my iPhone 

On Nov 18, 2011, at 4:02 AM, Raimund Sacherer < raimund.sacherer at logitravel.com > wrote: 

Hello, 

I have a rather problematic provider with which I am stuck in Brasil. After wrestling around I am able to make calls, but when FreeSWITCH send's it's BYE, I do receive a 200 OK, but it seems that FreeSWITCH does not recognize what it receives and keeps sending BYE's with Answers from the remote party that the call no longer exists. 

Looking at the Sip trace and the debug log (attached as txt file) everything *seems* fine ... but I am not a FS developer either, so I would appreciate if someone with more experience can have a look at it. 

When connecting with a Eyebeam or X-Lite this problem does not exist, but I could not tell a real difference from the tcp-dumps other than X-Lite uses TCP instead of UPD. 

Trying to use TCP in FreeSWITCH times out after receiving a 100 Giving a try messages after the Invite, so not sure what to make of this either ..., but I would settle for a working BYE and move on ... 

Thank you, 
Best 
Ray 

IRC:Hatrix76, Hatrix, Hatrix|Away 

<blockquote>

<surfix_trace_and_log.txt> 
</blockquote>

<blockquote>

_________________________________________________________________________ 
Professional FreeSWITCH Consulting Services: 
consulting at freeswitch.org 
http://www.freeswitchsolutions.com 

Official FreeSWITCH Sites 
http://www.freeswitch.org 
http://wiki.freeswitch.org 
http://www.cluecon.com 

FreeSWITCH-users mailing list 
FreeSWITCH-users at lists.freeswitch.org 
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users 
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users 
http://www.freeswitch.org 

</blockquote>

_________________________________________________________________________ 
Professional FreeSWITCH Consulting Services: 
consulting at freeswitch.org 
http://www.freeswitchsolutions.com 

Official FreeSWITCH Sites 
http://www.freeswitch.org 
http://wiki.freeswitch.org 
http://www.cluecon.com 

FreeSWITCH-users mailing list 
FreeSWITCH-users at lists.freeswitch.org 
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users 
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users 
http://www.freeswitch.org 

--