VoIP Mailing List Archives
Mailing list archives for the VoIP community |
|
| View previous topic :: View next topic |
| Author |
Message |
mattdfong at gmail.com
Guest
|
 Posted: Sun Oct 18, 2009 9:35 am Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
 |
|
I'm still having this issue with random EXCHANGE_ROUTING_ERROR disconnects for users utilizing my inbound DID to connect to my FreeSWITCH server. It's a predictive dialing application, with one agent session being bridged with multiple calls and transfered back and forth between extensions in my dial plan. After a random number of bridging and transferring, FreeSWITCH suddenly sends a BYE to my DID provider citing an EXCHANGE_ROUTING_ERROR. It does not happen at any one-point in my dial plan, or applications--it just randomly disconnects when a call that the Agent is bridged to hangs-up or is disconnected. It seems to only happen when two external sip profiles are being bridged together, and not when an internal and external profile is being bridged.
I turned
sip trace on and
sofia loglevel all 9
below is the the snippet. I've posted the entire Agent session at the following pastebin http://pastebin.freeswitch.org/10756
tport_deliver(0x18413c0): msg 0x7faeb818ea30 (304 bytes) from udp/208.76.18.254:5080/sip next=(nil)
nta: received 200 OK for BYE (121818983)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 84.409 ms
tport_release(0x18413c0): 0x1a15cc0 by 0x1a16a00 with 0x7faeb818ea30
nua(0x1ad6fb0): event r_bye 200 OK
nua(0x1ad6fb0): call state changed: terminating -> terminated
nua(0x1ad6fb0): event i_state 200 to BYE
nua: nua_application_event: entering
nua(0x1ad6fb0): event i_terminated 200 to BYE
nua: nua_handle_magic: entering
nua(0x1ad6fb0): removing session usage
soa_destroy(static::0x1b5ae90) called
nua: nua_application_event: entering
nta_leg_destroy(0x1b594a0)
nua: nua_handle_magic: entering
nua: nua_handle_bind: entering
nua: nua_application_event: entering
nua: nua_handle_magic: entering
nua: terminated session 0x1ad6fb0
nua: nua_handle_destroy: entering
nua(0x1ad6fb0): recv signal r_destroy
nta_leg_destroy((nil))
nua(0x1ad6fb0): sent signal r_destroy
nta: timer set next to 28 ms
nta: timer E fired, retransmit BYE (121818989)
tport_release(0x18413c0): 0x1b5c9b0 by 0x7faeb817d830 with (nil)
tport_tsend(0x18413c0) tpn = */209.216.2.211:5060
tport_resolve addrinfo = 209.216.2.211:5060
tport_by_addrinfo(0x18413c0): not found by name */209.216.2.211:5060
tport_vsend(0x18413c0): 862 bytes of 862 to udp/209.216.2.211:5060
tport_vsend returned 862
send 862 bytes to udp/[209.216.2.211]:5060 at 14:04:11.753690:
------------------------------------------------------------------------
BYE sip:199.173.100.16:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 67.220.216.146:5080;rport;branch=z9hG4bK02jNX8a4HrNyN
Route: <sip:209.216.2.211;ftag=4adc7-13c4-1ab03-71ce3705-1ab03;lr=on>
Route: <sip:65.211.120.237:5060;lr>
Route: <sip:63.110.102.239;lr>
Max-Forwards: 70
From: <sip:+12133304391@63.110.102.239:5060;user=phone>;tag=cgBe054jZrt3a
To: <sip:+14158867717@199.173.100.16:5060;user=phone>;tag=4adc7-13c4-1ab03-71ce3705-1ab03
Call-ID: a0f656a01064adc713c41ab036840746ee20ca11c06b2d8-0440-5124
CSeq: 121818989 BYE
Contact: <sip:+12133304391@67.220.216.146:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15135
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, UPDATE, NOTIFY
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
------------------------------------------------------------------------
Thanks.
--matt
On Sat, Aug 8, 2009 at 12:42 PM, Michael Jerris <mike@jerris.com (mike@jerris.com)> wrote:
| Quote: | http://wiki.freeswitch.org/wiki/Sofia#Debugging_Sofia-SIP
turn the logging all the way up and see what it says.
Mike
On Aug 4, 2009, at 2:51 PM, Matthew Fong wrote:
| Quote: | Hi Mathieu, thanks for the reply. I enabled sip trace logging and got the logs below, but I am still at a loss at being able to identify the error or reproduce it consistently. The below log indicates to me that my FS server is initiating sending 2 BYE message to my DID provider (didforsale.com). Is there a way I can look further inside FreeSWITCH to see why it is sending this BYE packet?
sent 882 bytes to udp/[209.216.2.211]:5060 at 17:15:44.679208:
BYE sip:199.173.100.144:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 66.197.142.69:5080;rport;branch=z9hG4bKD0UKrDB508mDD
Route: <sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on>
Route: <sip:65.217.40.210:5060;lr>
Route: <sip:63.110.102.238;lr>
Max-Forwards: 70
From: <sip:+1212381XXXX@63.110.102.238:5060;user=phone>;tag=Ztr5ycrv3QZ1g
To: <sip:+1909635XXXX@199.173.100.144:5060;user=phone>;tag=dc7-13c4-2401b7-46dea593-2401b7
Call-ID: a22bffb89064adc713c42401b78ca6b689e90b32fdbf612c0-0487-7441
CSeq: 118584736 BYE
Contact: <sip:+1212381XXXX@66.197.142.69:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14417M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
sent 882 bytes to udp/[209.216.2.211]:5060 at 17:15:45.182589:
BYE sip:199.173.100.144:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 66.197.142.69:5080;rport;branch=z9hG4bKD0UKrDB508mDD
Route: <sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on>
Route: <sip:65.217.40.210:5060;lr>
Route: <sip:63.110.102.238;lr>
Max-Forwards: 70
From: <sip:+1212381XXXX@63.110.102.238:5060;user=phone>;tag=Ztr5ycrv3QZ1g
To: <sip:+1909635XXXX@199.173.100.144:5060;user=phone>;tag=dc7-13c4-2401b7-46dea593-2401b7
Call-ID: a22bffb89064adc713c42401b78ca6b689e90b32fdbf612c0-0487-7441
CSeq: 118584736 BYE
Contact: <sip:+1212381XXXX@66.197.142.69:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14417M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
On Sun, Aug 2, 2009 at 11:20 PM, Mathieu Rene <mrene_lists@avgs.ca (mrene_lists@avgs.ca)> wrote:
| Quote: | Hi,
Digging a bit in mod_sofia releaved that it can be caused by a SIP
code 482 (loop detected), 483 (too many hops) or 484 (address
incomplete).
Do a SIP trace to sched more light on what's happening.
Mathieu Rene
Avant-Garde Solutions Inc
Office: + 1 (514) 664-1044 x100
Cell: +1 (514) 664-1044 x200
mrene@avgs.ca (mrene@avgs.ca)
|
|
_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org (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
|
|
|
| Back to top |
|
 |
mike at jerris.com
Guest
|
| Posted: Sun Oct 18, 2009 9:04 pm Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
FreeSWITCH debug level logs should help tell you exactly what is killing the call.
On Oct 18, 2009, at 10:25 AM, Matthew Fong wrote:
| Quote: | I'm still having this issue with random EXCHANGE_ROUTING_ERROR disconnects for users utilizing my inbound DID to connect to my FreeSWITCH server. It's a predictive dialing application, with one agent session being bridged with multiple calls and transfered back and forth between extensions in my dial plan. After a random number of bridging and transferring, FreeSWITCH suddenly sends a BYE to my DID provider citing an EXCHANGE_ROUTING_ERROR. It does not happen at any one-point in my dial plan, or applications--it just randomly disconnects when a call that the Agent is bridged to hangs-up or is disconnected. It seems to only happen when two external sip profiles are being bridged together, and not when an internal and external profile is being bridged.
I turned
sip trace on and
sofia loglevel all 9
below is the the snippet. I've posted the entire Agent session at the following pastebin http://pastebin.freeswitch.org/10756
tport_deliver(0x18413c0): msg 0x7faeb818ea30 (304 bytes) from udp/208.76.18.254:5080/sip next=(nil)
nta: received 200 OK for BYE (121818983)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 84.409 ms
tport_release(0x18413c0): 0x1a15cc0 by 0x1a16a00 with 0x7faeb818ea30
nua(0x1ad6fb0): event r_bye 200 OK
nua(0x1ad6fb0): call state changed: terminating -> terminated
nua(0x1ad6fb0): event i_state 200 to BYE
nua: nua_application_event: entering
nua(0x1ad6fb0): event i_terminated 200 to BYE
nua: nua_handle_magic: entering
nua(0x1ad6fb0): removing session usage
soa_destroy(static::0x1b5ae90) called
nua: nua_application_event: entering
nta_leg_destroy(0x1b594a0)
nua: nua_handle_magic: entering
nua: nua_handle_bind: entering
nua: nua_application_event: entering
nua: nua_handle_magic: entering
nua: terminated session 0x1ad6fb0
nua: nua_handle_destroy: entering
nua(0x1ad6fb0): recv signal r_destroy
nta_leg_destroy((nil))
nua(0x1ad6fb0): sent signal r_destroy
nta: timer set next to 28 ms
nta: timer E fired, retransmit BYE (121818989)
tport_release(0x18413c0): 0x1b5c9b0 by 0x7faeb817d830 with (nil)
tport_tsend(0x18413c0) tpn = */209.216.2.211:5060
tport_resolve addrinfo = 209.216.2.211:5060
tport_by_addrinfo(0x18413c0): not found by name */209.216.2.211:5060
tport_vsend(0x18413c0): 862 bytes of 862 to udp/209.216.2.211:5060
tport_vsend returned 862
send 862 bytes to udp/[209.216.2.211]:5060 at 14:04:11.753690:
------------------------------------------------------------------------
BYE [url=sip:199.173.100.16:5060;transport=UDP]sip:199.173.100.16:5060;transport=UDP[/url] SIP/2.0
Via: SIP/2.0/UDP 67.220.216.146:5080;rport;branch=z9hG4bK02jNX8a4HrNyN
Route: <[url=sip:209.216.2.211;ftag=4adc7-13c4-1ab03-71ce3705-1ab03;lr=on]sip:209.216.2.211;ftag=4adc7-13c4-1ab03-71ce3705-1ab03;lr=on[/url]>
Route: <[url=sip:65.211.120.237:5060;lr]sip:65.211.120.237:5060;lr[/url]>
Route: <[url=sip:63.110.102.239;lr]sip:63.110.102.239;lr[/url]>
Max-Forwards: 70
From: <[url=sip:+12133304391@63.110.102.239:5060;user=phone]sip:+12133304391@63.110.102.239:5060;user=phone[/url]>;tag=cgBe054jZrt3a
To: <[url=sip:+14158867717@199.173.100.16:5060;user=phone]sip:+14158867717@199.173.100.16:5060;user=phone[/url]>;tag=4adc7-13c4-1ab03-71ce3705-1ab03
Call-ID: a0f656a01064adc713c41ab036840746ee20ca11c06b2d8-0440-5124
CSeq: 121818989 BYE
Contact: <[url=sip:+12133304391@67.220.216.146:5080;transport=udp]sip:+12133304391@67.220.216.146:5080;transport=udp[/url]>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15135
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, UPDATE, NOTIFY
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
------------------------------------------------------------------------
Thanks.
--matt
On Sat, Aug 8, 2009 at 12:42 PM, Michael Jerris <mike@jerris.com (mike@jerris.com)> wrote:
| Quote: | http://wiki.freeswitch.org/wiki/Sofia#Debugging_Sofia-SIP
turn the logging all the way up and see what it says.
Mike
On Aug 4, 2009, at 2:51 PM, Matthew Fong wrote:
| Quote: | Hi Mathieu, thanks for the reply. I enabled sip trace logging and got the logs below, but I am still at a loss at being able to identify the error or reproduce it consistently. The below log indicates to me that my FS server is initiating sending 2 BYE message to my DID provider (didforsale.com). Is there a way I can look further inside FreeSWITCH to see why it is sending this BYE packet?
sent 882 bytes to udp/[209.216.2.211]:5060 at 17:15:44.679208:
BYE [url=sip:199.173.100.144:5060;transport=UDP]sip:199.173.100.144:5060;transport=UDP[/url] SIP/2.0
Via: SIP/2.0/UDP 66.197.142.69:5080;rport;branch=z9hG4bKD0UKrDB508mDD
Route: <[url=sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on]sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on[/url]>
Route: <[url=sip:65.217.40.210:5060;lr]sip:65.217.40.210:5060;lr[/url]>
Route: <[url=sip:63.110.102.238;lr]sip:63.110.102.238;lr[/url]>
Max-Forwards: 70
From: <[url=sip:+1212381XXXX@63.110.102.238:5060;user=phone]sip:+1212381XXXX@63.110.102.238:5060;user=phone[/url]>;tag=Ztr5ycrv3QZ1g
To: <[url=sip:+1909635XXXX@199.173.100.144:5060;user=phone]sip:+1909635XXXX@199.173.100.144:5060;user=phone[/url]>;tag=dc7-13c4-2401b7-46dea593-2401b7
Call-ID: a22bffb89064adc713c42401b78ca6b689e90b32fdbf612c0-0487-7441
CSeq: 118584736 BYE
Contact: <[url=sip:+1212381XXXX@66.197.142.69:5080;transport=udp]sip:+1212381XXXX@66.197.142.69:5080;transport=udp[/url]>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14417M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
sent 882 bytes to udp/[209.216.2.211]:5060 at 17:15:45.182589:
BYE [url=sip:199.173.100.144:5060;transport=UDP]sip:199.173.100.144:5060;transport=UDP[/url] SIP/2.0
Via: SIP/2.0/UDP 66.197.142.69:5080;rport;branch=z9hG4bKD0UKrDB508mDD
Route: <[url=sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on]sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on[/url]>
Route: <[url=sip:65.217.40.210:5060;lr]sip:65.217.40.210:5060;lr[/url]>
Route: <[url=sip:63.110.102.238;lr]sip:63.110.102.238;lr[/url]>
Max-Forwards: 70
From: <[url=sip:+1212381XXXX@63.110.102.238:5060;user=phone]sip:+1212381XXXX@63.110.102.238:5060;user=phone[/url]>;tag=Ztr5ycrv3QZ1g
To: <[url=sip:+1909635XXXX@199.173.100.144:5060;user=phone]sip:+1909635XXXX@199.173.100.144:5060;user=phone[/url]>;tag=dc7-13c4-2401b7-46dea593-2401b7
Call-ID: a22bffb89064adc713c42401b78ca6b689e90b32fdbf612c0-0487-7441
CSeq: 118584736 BYE
Contact: <[url=sip:+1212381XXXX@66.197.142.69:5080;transport=udp]sip:+1212381XXXX@66.197.142.69:5080;transport=udp[/url]>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14417M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
On Sun, Aug 2, 2009 at 11:20 PM, Mathieu Rene <mrene_lists@avgs.ca (mrene_lists@avgs.ca)> wrote:
| Quote: | Hi,
Digging a bit in mod_sofia releaved that it can be caused by a SIP
code 482 (loop detected), 483 (too many hops) or 484 (address
incomplete).
Do a SIP trace to sched more light on what's happening.
Mathieu Rene
Avant-Garde Solutions Inc
Office: + 1 (514) 664-1044 x100
Cell: +1 (514) 664-1044 x200
m (mrene@avgs.ca) |
|
|
|
|
|
| Back to top |
|
|
mattdfong at gmail.com
Guest
|
| Posted: Sun Oct 18, 2009 11:59 pm Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
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.
I did do some additional testing, and my prior comment about it working in the internal profile is incorrect. Even if I put my DID provider in my internal profile, I still receive the Exchange_Routing_Error after being bridged with a few channels. However, I purchased a DID from icall, and that DID worked. So icall YES, didforsale.com NO...It's too bad tho that didforsale.com doesn't work too well with FreeSWITCH because their 20 unlimited inbound channels can't be beat.
--matt
http://www.hellohunter.com
On Mon, Oct 19, 2009 at 8:56 AM, Michael Jerris <mike@jerris.com (mike@jerris.com)> wrote:
| Quote: | FreeSWITCH debug level logs should help tell you exactly what is killing the call.
On Oct 18, 2009, at 10:25 AM, Matthew Fong wrote:
| Quote: | I'm still having this issue with random EXCHANGE_ROUTING_ERROR disconnects for users utilizing my inbound DID to connect to my FreeSWITCH server. It's a predictive dialing application, with one agent session being bridged with multiple calls and transfered back and forth between extensions in my dial plan. After a random number of bridging and transferring, FreeSWITCH suddenly sends a BYE to my DID provider citing an EXCHANGE_ROUTING_ERROR. It does not happen at any one-point in my dial plan, or applications--it just randomly disconnects when a call that the Agent is bridged to hangs-up or is disconnected. It seems to only happen when two external sip profiles are being bridged together, and not when an internal and external profile is being bridged.
I turned
sip trace on and
sofia loglevel all 9
below is the the snippet. I've posted the entire Agent session at the following pastebin http://pastebin.freeswitch.org/10756
tport_deliver(0x18413c0): msg 0x7faeb818ea30 (304 bytes) from udp/208.76.18.254:5080/sip next=(nil)
nta: received 200 OK for BYE (121818983)
nta: 200 OK is going to a transaction
nta_outgoing: RTT is 84.409 ms
tport_release(0x18413c0): 0x1a15cc0 by 0x1a16a00 with 0x7faeb818ea30
nua(0x1ad6fb0): event r_bye 200 OK
nua(0x1ad6fb0): call state changed: terminating -> terminated
nua(0x1ad6fb0): event i_state 200 to BYE
nua: nua_application_event: entering
nua(0x1ad6fb0): event i_terminated 200 to BYE
nua: nua_handle_magic: entering
nua(0x1ad6fb0): removing session usage
soa_destroy(static::0x1b5ae90) called
nua: nua_application_event: entering
nta_leg_destroy(0x1b594a0)
nua: nua_handle_magic: entering
nua: nua_handle_bind: entering
nua: nua_application_event: entering
nua: nua_handle_magic: entering
nua: terminated session 0x1ad6fb0
nua: nua_handle_destroy: entering
nua(0x1ad6fb0): recv signal r_destroy
nta_leg_destroy((nil))
nua(0x1ad6fb0): sent signal r_destroy
nta: timer set next to 28 ms
nta: timer E fired, retransmit BYE (121818989)
tport_release(0x18413c0): 0x1b5c9b0 by 0x7faeb817d830 with (nil)
tport_tsend(0x18413c0) tpn = */209.216.2.211:5060
tport_resolve addrinfo = 209.216.2.211:5060
tport_by_addrinfo(0x18413c0): not found by name */209.216.2.211:5060
tport_vsend(0x18413c0): 862 bytes of 862 to udp/209.216.2.211:5060
tport_vsend returned 862
send 862 bytes to udp/[209.216.2.211]:5060 at 14:04:11.753690:
------------------------------------------------------------------------
BYE sip:199.173.100.16:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 67.220.216.146:5080;rport;branch=z9hG4bK02jNX8a4HrNyN
Route: <sip:209.216.2.211;ftag=4adc7-13c4-1ab03-71ce3705-1ab03;lr=on>
Route: <sip:65.211.120.237:5060;lr>
Route: <sip:63.110.102.239;lr>
Max-Forwards: 70
From: <sip:+12133304391@63.110.102.239:5060;user=phone>;tag=cgBe054jZrt3a
To: <sip:+14158867717@199.173.100.16:5060;user=phone>;tag=4adc7-13c4-1ab03-71ce3705-1ab03
Call-ID: a0f656a01064adc713c41ab036840746ee20ca11c06b2d8-0440-5124
CSeq: 121818989 BYE
Contact: <sip:+12133304391@67.220.216.146:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15135
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, UPDATE, NOTIFY
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
------------------------------------------------------------------------
Thanks.
--matt
On Sat, Aug 8, 2009 at 12:42 PM, Michael Jerris <mike@jerris.com (mike@jerris.com)> wrote:
| Quote: | http://wiki.freeswitch.org/wiki/Sofia#Debugging_Sofia-SIP
turn the logging all the way up and see what it says.
Mike
On Aug 4, 2009, at 2:51 PM, Matthew Fong wrote:
| Quote: | Hi Mathieu, thanks for the reply. I enabled sip trace logging and got the logs below, but I am still at a loss at being able to identify the error or reproduce it consistently. The below log indicates to me that my FS server is initiating sending 2 BYE message to my DID provider (didforsale.com). Is there a way I can look further inside FreeSWITCH to see why it is sending this BYE packet?
sent 882 bytes to udp/[209.216.2.211]:5060 at 17:15:44.679208:
BYE sip:199.173.100.144:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 66.197.142.69:5080;rport;branch=z9hG4bKD0UKrDB508mDD
Route: <sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on>
Route: <sip:65.217.40.210:5060;lr>
Route: <sip:63.110.102.238;lr>
Max-Forwards: 70
From: <sip:+1212381XXXX@63.110.102.238:5060;user=phone>;tag=Ztr5ycrv3QZ1g
To: <sip:+1909635XXXX@199.173.100.144:5060;user=phone>;tag=dc7-13c4-2401b7-46dea593-2401b7
Call-ID: a22bffb89064adc713c42401b78ca6b689e90b32fdbf612c0-0487-7441
CSeq: 118584736 BYE
Contact: <sip:+1212381XXXX@66.197.142.69:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14417M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
sent 882 bytes to udp/[209.216.2.211]:5060 at 17:15:45.182589:
BYE sip:199.173.100.144:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 66.197.142.69:5080;rport;branch=z9hG4bKD0UKrDB508mDD
Route: <sip:209.216.2.211;ftag=dc7-13c4-2401b7-46dea593-2401b7;lr=on>
Route: <sip:65.217.40.210:5060;lr>
Route: <sip:63.110.102.238;lr>
Max-Forwards: 70
From: <sip:+1212381XXXX@63.110.102.238:5060;user=phone>;tag=Ztr5ycrv3QZ1g
To: <sip:+1909635XXXX@199.173.100.144:5060;user=phone>;tag=dc7-13c4-2401b7-46dea593-2401b7
Call-ID: a22bffb89064adc713c42401b78ca6b689e90b32fdbf612c0-0487-7441
CSeq: 118584736 BYE
Contact: <sip:+1212381XXXX@66.197.142.69:5080;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-14417M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=25;text="EXCHANGE_ROUTING_ERROR"
Content-Length: 0
On Sun, Aug 2, 2009 at 11:20 PM, Mathieu Rene <mrene_lists@avgs.ca (mrene_lists@avgs.ca)> wrote:
| Quote: | Hi,
Digging a bit in mod_sofia releaved that it can be caused by a SIP
code 482 (loop detected), 483 (too many hops) or 484 (address
incomplete).
Do a SIP trace to sched more light on what's happening.
Mathieu Rene
Avant-Garde Solutions Inc
Office: + 1 (514) 664-1044 x100
Cell: +1 (514) 664-1044 x200
m (mrene@avgs.ca) |
|
|
|
_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org (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
|
|
|
| Back to top |
|
|
msc at freeswitch.org
Guest
|
| Posted: Mon Oct 19, 2009 1:55 pm Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 |
|
| Back to top |
|
|
mattdfong at gmail.com
Guest
|
| Posted: Thu Oct 22, 2009 12:56 pm Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
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
[/url]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 [url=http://didforsale.org]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:5060 set(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/+[url=http://14158 867717@199.173.100.16:5060]14158867717@199.173.100.16:5060[/url] [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 (msc@freeswitch.org)> wrote:
| Quote: |
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 (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
|
|
|
| Back to top |
|
|
anthony.minessale at g...
Guest
|
| Posted: Thu Oct 22, 2009 2:46 pm Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
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 (mattdfong@gmail.com)> wrote:
| Quote: | 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
[/url]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 [url=http://didforsale.org]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:5060 set(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 (msc@freeswitch.org)> wrote:
| Quote: |
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 (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 (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 ([email]MSN%3Aanthony_minessale@hotmail.com[/email])
GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com ([email]PAYPAL%3Aanthony.minessale@gmail.com[/email])
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888@conference.freeswitch.org ([email]sip%3A888@conference.freeswitch.org[/email])
iax:guest@conference.freeswitch.org/888
googletalk:conf+888@conference.freeswitch.org ([email]googletalk%3Aconf%2B888@conference.freeswitch.org[/email])
pstn:213-799-1400 |
|
| Back to top |
|
|
mattdfong at gmail.com
Guest
|
| Posted: Thu Oct 22, 2009 10:35 pm Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
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 (anthony.minessale@gmail.com)> wrote:
| Quote: | 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 (mattdfong@gmail.com)> wrote:
| Quote: | 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
[/url]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 [url=http://didforsale.org]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.17 3.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:5060 set(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 (msc@freeswitch.org)> wrote:
| Quote: |
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 (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 (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 ([email]MSN%3Aanthony_minessale@hotmail.com[/email])
GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com ([email]PAYPAL%3Aanthony.minessale@gmail.com[/email])
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888@conference.freeswitch.org ([email]sip%3A888@conference.freeswitch.org[/email])
iax:guest@conference.freeswitch.org/888
googletalk:conf+888@conference.freeswitch.org ([email]googletalk%3Aconf%2B888@conference.freeswitch.org[/email])
pstn:213-799-1400
_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org (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
|
|
|
| Back to top |
|
|
mattdfong at gmail.com
Guest
|
| Posted: Fri Oct 23, 2009 8:57 am Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
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 (mattdfong@gmail.com)> wrote:
| Quote: | 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 (anthony.minessale@gmail.com)> wrote:
| Quote: | 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 (mattdfong@gmail.com)> wrote:
| Quote: | 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
[/url]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 [url=http://didforsale.org]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/+[url=http://14158867717@19 9.173.100.16:5060]14158867717@199.173.100.16:5060[/url] 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:5060 set(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 (msc@freeswitch.org)> wrote:
| Quote: |
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 (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 (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 ([email]MSN%3Aanthony_minessale@hotmail.com[/email])
GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com ([email]PAYPAL%3Aanthony.minessale@gmail.com[/email])
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888@conference.freeswitch.org ([email]sip%3A888@conference.freeswitch.org[/email])
iax:guest@conference.freeswitch.org/888
googletalk:conf+888@conference.freeswitch.org ([email]googletalk%3Aconf%2B888@conference.freeswitch.org[/email])
pstn:213-799-1400
_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org (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
|
|
|
|
| Back to top |
|
|
anthony.minessale at g...
Guest
|
| Posted: Fri Oct 23, 2009 9:53 am Post subject: [Freeswitch-users] EXCHANGE_ROUTING_ERROR -- how to diagnose |
|
|
you can set the variable max_forwards to a high number.
It does not magically set itself so you must be looping through many transfers at least.
On Fri, Oct 23, 2009 at 8:46 AM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 (mattdfong@gmail.com)> wrote:
| Quote: | 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 (anthony.minessale@gmail.com)> wrote:
| Quote: | 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 (mattdfong@gmail.com)> wrote:
| Quote: | 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
[/url]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 [url=http://didforsale.org]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:5060 set(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 (msc@freeswitch.org)> wrote:
| Quote: |
On Sun, Oct 18, 2009 at 9:48 PM, Matthew Fong <mattdfong@gmail.com (mattdfong@gmail.com)> wrote:
| Quote: | 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 (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 (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 ([email]MSN%3Aanthony_minessale@hotmail.com[/email])
GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com ([email]PAYPAL%3Aanthony.minessale@gmail.com[/email])
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888@conference.freeswitch.org ([email]sip%3A888@conference.freeswitch.org[/email])
iax:guest@conference.freeswitch.org/888
googletalk:conf+888@conference.freeswitch.org ([email]googletalk%3Aconf%2B888@conference.freeswitch.org[/email])
pstn:213-799-1400
_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org (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 (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 ([email]MSN%3Aanthony_minessale@hotmail.com[/email])
GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com ([email]PAYPAL%3Aanthony.minessale@gmail.com[/email])
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888@conference.freeswitch.org ([email]sip%3A888@conference.freeswitch.org[/email])
iax:guest@conference.freeswitch.org/888
googletalk:conf+888@conference.freeswitch.org ([email]googletalk%3Aconf%2B888@conference.freeswitch.org[/email])
pstn:213-799-1400 |
|
| Back to top |
|
|
|
|
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
Powered by phpBB © 2001, 2005 phpBB Group
|
Search
