Is there a way I can reset the forwardvars for a channel or execute some action that would reset this value? I'm pretty certain there is no endless looping going on in my dial plan. Thanks. --matt On Fri, Oct 23, 2009 at 10:19 AM, Matthew Fong <mattdfong@gmail.com> wrote:
Hi Anthm, Thanks for the response. I'll use pastebin from now on.
How would I go about fixing this so my calls do not get hung-up?
--matt
On Fri, Oct 23, 2009 at 2:26 AM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
1) please do not flood emails with traces reference pastebins 2) the error is a routing loop being prevented so you are looping the call into your same box too many times.
You could have figured this out your self by looking at one of the lines of code where it reported the hangup.
if (!switch_strlen_zero(forwardvar)) { forwardval = atoi(forwardvar) - 1; } if (forwardval <= 0) { switch_channel_hangup(channel, SWITCH_CAUSE_EXCHANGE_ROUTING_ERROR); return SWITCH_STATUS_FALSE;
}
On Thu, Oct 22, 2009 at 12:42 PM, Matthew Fong <mattdfong@gmail.com>wrote:
I figured out how to turn debug mode on. For some reason F8 didn't work, so I just set the default debug mode to DEBUG in switch.conf.xml
http://pastebin.freeswitch.org/10805 <http://pastebin.freeswitch.org/10805>So my program does more or less the same sequence for an Agent every time when connected to another party. They uuid_kill the bridged parties uuid, and then are transfered to an extension that park's the agent (using the transfer_after_bridge variable -- in my dialplan extn 1998). In some instances the agent is then transfered to another extension, played a wav file, and then park'ed again
Sometimes, FreeSWITCH unexpectidly hangsup the Agent channel citing an EXCHANGE_ROUTING_ERROR. It seems (to me to happen at random times)...and it's more prevelent with some did providers than others. With didforsale.org it happens about one ever 5 bridges. With icall.com it only happens about once every 30 bridges. With IPKall it happens rarely. I can't figure it out, and it's driving me crazy :)
A GOOD UUID_KILL SEQUENCE: 2009-10-22 17:22:31.741845 [DEBUG] switch_ivr_play_say.c:1432 done playing file 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:340 (sofia/external/+14158867717@199.173.100.16:5060) State EXECUTE going to sleep 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_HIBERNATE 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:355 (sofia/external/+14158867717@199.173.100.16:5060) State HIBERNATE 2009-10-22 17:22:31.741845 [DEBUG] mod_sofia.c:160 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA HIBERNATE 2009-10-22 17:22:31.741845 [DEBUG] switch_ivr_bridge.c:650 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_HIBERNATE -> CS_RESET 2009-10-22 17:22:31.741845 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:355 (sofia/external/+14158867717@199.173.100.16:5060) State HIBERNATE going to sleep 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_RESET 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:336 (sofia/external/+14158867717@199.173.100.16:5060) State RESET 2009-10-22 17:22:31.741845 [DEBUG] mod_sofia.c:145 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA RESET 2009-10-22 17:22:31.741845 [DEBUG] switch_ivr_bridge.c:637 sofia/external/+14158867717@199.173.100.16:5060 CUSTOM RESET 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:67 sofia/external/+14158867717@199.173.100.16:5060 Standard RESET 2009-10-22 17:22:31.741845 [DEBUG] switch_core_state_machine.c:336 (sofia/external/+14158867717@199.173.100.16:5060) State RESET going to sleep 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:340 (sofia/external/14159927717) State EXECUTE going to sleep 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_HIBERNATE 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:355 (sofia/external/14159927717) State HIBERNATE 2009-10-22 17:22:31.748086 [DEBUG] mod_sofia.c:160 sofia/external/14159927717 SOFIA HIBERNATE 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:650 (sofia/external/14159927717) State Change CS_HIBERNATE -> CS_RESET 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:355 (sofia/external/14159927717) State HIBERNATE going to sleep 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_RESET 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:336 (sofia/external/14159927717) State RESET 2009-10-22 17:22:31.748086 [DEBUG] mod_sofia.c:145 sofia/external/14159927717 SOFIA RESET 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:637 sofia/external/14159927717 CUSTOM RESET 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:642 (sofia/external/14159927717) State Change CS_RESET -> CS_SOFT_EXECUTE 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:336 (sofia/external/14159927717) State RESET going to sleep 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_SOFT_EXECUTE 2009-10-22 17:22:31.748086 [DEBUG] switch_core_state_machine.c:346 (sofia/external/14159927717) State SOFT_EXECUTE 2009-10-22 17:22:31.748086 [DEBUG] mod_sofia.c:442 SOFIA TRANSMIT 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:660 sofia/external/14159927717 CUSTOM SOFT_EXECUTE 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_originate.c:674 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_RESET -> CS_SOFT_EXECUTE 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:120 sofia/external/+14158867717@199.173.100.16:5060 receive message [DISPLAY] 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:120 sofia/external/14159927717 receive message [DISPLAY] 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:924 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:968 sofia/external/+14158867717@199.173.100.16:5060 receive message [BRIDGE] 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:630 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:975 sofia/external/14159927717 receive message [BRIDGE] 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:630 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:22:31.748086 [DEBUG] switch_ivr_bridge.c:1019 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2009-10-22 17:22:31.748086 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:31.749553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_EXCHANGE_MEDIA 2009-10-22 17:22:31.749553 [DEBUG] switch_core_state_machine.c:343 (sofia/external/+14158867717@199.173.100.16:5060) State EXCHANGE_MEDIA 2009-10-22 17:22:31.749553 [DEBUG] mod_sofia.c:436 SOFIA LOOPBACK multipler is being overrided to1 2009-10-22 17:22:34.300662 [INFO] switch_cpp.cpp:1116 BG_AG_GEN_CALLS, Agents total:1 avail:0 OutChan:0 AR:0 +-Calls:0:Q Call NYNoc multipler is being overrided to1 2009-10-22 17:22:39.303041 [INFO] switch_cpp.cpp:1116 BG_AG_GEN_CALLS, Agents total:1 avail:0 OutChan:0 AR:0 +-Calls:0:Q Call NYNoc 2009-10-22 17:22:40.626379 [NOTICE] sofia.c:328 Hangup sofia/external/14159927717 [CS_SOFT_EXECUTE] [NORMAL_CLEARING] 2009-10-22 17:22:40.626379 [DEBUG] switch_channel.c:1810 Send signal sofia/external/14159927717 [KILL] 2009-10-22 17:22:40.626379 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] active_true=1 --contact NOT in playmsg or conference, update AGENT 2009-10-22 17:22:40.626379 [DEBUG] switch_core_state_machine.c:437 thread mismatch skipping state handler. 2009-10-22 17:22:40.626379 [INFO] switch_cpp.cpp:1116 EVENTC_HANGUP_CONTACT, Q_CONTACT fired for agent:1/1 for qcall:1 contact:4801442/4 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:440 sofia/external/14159927717 ending bridge by request from write function 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:495 sofia/external/+14158867717@199.173.100.16:5060 receive message [UNBRIDGE] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:630 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:521 BRIDGE THREAD DONE [sofia/external/+14158867717@199.173.100.16:5060] 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:523 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr.c:1361 (sofia/external/+ 14158867717@199.173.100.16:5060) State Change CS_EXCHANGE_MEDIA -> CS_ROUTING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr.c:1365 sofia/external/+ 14158867717@199.173.100.16:5060 receive message [TRANSFER] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:630 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:40.639760 [NOTICE] switch_ivr.c:1367 Transfer sofia/external/+14158867717@199.173.100.16:5060 to xml[1998@default] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:343 (sofia/external/+14158867717@199.173.100.16:5060) State EXCHANGE_MEDIA going to sleep 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_ROUTING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:333 (sofia/external/+14158867717@199.173.100.16:5060) State ROUTING 2009-10-22 17:22:40.639760 [DEBUG] mod_sofia.c:130 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA ROUTING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:78 sofia/external/+14158867717@199.173.100.16:5060 Standard ROUTING 2009-10-22 17:22:40.639760 [INFO] mod_dialplan_xml.c:391 Processing +14158867717->1998 in context default Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->tod_example] continue=true Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (PASS) [tod_example] ${strftime(%w)}(4) =~ /^([1-5])$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (PASS) [tod_example] ${strftime(%H%M)}(1722) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Action set(open=true) Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->ivr_demo] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [ivr_demo] destination_number(1998) =~ /^5000$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1975] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1975] destination_number(1998) =~ /^1975$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1971] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1971] destination_number(1998) =~ /^1971$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1972] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1972] destination_number(1998) =~ /^1972$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1920] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1920] destination_number(1998) =~ /^1920$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1981] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1981] destination_number(1998) =~ /^1981$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1982] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1982] destination_number(1998) =~ /^1982$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1481] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1481] destination_number(1998) =~ /^1481$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1989] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1989] destination_number(1998) =~ /^1989$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1990] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1990] destination_number(1998) =~ /^1990$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1991] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1991] destination_number(1998) =~ /^1991$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1992] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1992] destination_number(1998) =~ /^1992$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1993] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1993] destination_number(1998) =~ /^1993$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1994] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1994] destination_number(1998) =~ /^1994$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1995] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1995] destination_number(1998) =~ /^1995$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1996] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1996] destination_number(1998) =~ /^1996$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1997] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (FAIL) [1997] destination_number(1998) =~ /^1997$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 parsing [default->1998] continue=false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Regex (PASS) [1998] destination_number(1998) =~ /^1998$/ break=on-false Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Action set(transfer_after_bridge=1998) Dialplan: sofia/external/+14158867717@199.173.100.16:5060 Action park() 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:114 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_ROUTING -> CS_EXECUTE 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:333 (sofia/external/+14158867717@199.173.100.16:5060) State ROUTING going to sleep 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_EXECUTE 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:340 (sofia/external/+14158867717@199.173.100.16:5060) State EXECUTE 2009-10-22 17:22:40.639760 [DEBUG] mod_sofia.c:173 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA EXECUTE 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:151 sofia/external/+14158867717@199.173.100.16:5060 Standard EXECUTE EXECUTE sofia/external/+14158867717@199.173.100.16:5060 set(open=true) 2009-10-22 17:22:40.639760 [DEBUG] mod_dptools.c:752 sofia/external/+ 14158867717@199.173.100.16:5060 SET [open]=[true] EXECUTE sofia/external/+14158867717@199.173.100.16:5060set(transfer_after_bridge=1998) 2009-10-22 17:22:40.639760 [DEBUG] mod_dptools.c:752 sofia/external/+ 14158867717@199.173.100.16:5060 SET [transfer_after_bridge]=[1998] EXECUTE sofia/external/+14158867717@199.173.100.16:5060 park() 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:446 sofia/external/14159927717 ending bridge by request from read function 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:521 BRIDGE THREAD DONE [sofia/external/14159927717] 2009-10-22 17:22:40.639760 [DEBUG] switch_ivr_bridge.c:523 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] subtracting 9 seconds for hh_call: 1095422 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:346 (sofia/external/14159927717) State SOFT_EXECUTE going to sleep 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_HANGUP 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:464 (sofia/external/14159927717) State HANGUP 2009-10-22 17:22:40.639760 [DEBUG] mod_sofia.c:344 Channel sofia/external/14159927717 hanging up, cause: NORMAL_CLEARING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:46 sofia/external/14159927717 Standard HANGUP, cause: NORMAL_CLEARING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:464 (sofia/external/14159927717) State HANGUP going to sleep 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:325 (sofia/external/14159927717) State Change CS_HANGUP -> CS_REPORTING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_REPORTING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:555 (sofia/external/14159927717) State REPORTING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:53 sofia/external/14159927717 Standard REPORTING, cause: NORMAL_CLEARING 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:555 (sofia/external/14159927717) State REPORTING going to sleep 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:319 (sofia/external/14159927717) State Change CS_REPORTING -> CS_DESTROY 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_session.c:1069 Session 6 (sofia/external/14159927717) Locked, Waiting on external entities 2009-10-22 17:22:40.639760 [NOTICE] switch_core_session.c:1087 Session 6 (sofia/external/14159927717) Ended 2009-10-22 17:22:40.639760 [NOTICE] switch_core_session.c:1089 Close Channel sofia/external/14159927717 [CS_DESTROY] 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:401 (sofia/external/14159927717) Running State Change CS_DESTROY 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:412 (sofia/external/14159927717) State DESTROY 2009-10-22 17:22:40.639760 [DEBUG] mod_sofia.c:261 sofia/external/14159927717 SOFIA DESTROY 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:60 sofia/external/14159927717 Standard DESTROY 2009-10-22 17:22:40.639760 [DEBUG] switch_core_state_machine.c:412 (sofia/external/14159927717) State DESTROY going to sleep 2009-10-22 17:22:40.639760 [INFO] switch_cpp.cpp:1116 PCHangup gw: teliax.com hc:NORMAL_CLEARING du:9 cn:sofia/external/14159927717
A BAD UUID_KILL SEQUENCE: (where the agent is hungup, unexpectedly)
--bridged in: 0.005821 seconds 2009-10-22 17:23:26.718930 [INFO] switch_cpp.cpp:1116 AG_CBRIDGE, connected agent:1/1 contact:4801439/22/1/1 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_play_say.c:1432 done playing file 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:340 (sofia/external/+14158867717@199.173.100.16:5060) State EXECUTE going to sleep 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_HIBERNATE 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:355 (sofia/external/+14158867717@199.173.100.16:5060) State HIBERNATE 2009-10-22 17:23:26.721553 [DEBUG] mod_sofia.c:160 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA HIBERNATE 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:650 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_HIBERNATE -> CS_RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:355 (sofia/external/+14158867717@199.173.100.16:5060) State HIBERNATE going to sleep 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:336 (sofia/external/+14158867717@199.173.100.16:5060) State RESET 2009-10-22 17:23:26.721553 [DEBUG] mod_sofia.c:145 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:637 sofia/external/+14158867717@199.173.100.16:5060 CUSTOM RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:67 sofia/external/+14158867717@199.173.100.16:5060 Standard RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:336 (sofia/external/+14158867717@199.173.100.16:5060) State RESET going to sleep 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:340 (sofia/external/14159927717) State EXECUTE going to sleep 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_HIBERNATE 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:355 (sofia/external/14159927717) State HIBERNATE 2009-10-22 17:23:26.721553 [DEBUG] mod_sofia.c:160 sofia/external/14159927717 SOFIA HIBERNATE 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:650 (sofia/external/14159927717) State Change CS_HIBERNATE -> CS_RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:355 (sofia/external/14159927717) State HIBERNATE going to sleep 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:336 (sofia/external/14159927717) State RESET 2009-10-22 17:23:26.721553 [DEBUG] mod_sofia.c:145 sofia/external/14159927717 SOFIA RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:637 sofia/external/14159927717 CUSTOM RESET 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:642 (sofia/external/14159927717) State Change CS_RESET -> CS_SOFT_EXECUTE 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:336 (sofia/external/14159927717) State RESET going to sleep 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_SOFT_EXECUTE 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:346 (sofia/external/14159927717) State SOFT_EXECUTE 2009-10-22 17:23:26.721553 [DEBUG] mod_sofia.c:442 SOFIA TRANSMIT 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:660 sofia/external/14159927717 CUSTOM SOFT_EXECUTE 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_originate.c:674 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_RESET -> CS_SOFT_EXECUTE 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:120 sofia/external/+14158867717@199.173.100.16:5060 receive message [DISPLAY] 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:120 sofia/external/14159927717 receive message [DISPLAY] 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:924 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:968 sofia/external/+14158867717@199.173.100.16:5060 receive message [BRIDGE] 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:630 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:975 sofia/external/14159927717 receive message [BRIDGE] 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:630 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_ivr_bridge.c:1019 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2009-10-22 17:23:26.721553 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_EXCHANGE_MEDIA 2009-10-22 17:23:26.721553 [DEBUG] switch_core_state_machine.c:343 (sofia/external/+14158867717@199.173.100.16:5060) State EXCHANGE_MEDIA 2009-10-22 17:23:26.721553 [DEBUG] mod_sofia.c:436 SOFIA LOOPBACK 2009-10-22 17:23:26.740065 [DEBUG] switch_core_io.c:234 sofia/external/+ 14158867717@199.173.100.16:5060 receive message [TRANSCODING_NECESSARY] 2009-10-22 17:23:27.319618 [DEBUG] switch_core_media_bug.c:393 Removing BUG from sofia/external/+14158867717@199.173.100.16:5060 multipler is being overrided to1 2009-10-22 17:23:29.406414 [INFO] switch_cpp.cpp:1116 BG_AG_GEN_CALLS, Agents total:1 avail:0 OutChan:0 AR:0 +-Calls:0:Q Call NYNoc 2009-10-22 17:23:31.873352 [NOTICE] mod_commands.c:1523 Hangup sofia/external/14159927717 [CS_SOFT_EXECUTE] [NORMAL_CLEARING] 2009-10-22 17:23:31.874411 [INFO] switch_cpp.cpp:1116 EVENTC_HANGUP_CONTACT, Q_CONTACT fired for agent:1/1 for qcall:1 contact:4801439/1 active_true=1 --contact NOT in playmsg or conference, update AGENT 2009-10-22 17:23:31.875475 [DEBUG] switch_channel.c:1810 Send signal sofia/external/14159927717 [KILL] 2009-10-22 17:23:31.875475 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:23:31.875475 [DEBUG] switch_core_state_machine.c:437 thread mismatch skipping state handler. 2009-10-22 17:23:31.882153 [DEBUG] switch_ivr_bridge.c:446 sofia/external/14159927717 ending bridge by request from read function 2009-10-22 17:23:31.882153 [DEBUG] switch_ivr_bridge.c:521 BRIDGE THREAD DONE [sofia/external/14159927717] 2009-10-22 17:23:31.882153 [DEBUG] switch_ivr_bridge.c:523 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:31.882153 [DEBUG] switch_ivr_bridge.c:495 sofia/external/+14158867717@199.173.100.16:5060 receive message [UNBRIDGE] 2009-10-22 17:23:31.882153 [DEBUG] switch_core_session.c:630 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:31.882153 [DEBUG] switch_ivr_bridge.c:521 BRIDGE THREAD DONE [sofia/external/+14158867717@199.173.100.16:5060] 2009-10-22 17:23:31.882153 [DEBUG] switch_ivr_bridge.c:523 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:23:31.882153 [NOTICE] switch_ivr.c:1268 Hangup sofia/external/+14158867717@199.173.100.16:5060 [CS_EXCHANGE_MEDIA] [EXCHANGE_ROUTING_ERROR] 2009-10-22 17:23:31.882153 [DEBUG] switch_channel.c:1810 Send signal sofia/external/+14158867717@199.173.100.16:5060 [KILL] 2009-10-22 17:23:31.882153 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:31.882153 [DEBUG] switch_core_state_machine.c:464 (sofia/external/+14158867717@199.173.100.16:5060) State HANGUP 2009-10-22 17:23:31.882153 [DEBUG] mod_sofia.c:344 Channel sofia/external/+14158867717@199.173.100.16:5060 hanging up, cause: EXCHANGE_ROUTING_ERROR 2009-10-22 17:23:31.882153 [DEBUG] mod_sofia.c:382 Sending BYE to sofia/external/+14158867717@199.173.100.16:5060 2009-10-22 17:23:31.882153 [DEBUG] switch_core_state_machine.c:46 sofia/external/+14158867717@199.173.100.16:5060 Standard HANGUP, cause: EXCHANGE_ROUTING_ERROR 2009-10-22 17:23:31.882153 [DEBUG] switch_core_state_machine.c:464 (sofia/external/+14158867717@199.173.100.16:5060) State HANGUP going to sleep 2009-10-22 17:23:31.884357 [INFO] switch_cpp.cpp:1116 HH_HANGUP, agent:1/1 uuid: f8604694-4e44-4c4c-9805-722b3e9d6b68 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:346 (sofia/external/14159927717) State SOFT_EXECUTE going to sleep 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_HANGUP 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:464 (sofia/external/14159927717) State HANGUP 2009-10-22 17:23:31.885412 [DEBUG] mod_sofia.c:344 Channel sofia/external/14159927717 hanging up, cause: NORMAL_CLEARING 2009-10-22 17:23:31.885412 [DEBUG] mod_sofia.c:382 Sending BYE to sofia/external/14159927717 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:46 sofia/external/14159927717 Standard HANGUP, cause: NORMAL_CLEARING 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:464 (sofia/external/14159927717) State HANGUP going to sleep 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:325 (sofia/external/14159927717) State Change CS_HANGUP -> CS_REPORTING 2009-10-22 17:23:31.885412 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] subtracting 5 seconds for hh_call: 1095423 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:306 (sofia/external/14159927717) Running State Change CS_REPORTING 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:555 (sofia/external/14159927717) State REPORTING 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:53 sofia/external/14159927717 Standard REPORTING, cause: NORMAL_CLEARING 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:555 (sofia/external/14159927717) State REPORTING going to sleep 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:319 (sofia/external/14159927717) State Change CS_REPORTING -> CS_DESTROY 2009-10-22 17:23:31.885412 [DEBUG] switch_core_session.c:932 Send signal sofia/external/14159927717 [BREAK] 2009-10-22 17:23:31.885412 [DEBUG] switch_core_session.c:1069 Session 7 (sofia/external/14159927717) Locked, Waiting on external entities 2009-10-22 17:23:31.885412 [NOTICE] switch_core_session.c:1087 Session 7 (sofia/external/14159927717) Ended 2009-10-22 17:23:31.885412 [NOTICE] switch_core_session.c:1089 Close Channel sofia/external/14159927717 [CS_DESTROY] 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:401 (sofia/external/14159927717) Running State Change CS_DESTROY 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:412 (sofia/external/14159927717) State DESTROY 2009-10-22 17:23:31.885412 [DEBUG] mod_sofia.c:261 sofia/external/14159927717 SOFIA DESTROY 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:60 sofia/external/14159927717 Standard DESTROY 2009-10-22 17:23:31.885412 [DEBUG] switch_core_state_machine.c:412 (sofia/external/14159927717) State DESTROY going to sleep 2009-10-22 17:23:31.885412 [INFO] switch_cpp.cpp:1116 PCHangup gw: teliax.com hc:NORMAL_CLEARING du:5 cn:sofia/external/14159927717 2009-10-22 17:23:31.885412 [INFO] switch_cpp.cpp:1116 EVENTC_BILLING_CEIL, subtracting 5 for hh_call:1095423 2009-10-22 17:23:31.901620 [DEBUG] switch_core_state_machine.c:494 Hangup Command luarun(hh_hangup.lua f8604694-4e44-4c4c-9805-722b3e9d6b68 1 1): +OK
2009-10-22 17:23:31.902676 [DEBUG] switch_core_state_machine.c:343 (sofia/external/+14158867717@199.173.100.16:5060) State EXCHANGE_MEDIA going to sleep 2009-10-22 17:23:31.902676 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_HANGUP 2009-10-22 17:23:31.902676 [DEBUG] switch_core_state_machine.c:442 handler already called, skipping state handler. 2009-10-22 17:23:31.902676 [DEBUG] switch_core_state_machine.c:325 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_HANGUP -> CS_REPORTING 2009-10-22 17:23:31.902676 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:31.902676 [DEBUG] switch_core_state_machine.c:306 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_REPORTING 2009-10-22 17:23:31.903742 [DEBUG] switch_core_state_machine.c:555 (sofia/external/+14158867717@199.173.100.16:5060) State REPORTING 2009-10-22 17:23:31.903742 [DEBUG] switch_core_state_machine.c:53 sofia/external/+14158867717@199.173.100.16:5060 Standard REPORTING, cause: EXCHANGE_ROUTING_ERROR 2009-10-22 17:23:31.903742 [DEBUG] switch_core_state_machine.c:555 (sofia/external/+14158867717@199.173.100.16:5060) State REPORTING going to sleep 2009-10-22 17:23:31.903742 [DEBUG] switch_core_state_machine.c:319 (sofia/external/+14158867717@199.173.100.16:5060) State Change CS_REPORTING -> CS_DESTROY 2009-10-22 17:23:31.903742 [DEBUG] switch_core_session.c:932 Send signal sofia/external/+14158867717@199.173.100.16:5060 [BREAK] 2009-10-22 17:23:31.903742 [DEBUG] switch_core_session.c:1069 Session 4 (sofia/external/+14158867717@199.173.100.16:5060) Locked, Waiting on external entities 2009-10-22 17:23:31.903742 [NOTICE] switch_core_session.c:1087 Session 4 (sofia/external/+14158867717@199.173.100.16:5060) Ended 2009-10-22 17:23:31.903742 [NOTICE] switch_core_session.c:1089 Close Channel sofia/external/+14158867717@199.173.100.16:5060 [CS_DESTROY] 2009-10-22 17:23:31.903742 [DEBUG] switch_core_state_machine.c:401 (sofia/external/+14158867717@199.173.100.16:5060) Running State Change CS_DESTROY 2009-10-22 17:23:31.904799 [DEBUG] switch_core_state_machine.c:412 (sofia/external/+14158867717@199.173.100.16:5060) State DESTROY 2009-10-22 17:23:31.904799 [DEBUG] mod_sofia.c:261 sofia/external/+ 14158867717@199.173.100.16:5060 SOFIA DESTROY 2009-10-22 17:23:31.904799 [DEBUG] switch_core_state_machine.c:60 sofia/external/+14158867717@199.173.100.16:5060 Standard DESTROY 2009-10-22 17:23:31.904799 [DEBUG] switch_core_state_machine.c:412 (sofia/external/+14158867717@199.173.100.16:5060) State DESTROY going to sleep
On Tue, Oct 20, 2009 at 1:44 AM, Michael Collins <msc@freeswitch.org>wrote:
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com>wrote:
The debug level logs to the console, right? The pastebin, had log level debug, sofia trace on for external and default, and sofia loglevel all 9. Is there another log enable command I'm missing? It seems loglevel all 9 outputs enter and exit functions, but at least to my novice eye, it's not too obvious why freeswitch is sending a BYE to my DID provider.
Evidently the console loglevel debug did not take because there isn't a single DEBUG level line of output. Please try again. Just remember that debug level log messages will have A LOT of information so be patient while sifting through it. Of course, feel free to pastebin the output and add a link to it in this email thread.
-MC
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire
AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> iax:guest@conference.freeswitch.org/888 googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:213-799-1400
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org