This issue is now fixed in svn trunk: http://fisheye.freeswitch.org/changelog/FreeSWITCH/?cs=8062 fix hung channels when using respond app with 1xx or 2xx responses or on re-invite in proxy/bypass media with 1xx and 2xx responses Mike On Apr 8, 2008, at 3:23 PM, kokoska rokoska wrote:
kokoska rokoska napsal(a):
kokoska rokoska napsal(a):
Anthony Minessale napsal(a):
That's all fine but the call leg does exist?
phoneA -- legA ---> FS <--- legB--- phoneB
if phoneB leaves and FS did not get a bye legA will never end so naturally when you hangup phoneA you will get a 200ok on it's leg.
That is why I asked you for the traces because it's most likely the case that legA is still up because legB is as well and only phoneB thinks the call is over.
I sent the dump few minutes before...
BTW: Phone B sends BYE, recieves 200 OK and Freeswitch announce hangup on console. But leaves call leg A alive. If I don't use "transfer" app, everything works ok.
Now I'm try to install IRC client and join conference :-)
Regards,
kokoska.rokoska
My e-mail with dump (400 kB) was rejected. How can I send the dump? Regards, kokoska.rokoska
Here is console dump.
regards,
kokoska.rokoska
2008-04-08 20:19:50 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a 2008-04-08 20:19:50 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/0002*23@192.168.1.128 :5065 [0821700d-67c1-46dc-8d9e-8e2b77f8d9a0] 2008-04-08 20:19:50 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [received] 2008-04-08 20:19:50 [DEBUG] sofia.c:1599 sofia_handle_sip_i_state() Remote SDP: v=0 o=- 3416667593 3416667593 IN IP4 192.168.1.101 s=SJphone c=IN IP4 192.168.1.101 t=0 0 m=audio 49152 RTP/AVP 8 101 c=IN IP4 192.168.1.101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=setup:active
2008-04-08 20:19:50 [DEBUG] sofia_glue.c:2011 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/ [G722:9:8000] 2008-04-08 20:19:50 [DEBUG] sofia_glue.c:2011 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA: 8:8000] 2008-04-08 20:19:50 [DEBUG] sofia_glue.c:1333 sofia_glue_tech_set_codec() Set Codec sofia/default/0002*23@192.168.1.128 :5065 PCMA/8000 20 ms 160 samples 2008-04-08 20:19:50 [DEBUG] sofia_glue.c:1975 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-04-08 20:19:50 [DEBUG] sofia.c:1736 sofia_handle_sip_i_state() sofia/default/0002*23@192.168.1.128 :5065 State Change CS_NEW -> CS_INIT 2008-04-08 20:19:50 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_INIT 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State INIT 2008-04-08 20:19:50 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/default/0002*23@192.168.1.128 :5065 SOFIA INIT 2008-04-08 20:19:50 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/default/0002*23@192.168.1.128 :5065 State Change CS_INIT -> CS_RING 2008-04-08 20:19:50 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State INIT going to sleep 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_RING 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING 2008-04-08 20:19:50 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/0002*23@192.168.1.128 :5065 SOFIA RING 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:50 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing unknown->23@default 2008-04-08 20:19:50 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(23) =~ /^.*$/ 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_RING -> CS_EXECUTE 2008-04-08 20:19:50 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING going to sleep 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_EXECUTE 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE 2008-04-08 20:19:50 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/0002*23@192.168.1.128 :5065 SOFIA EXECUTE 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(forward_counter=1) 2008-04-08 20:19:50 [DEBUG] mod_dptools.c:493 set_function() SET [forward_counter]=[1] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(forward_counter=1) 2008-04-08 20:19:50 [DEBUG] mod_dptools.c:626 export_function() EXPORT [forward_counter]=[1] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute respond(181 Call is being forwarded) 2008-04-08 20:19:50 [DEBUG] mod_sofia.c:990 sofia_receive_message() Responding with 181 Call is being forwarded 2008-04-08 20:19:50 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(sip_h_Diversion=<sip:24@192.168.1.128
;reason=uncoditional;counter=1) 2008-04-08 20:19:50 [DEBUG] mod_dptools.c:626 export_function() EXPORT [sip_h_Diversion]=[<sip: 24@192.168.1.128>;reason=uncoditional;counter=1] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute transfer(24) 2008-04-08 20:19:50 [DEBUG] switch_ivr.c:1007 switch_ivr_session_transfer() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_EXECUTE -> CS_RING 2008-04-08 20:19:50 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:50 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:50 [NOTICE] switch_ivr.c:1013 switch_ivr_session_transfer() Transfer sofia/default/0002*23@192.168.1.128 :5065 to XML[24@default] 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE going to sleep 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_RING 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING 2008-04-08 20:19:50 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/0002*23@192.168.1.128 :5065 SOFIA RING 2008-04-08 20:19:50 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:50 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing unknown->24@default 2008-04-08 20:19:50 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [181][Call is being forwarded] session: sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:51 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(24) =~ /^.*$/ 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_RING -> CS_EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING going to sleep 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/0002*23@192.168.1.128 :5065 SOFIA EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(forward_counter=2) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [forward_counter]=[2] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(forward_counter=2) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:626 export_function() EXPORT [forward_counter]=[2] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute respond(181 Call is being forwarded) 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:990 sofia_receive_message() Responding with 181 Call is being forwarded 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(sip_h_Diversion=<sip:22@192.168.1.128 ;reason=uncoditional;counter=2) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:626 export_function() EXPORT [sip_h_Diversion]=[<sip: 22@192.168.1.128>;reason=uncoditional;counter=2] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute transfer(22) 2008-04-08 20:19:51 [DEBUG] switch_ivr.c:1007 switch_ivr_session_transfer() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_EXECUTE -> CS_RING 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [NOTICE] switch_ivr.c:1013 switch_ivr_session_transfer() Transfer sofia/default/0002*23@192.168.1.128 :5065 to XML[22@default] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE going to sleep 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_RING 2008-04-08 20:19:51 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [early] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/0002*23@192.168.1.128 :5065 SOFIA RING 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:51 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing unknown->22@default 2008-04-08 20:19:51 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [181][Call is being forwarded] session: sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:51 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(22) =~ /^.*$/ 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_RING -> CS_EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING going to sleep 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/0002*23@192.168.1.128 :5065 SOFIA EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(forward_counter=3) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [forward_counter]=[3] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(forward_counter=3) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:626 export_function() EXPORT [forward_counter]=[3] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute respond(181 Call is being forwarded) 2008-04-08 20:19:51 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [early] 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:990 sofia_receive_message() Responding with 181 Call is being forwarded 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(sip_h_Diversion=<sip:21@192.168.1.128 ;reason=uncoditional;counter=3) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:626 export_function() EXPORT [sip_h_Diversion]=[<sip: 21@192.168.1.128>;reason=uncoditional;counter=3] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute transfer(21) 2008-04-08 20:19:51 [DEBUG] switch_ivr.c:1007 switch_ivr_session_transfer() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_EXECUTE -> CS_RING 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [NOTICE] switch_ivr.c:1013 switch_ivr_session_transfer() Transfer sofia/default/0002*23@192.168.1.128 :5065 to XML[21@default] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE going to sleep 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_RING 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/0002*23@192.168.1.128 :5065 SOFIA RING 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:51 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing unknown->21@default 2008-04-08 20:19:51 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [181][Call is being forwarded] session: sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:51 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(21) =~ /^.*$/ 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/ 0002*23@192.168.1.128:5065 State Change CS_RING -> CS_EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State RING going to sleep 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/0002*23@192.168.1.128 :5065 SOFIA EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(dialed_ext=21) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [dialed_ext]=[21] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(dialed_ext=21) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:626 export_function() EXPORT [dialed_ext]=[21] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute export(dst_user=0002*21) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:626 export_function() EXPORT [dst_user]=[0002*21] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(call_timeout=10) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [call_timeout]=[10] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(sip_exclude_contact=$ {network_addr}) 2008-04-08 20:19:51 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [early] 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/0002*23@192.168.1.128 :5065 Expanded String set(sip_exclude_contact=192.168.1.101) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [sip_exclude_contact]=[192.168.1.101] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(hangup_after_bridge=true) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [hangup_after_bridge]=[true] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute set(continue_on_fail=true) 2008-04-08 20:19:51 [DEBUG] mod_dptools.c:493 set_function() SET [continue_on_fail]=[true] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/ 0002*23@192.168.1.128:5065 Execute bridge(sofia/default/${dst_user} %192.168.1.128) 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/0002*23@192.168.1.128 :5065 Expanded String bridge(sofia/default/0002*21%192.168.1.128) 2008-04-08 20:19:51 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/0002*21 [0ded99a5-5044-48d2-96ab-66f43af1a03c] 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:1829 sofia_outgoing_channel() sofia/default/0002*21 State Change CS_NEW - CS_INIT 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*21 Running State Change CS_INIT 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/0002*21) State INIT 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/ default/0002*21 SOFIA INIT 2008-04-08 20:19:51 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/default/0002*21 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/ default/0002*21 State Change CS_INIT -> CS_RING 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/0002*21) State INIT going to sleep 2008-04-08 20:19:51 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*21 entering state [calling] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*21 Running State Change CS_RING 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*21) State RING 2008-04-08 20:19:51 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/ default/0002*21 SOFIA RING 2008-04-08 20:19:51 [DEBUG] switch_ivr_originate.c:55 originate_on_ring() sofia/default/0002*21 State Change CS_RING -> CS_HOLD 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/0002*21) State RING going to sleep 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*21 Running State Change CS_HOLD 2008-04-08 20:19:51 [DEBUG] switch_core_state_machine.c:440 switch_core_session_run() (sofia/default/0002*21) State HOLD 2008-04-08 20:19:51 [DEBUG] switch_ivr_originate.c:951 switch_ivr_originate() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-04-08 20:19:51 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_r_invite] status [180][Ringing] session: sofia/default/0002*21 2008-04-08 20:19:51 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/default/0002*21 2008-04-08 20:19:51 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*21 entering state [proceeding] 2008-04-08 20:19:51 [NOTICE] sofia.c:1633 sofia_handle_sip_i_state() Ring-Ready sofia/default/0002*21! 2008-04-08 20:19:51 [NOTICE] mod_sofia.c:1017 sofia_receive_message() Ring-Ready sofia/default/ 0002*23@192.168.1.128:5065! 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [NOTICE] switch_ivr_originate.c:1026 switch_ivr_originate() Ring Ready sofia/default/ 0002*23@192.168.1.128:5065! 2008-04-08 20:19:51 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:51 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/default/0002*23@192.168.1.128 :5065 2008-04-08 20:19:51 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [early] 2008-04-08 20:19:53 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*21 entering state [ready] 2008-04-08 20:19:53 [DEBUG] sofia.c:1599 sofia_handle_sip_i_state() Remote SDP: v=0 o=- 18939677 18939677 IN IP4 192.168.1.151 s=- c=IN IP4 192.168.1.151 t=0 0 m=audio 16424 RTP/AVP 8 100 101 a=rtpmap:8 PCMA/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20
2008-04-08 20:19:53 [DEBUG] sofia_glue.c:2011 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA: 8:8000] 2008-04-08 20:19:53 [DEBUG] sofia_glue.c:1333 sofia_glue_tech_set_codec() Set Codec sofia/default/0002*21 PCMA/ 8000 20 ms 160 samples 2008-04-08 20:19:53 [DEBUG] sofia_glue.c:1975 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-04-08 20:19:53 [DEBUG] sofia_glue.c:1523 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/0002*21] 192.168.1.128:26702->192.168.1.151:16424 codec: 8 ms: 20 2008-04-08 20:19:53 [DEBUG] switch_rtp.c:716 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-04-08 20:19:53 [DEBUG] switch_channel.c:1506 switch_channel_perform_mark_answered() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:53 [NOTICE] sofia.c:1945 sofia_handle_sip_i_state() Channel [sofia/default/0002*21] has been answered 2008-04-08 20:19:53 [DEBUG] sofia_glue.c:1523 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/0002*23@192.168.1.128 :5065] 192.168.1.128:22042->192.168.1.101:49152 codec: 8 ms: 20 2008-04-08 20:19:53 [DEBUG] switch_rtp.c:716 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-04-08 20:19:53 [DEBUG] mod_sofia.c:376 sofia_answer_channel() Local SDP sofia/default/0002*23@192.168.1.128:5065: v=0 o=FreeSWITCH 1207656751 1207656752 IN IP4 192.168.1.128 s=FreeSWITCH c=IN IP4 192.168.1.128 t=0 0 a=sendrecv m=audio 22042 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20
2008-04-08 20:19:53 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:53 [NOTICE] switch_ivr_originate.c:1171 switch_ivr_originate() Channel [sofia/default/ 0002*23@192.168.1.128:5065] has been answered 2008-04-08 20:19:53 [DEBUG] switch_ivr_originate.c:1205 switch_ivr_originate() Originate Resulted in Success: [sofia/default/ 0002*21] 2008-04-08 20:19:53 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:19:53 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:19:53 [DEBUG] switch_ivr_bridge.c:756 switch_ivr_multi_threaded_bridge() sofia/default/0002*21 State Change CS_HOLD -> CS_LOOPBACK 2008-04-08 20:19:53 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:19:53 [DEBUG] switch_core_state_machine.c:440 switch_core_session_run() (sofia/default/0002*21) State HOLD going to sleep 2008-04-08 20:19:53 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*21 Running State Change CS_LOOPBACK 2008-04-08 20:19:53 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/0002*21) State LOOPBACK 2008-04-08 20:19:53 [DEBUG] mod_sofia.c:314 sofia_on_loopback() SOFIA LOOPBACK 2008-04-08 20:19:53 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [completed] 2008-04-08 20:19:53 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*23@192.168.1.128:5065 entering state [ready] 2008-04-08 20:20:08 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/0002*21 entering state [terminated] 2008-04-08 20:20:08 [NOTICE] sofia.c:1992 sofia_handle_sip_i_state() Hangup sofia/default/0002*21 [CS_LOOPBACK] [NORMAL_CLEARING] 2008-04-08 20:20:08 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/0002*21 [KILL] 2008-04-08 20:20:08 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:20:08 [DEBUG] switch_ivr_bridge.c:275 audio_bridge_thread() read: sofia/default/0002*21 Bad Frame.... Bubye! 2008-04-08 20:20:08 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/0002*23@192.168.1.128:5065 [BREAK] 2008-04-08 20:20:08 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/0002*21] 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/0002*21) State LOOPBACK going to sleep 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*21 Running State Change CS_HANGUP 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/default/0002*21) State HANGUP 2008-04-08 20:20:08 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/0002*21 hanging up, cause: NORMAL_CLEARING 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/ 0002*21, cause: NORMAL_CLEARING 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/default/0002*21) State HANGUP going to sleep 2008-04-08 20:20:08 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 2 (sofia/default/0002*21) Locked, Waiting on external entities 2008-04-08 20:20:08 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:20:08 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/0002*21 [BREAK] 2008-04-08 20:20:08 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/0002*23@192.168.1.128 :5065] 2008-04-08 20:20:08 [NOTICE] switch_ivr_bridge.c:802 switch_ivr_multi_threaded_bridge() Hangup sofia/default/0002*23@192.168.1.128 :5065 [CS_EXECUTE] [NORMAL_CLEARING] 2008-04-08 20:20:08 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/0002*23@192.168.1.128 :5065 [KILL] 2008-04-08 20:20:08 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/0002*23@192.168.1.128 :5065 [BREAK] 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State EXECUTE going to sleep 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/0002*23@192.168.1.128:5065 Running State Change CS_HANGUP 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State HANGUP 2008-04-08 20:20:08 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/0002*23@192.168.1.128:5065 hanging up, cause: NORMAL_CLEARING 2008-04-08 20:20:08 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 2 (sofia/default/0002*21) Ended 2008-04-08 20:20:08 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/0002*21 [CS_HANGUP] 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/0002*23@192.168.1.128 :5065, cause: NORMAL_CLEARING 2008-04-08 20:20:08 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/default/0002*23@192.168.1.128:5065) State HANGUP going to sleep 2008-04-08 20:20:08 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 1 (sofia/default/0002*23@192.168.1.128 :5065) Locked, Waiting on external entities 2008-04-08 20:20:08 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 1 (sofia/default/0002*23@192.168.1.128 :5065) Ended 2008-04-08 20:20:08 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/0002*23@192.168.1.128 :5065 [CS_HANGUP] _______________________________________________ Freeswitch-dev mailing list Freeswitch-dev@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev http://www.freeswitch.org