2009-06-11 12:14:34.870820 [NOTICE] switch_channel.c:602 New Channel sofia/external/6473671811@sip.gafachi.com [6867d2a1-e26a-4cab-9122-7ecab2b9397f]
2009-06-11 12:14:34.870820 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [received][100]
2009-06-11 12:14:34.870820 [DEBUG] sofia.c:3107 Remote SDP:
v=0
o=root 273544867 273544867 IN IP4 67.216.37.18
s=session
c=IN IP4 67.216.37.18
t=0 0
m=audio 35116 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20

2009-06-11 12:14:34.870820 [DEBUG] sofia_glue.c:3059 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
2009-06-11 12:14:34.870820 [DEBUG] sofia_glue.c:2017 Set Codec sofia/external/6473671811@sip.gafachi.com PCMU/8000 20 ms 160 samples
2009-06-11 12:14:34.870820 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_NEW
2009-06-11 12:14:34.874889 [DEBUG] switch_core_state_machine.c:403 (sofia/external/6473671811@sip.gafachi.com) State NEW
2009-06-11 12:14:34.874889 [DEBUG] sofia_glue.c:3019 Set 2833 dtmf payload to 101
2009-06-11 12:14:34.874889 [DEBUG] sofia.c:3266 (sofia/external/6473671811@sip.gafachi.com) State Change CS_NEW -> CS_INIT
2009-06-11 12:14:34.874889 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_INIT
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT
2009-06-11 12:14:34.878827 [DEBUG] mod_sofia.c:83 sofia/external/6473671811@sip.gafachi.com SOFIA INIT
2009-06-11 12:14:34.878827 [DEBUG] mod_sofia.c:111 (sofia/external/6473671811@sip.gafachi.com) State Change CS_INIT -> CS_ROUTING
2009-06-11 12:14:34.878827 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT going to sleep
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_ROUTING
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING
2009-06-11 12:14:34.878827 [DEBUG] mod_sofia.c:130 sofia/external/6473671811@sip.gafachi.com SOFIA ROUTING
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:78 sofia/external/6473671811@sip.gafachi.com Standard ROUTING
2009-06-11 12:14:34.878827 [INFO] mod_dialplan_xml.c:252 Processing unknown->18664591152 in context public
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->unloop] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Absolute Condition [outside_call]
Dialplan: sofia/external/6473671811@sip.gafachi.com Action set(outside_call=true)
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_extensions] destination_number(18664591152) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_did] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_did] destination_number(18664591152) =~ /^(5551212)$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->gafachi-extension] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [gafachi-extension] destination_number(18664591152) =~ /^1866.*$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Action respond(503)
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:114 (sofia/external/6473671811@sip.gafachi.com) State Change CS_ROUTING -> CS_EXECUTE
2009-06-11 12:14:34.878827 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING going to sleep
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_EXECUTE
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE
2009-06-11 12:14:34.878827 [DEBUG] mod_sofia.c:173 sofia/external/6473671811@sip.gafachi.com SOFIA EXECUTE
2009-06-11 12:14:34.878827 [DEBUG] switch_core_state_machine.c:151 sofia/external/6473671811@sip.gafachi.com Standard EXECUTE
EXECUTE sofia/external/6473671811@sip.gafachi.com set(outside_call=true)
2009-06-11 12:14:34.878827 [DEBUG] mod_dptools.c:748 sofia/external/6473671811@sip.gafachi.com SET [outside_call]=[true]
EXECUTE sofia/external/6473671811@sip.gafachi.com respond(503)
2009-06-11 12:14:34.882811 [DEBUG] mod_dptools.c:710 sofia/external/6473671811@sip.gafachi.com receive message [RESPOND]
2009-06-11 12:14:34.882811 [DEBUG] mod_sofia.c:1406 Responding with 503 [Service Unavailable]
2009-06-11 12:14:34.882811 [DEBUG] switch_core_session.c:630 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:34.882811 [NOTICE] switch_core_state_machine.c:179 Hangup sofia/external/6473671811@sip.gafachi.com [CS_EXECUTE] [NORMAL_CLEARING]
2009-06-11 12:14:34.882811 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [terminated][503]
2009-06-11 12:14:34.882811 [DEBUG] switch_channel.c:1683 Send signal sofia/external/6473671811@sip.gafachi.com [KILL]
2009-06-11 12:14:34.882811 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:34.882811 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE going to sleep
2009-06-11 12:14:34.882811 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_HANGUP
2009-06-11 12:14:34.882811 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP
2009-06-11 12:14:34.882811 [DEBUG] mod_sofia.c:338 Channel sofia/external/6473671811@sip.gafachi.com hanging up, cause: NORMAL_CLEARING
2009-06-11 12:14:34.882811 [DEBUG] switch_core_state_machine.c:46 sofia/external/6473671811@sip.gafachi.com Standard HANGUP, cause: NORMAL_CLEARING
2009-06-11 12:14:34.882811 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP going to sleep
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:475 (sofia/external/6473671811@sip.gafachi.com) State Change CS_HANGUP -> CS_REPORTING
2009-06-11 12:14:34.886819 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_REPORTING
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:53 sofia/external/6473671811@sip.gafachi.com Standard REPORTING, cause: NORMAL_CLEARING
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING going to sleep
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:410 (sofia/external/6473671811@sip.gafachi.com) State Change CS_REPORTING -> CS_DESTROY
2009-06-11 12:14:34.886819 [DEBUG] switch_core_session.c:1067 Session 1 (sofia/external/6473671811@sip.gafachi.com) Locked, Waiting on external entities
2009-06-11 12:14:34.886819 [NOTICE] switch_core_session.c:1085 Session 1 (sofia/external/6473671811@sip.gafachi.com) Ended
2009-06-11 12:14:34.886819 [NOTICE] switch_core_session.c:1087 Close Channel sofia/external/6473671811@sip.gafachi.com [CS_DESTROY]
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY
2009-06-11 12:14:34.886819 [DEBUG] mod_sofia.c:255 sofia/external/6473671811@sip.gafachi.com SOFIA DESTROY
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:60 sofia/external/6473671811@sip.gafachi.com Standard DESTROY
2009-06-11 12:14:34.886819 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY going to sleep
2009-06-11 12:14:38.559058 [NOTICE] switch_channel.c:602 New Channel sofia/external/6473671811@sip.gafachi.com [f1544b7b-0176-447d-88f0-db6a422fb89e]
2009-06-11 12:14:38.559058 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [received][100]
2009-06-11 12:14:38.559058 [DEBUG] sofia.c:3107 Remote SDP:
v=0
o=root 1686340962 1686340962 IN IP4 67.216.37.18
s=session
c=IN IP4 67.216.37.18
t=0 0
m=audio 43928 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20

2009-06-11 12:14:38.559058 [DEBUG] sofia_glue.c:3059 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
2009-06-11 12:14:38.559058 [DEBUG] sofia_glue.c:2017 Set Codec sofia/external/6473671811@sip.gafachi.com PCMU/8000 20 ms 160 samples
2009-06-11 12:14:38.559058 [DEBUG] sofia_glue.c:3019 Set 2833 dtmf payload to 101
2009-06-11 12:14:38.559058 [DEBUG] sofia.c:3266 (sofia/external/6473671811@sip.gafachi.com) State Change CS_NEW -> CS_INIT
2009-06-11 12:14:38.559058 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:38.559058 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_INIT
2009-06-11 12:14:38.559058 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT
2009-06-11 12:14:38.559058 [DEBUG] mod_sofia.c:83 sofia/external/6473671811@sip.gafachi.com SOFIA INIT
2009-06-11 12:14:38.559058 [DEBUG] mod_sofia.c:111 (sofia/external/6473671811@sip.gafachi.com) State Change CS_INIT -> CS_ROUTING
2009-06-11 12:14:38.559058 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:38.559058 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT going to sleep
2009-06-11 12:14:38.559058 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_ROUTING
2009-06-11 12:14:38.559058 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING
2009-06-11 12:14:38.559058 [DEBUG] mod_sofia.c:130 sofia/external/6473671811@sip.gafachi.com SOFIA ROUTING
2009-06-11 12:14:38.559058 [DEBUG] switch_core_state_machine.c:78 sofia/external/6473671811@sip.gafachi.com Standard ROUTING
2009-06-11 12:14:38.559058 [INFO] mod_dialplan_xml.c:252 Processing unknown->18664591152 in context public
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->unloop] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Absolute Condition [outside_call]
Dialplan: sofia/external/6473671811@sip.gafachi.com Action set(outside_call=true)
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_extensions] destination_number(18664591152) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_did] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_did] destination_number(18664591152) =~ /^(5551212)$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->gafachi-extension] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [gafachi-extension] destination_number(18664591152) =~ /^1866.*$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Action respond(503)
2009-06-11 12:14:38.563057 [DEBUG] switch_core_state_machine.c:114 (sofia/external/6473671811@sip.gafachi.com) State Change CS_ROUTING -> CS_EXECUTE
2009-06-11 12:14:38.563057 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:38.563057 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING going to sleep
2009-06-11 12:14:38.563057 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_EXECUTE
2009-06-11 12:14:38.563057 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE
2009-06-11 12:14:38.563057 [DEBUG] mod_sofia.c:173 sofia/external/6473671811@sip.gafachi.com SOFIA EXECUTE
2009-06-11 12:14:38.563057 [DEBUG] switch_core_state_machine.c:151 sofia/external/6473671811@sip.gafachi.com Standard EXECUTE
EXECUTE sofia/external/6473671811@sip.gafachi.com set(outside_call=true)
2009-06-11 12:14:38.563057 [DEBUG] mod_dptools.c:748 sofia/external/6473671811@sip.gafachi.com SET [outside_call]=[true]
EXECUTE sofia/external/6473671811@sip.gafachi.com respond(503)
2009-06-11 12:14:38.563057 [DEBUG] mod_dptools.c:710 sofia/external/6473671811@sip.gafachi.com receive message [RESPOND]
2009-06-11 12:14:38.563057 [DEBUG] mod_sofia.c:1406 Responding with 503 [Service Unavailable]
2009-06-11 12:14:38.563057 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [terminated][503]
2009-06-11 12:14:38.563057 [NOTICE] sofia.c:3660 Hangup sofia/external/6473671811@sip.gafachi.com [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2009-06-11 12:14:38.567118 [DEBUG] switch_channel.c:1683 Send signal sofia/external/6473671811@sip.gafachi.com [KILL]
2009-06-11 12:14:38.567118 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:38.567118 [DEBUG] switch_core_session.c:630 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE going to sleep
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_HANGUP
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP
2009-06-11 12:14:38.567118 [DEBUG] mod_sofia.c:306 sofia/external/6473671811@sip.gafachi.com Overriding SIP cause 503 with 503 from the other leg
2009-06-11 12:14:38.567118 [DEBUG] mod_sofia.c:338 Channel sofia/external/6473671811@sip.gafachi.com hanging up, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:46 sofia/external/6473671811@sip.gafachi.com Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP going to sleep
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:475 (sofia/external/6473671811@sip.gafachi.com) State Change CS_HANGUP -> CS_REPORTING
2009-06-11 12:14:38.567118 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_REPORTING
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:53 sofia/external/6473671811@sip.gafachi.com Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING going to sleep
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:410 (sofia/external/6473671811@sip.gafachi.com) State Change CS_REPORTING -> CS_DESTROY
2009-06-11 12:14:38.567118 [DEBUG] switch_core_session.c:1067 Session 2 (sofia/external/6473671811@sip.gafachi.com) Locked, Waiting on external entities
2009-06-11 12:14:38.567118 [NOTICE] switch_core_session.c:1085 Session 2 (sofia/external/6473671811@sip.gafachi.com) Ended
2009-06-11 12:14:38.567118 [NOTICE] switch_core_session.c:1087 Close Channel sofia/external/6473671811@sip.gafachi.com [CS_DESTROY]
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY
2009-06-11 12:14:38.567118 [DEBUG] mod_sofia.c:255 sofia/external/6473671811@sip.gafachi.com SOFIA DESTROY
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:60 sofia/external/6473671811@sip.gafachi.com Standard DESTROY
2009-06-11 12:14:38.567118 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY going to sleep
2009-06-11 12:14:42.471295 [NOTICE] switch_channel.c:602 New Channel sofia/external/6473671811@sip.gafachi.com [dcf89ba0-7932-4cc8-a337-5f807ae3c394]
2009-06-11 12:14:42.471295 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [received][100]
2009-06-11 12:14:42.471295 [DEBUG] sofia.c:3107 Remote SDP:
v=0
o=root 1254501935 1254501935 IN IP4 67.216.37.17
s=session
c=IN IP4 67.216.37.17
t=0 0
m=audio 34272 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20

2009-06-11 12:14:42.471295 [DEBUG] sofia_glue.c:3059 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
2009-06-11 12:14:42.471295 [DEBUG] sofia_glue.c:2017 Set Codec sofia/external/6473671811@sip.gafachi.com PCMU/8000 20 ms 160 samples
2009-06-11 12:14:42.471295 [DEBUG] sofia_glue.c:3019 Set 2833 dtmf payload to 101
2009-06-11 12:14:42.471295 [DEBUG] sofia.c:3266 (sofia/external/6473671811@sip.gafachi.com) State Change CS_NEW -> CS_INIT
2009-06-11 12:14:42.471295 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:42.471295 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_INIT
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT
2009-06-11 12:14:42.475309 [DEBUG] mod_sofia.c:83 sofia/external/6473671811@sip.gafachi.com SOFIA INIT
2009-06-11 12:14:42.475309 [DEBUG] mod_sofia.c:111 (sofia/external/6473671811@sip.gafachi.com) State Change CS_INIT -> CS_ROUTING
2009-06-11 12:14:42.475309 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT going to sleep
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_ROUTING
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING
2009-06-11 12:14:42.475309 [DEBUG] mod_sofia.c:130 sofia/external/6473671811@sip.gafachi.com SOFIA ROUTING
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:78 sofia/external/6473671811@sip.gafachi.com Standard ROUTING
2009-06-11 12:14:42.475309 [INFO] mod_dialplan_xml.c:252 Processing unknown->18664591152 in context public
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->unloop] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Absolute Condition [outside_call]
Dialplan: sofia/external/6473671811@sip.gafachi.com Action set(outside_call=true)
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_extensions] destination_number(18664591152) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_did] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_did] destination_number(18664591152) =~ /^(5551212)$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->gafachi-extension] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [gafachi-extension] destination_number(18664591152) =~ /^1866.*$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Action respond(503)
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:114 (sofia/external/6473671811@sip.gafachi.com) State Change CS_ROUTING -> CS_EXECUTE
2009-06-11 12:14:42.475309 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING going to sleep
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_EXECUTE
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE
2009-06-11 12:14:42.475309 [DEBUG] mod_sofia.c:173 sofia/external/6473671811@sip.gafachi.com SOFIA EXECUTE
2009-06-11 12:14:42.475309 [DEBUG] switch_core_state_machine.c:151 sofia/external/6473671811@sip.gafachi.com Standard EXECUTE
EXECUTE sofia/external/6473671811@sip.gafachi.com set(outside_call=true)
2009-06-11 12:14:42.475309 [DEBUG] mod_dptools.c:748 sofia/external/6473671811@sip.gafachi.com SET [outside_call]=[true]
EXECUTE sofia/external/6473671811@sip.gafachi.com respond(503)
2009-06-11 12:14:42.479287 [DEBUG] mod_dptools.c:710 sofia/external/6473671811@sip.gafachi.com receive message [RESPOND]
2009-06-11 12:14:42.479287 [DEBUG] mod_sofia.c:1406 Responding with 503 [Service Unavailable]
2009-06-11 12:14:42.479287 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [terminated][503]
2009-06-11 12:14:42.479287 [NOTICE] sofia.c:3660 Hangup sofia/external/6473671811@sip.gafachi.com [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2009-06-11 12:14:42.479287 [DEBUG] switch_channel.c:1683 Send signal sofia/external/6473671811@sip.gafachi.com [KILL]
2009-06-11 12:14:42.479287 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:42.479287 [DEBUG] switch_core_session.c:630 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:42.479287 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE going to sleep
2009-06-11 12:14:42.479287 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_HANGUP
2009-06-11 12:14:42.479287 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP
2009-06-11 12:14:42.479287 [DEBUG] mod_sofia.c:306 sofia/external/6473671811@sip.gafachi.com Overriding SIP cause 503 with 503 from the other leg
2009-06-11 12:14:42.479287 [DEBUG] mod_sofia.c:338 Channel sofia/external/6473671811@sip.gafachi.com hanging up, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:42.479287 [DEBUG] switch_core_state_machine.c:46 sofia/external/6473671811@sip.gafachi.com Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:42.479287 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP going to sleep
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:475 (sofia/external/6473671811@sip.gafachi.com) State Change CS_HANGUP -> CS_REPORTING
2009-06-11 12:14:42.483297 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_REPORTING
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:53 sofia/external/6473671811@sip.gafachi.com Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING going to sleep
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:410 (sofia/external/6473671811@sip.gafachi.com) State Change CS_REPORTING -> CS_DESTROY
2009-06-11 12:14:42.483297 [DEBUG] switch_core_session.c:1067 Session 3 (sofia/external/6473671811@sip.gafachi.com) Locked, Waiting on external entities
2009-06-11 12:14:42.483297 [NOTICE] switch_core_session.c:1085 Session 3 (sofia/external/6473671811@sip.gafachi.com) Ended
2009-06-11 12:14:42.483297 [NOTICE] switch_core_session.c:1087 Close Channel sofia/external/6473671811@sip.gafachi.com [CS_DESTROY]
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY
2009-06-11 12:14:42.483297 [DEBUG] mod_sofia.c:255 sofia/external/6473671811@sip.gafachi.com SOFIA DESTROY
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:60 sofia/external/6473671811@sip.gafachi.com Standard DESTROY
2009-06-11 12:14:42.483297 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY going to sleep
2009-06-11 12:14:44.147389 [NOTICE] switch_channel.c:602 New Channel sofia/external/6473671811@sip.gafachi.com [7e608276-0901-4525-8822-7d4c07283466]
2009-06-11 12:14:44.147389 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [received][100]
2009-06-11 12:14:44.147389 [DEBUG] sofia.c:3107 Remote SDP:
v=0
o=root 36880947 36880947 IN IP4 67.216.37.18
s=session
c=IN IP4 67.216.37.18
t=0 0
m=audio 59904 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20

2009-06-11 12:14:44.147389 [DEBUG] sofia_glue.c:3059 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
2009-06-11 12:14:44.147389 [DEBUG] sofia_glue.c:2017 Set Codec sofia/external/6473671811@sip.gafachi.com PCMU/8000 20 ms 160 samples
2009-06-11 12:14:44.151433 [DEBUG] sofia_glue.c:3019 Set 2833 dtmf payload to 101
2009-06-11 12:14:44.151433 [DEBUG] sofia.c:3266 (sofia/external/6473671811@sip.gafachi.com) State Change CS_NEW -> CS_INIT
2009-06-11 12:14:44.151433 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_INIT
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT
2009-06-11 12:14:44.151433 [DEBUG] mod_sofia.c:83 sofia/external/6473671811@sip.gafachi.com SOFIA INIT
2009-06-11 12:14:44.151433 [DEBUG] mod_sofia.c:111 (sofia/external/6473671811@sip.gafachi.com) State Change CS_INIT -> CS_ROUTING
2009-06-11 12:14:44.151433 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT going to sleep
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_ROUTING
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING
2009-06-11 12:14:44.151433 [DEBUG] mod_sofia.c:130 sofia/external/6473671811@sip.gafachi.com SOFIA ROUTING
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:78 sofia/external/6473671811@sip.gafachi.com Standard ROUTING
2009-06-11 12:14:44.151433 [INFO] mod_dialplan_xml.c:252 Processing unknown->18664591152 in context public
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->unloop] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Absolute Condition [outside_call]
Dialplan: sofia/external/6473671811@sip.gafachi.com Action set(outside_call=true)
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_extensions] destination_number(18664591152) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_did] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_did] destination_number(18664591152) =~ /^(5551212)$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->gafachi-extension] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [gafachi-extension] destination_number(18664591152) =~ /^1866.*$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Action respond(503)
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:114 (sofia/external/6473671811@sip.gafachi.com) State Change CS_ROUTING -> CS_EXECUTE
2009-06-11 12:14:44.151433 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING going to sleep
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_EXECUTE
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE
2009-06-11 12:14:44.151433 [DEBUG] mod_sofia.c:173 sofia/external/6473671811@sip.gafachi.com SOFIA EXECUTE
2009-06-11 12:14:44.151433 [DEBUG] switch_core_state_machine.c:151 sofia/external/6473671811@sip.gafachi.com Standard EXECUTE
EXECUTE sofia/external/6473671811@sip.gafachi.com set(outside_call=true)
2009-06-11 12:14:44.155404 [DEBUG] mod_dptools.c:748 sofia/external/6473671811@sip.gafachi.com SET [outside_call]=[true]
EXECUTE sofia/external/6473671811@sip.gafachi.com respond(503)
2009-06-11 12:14:44.155404 [DEBUG] mod_dptools.c:710 sofia/external/6473671811@sip.gafachi.com receive message [RESPOND]
2009-06-11 12:14:44.155404 [DEBUG] mod_sofia.c:1406 Responding with 503 [Service Unavailable]
2009-06-11 12:14:44.155404 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [terminated][503]
2009-06-11 12:14:44.155404 [NOTICE] sofia.c:3660 Hangup sofia/external/6473671811@sip.gafachi.com [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2009-06-11 12:14:44.155404 [DEBUG] switch_channel.c:1683 Send signal sofia/external/6473671811@sip.gafachi.com [KILL]
2009-06-11 12:14:44.155404 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:44.155404 [DEBUG] switch_core_session.c:630 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE going to sleep
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_HANGUP
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP
2009-06-11 12:14:44.155404 [DEBUG] mod_sofia.c:306 sofia/external/6473671811@sip.gafachi.com Overriding SIP cause 503 with 503 from the other leg
2009-06-11 12:14:44.155404 [DEBUG] mod_sofia.c:338 Channel sofia/external/6473671811@sip.gafachi.com hanging up, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:46 sofia/external/6473671811@sip.gafachi.com Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP going to sleep
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:475 (sofia/external/6473671811@sip.gafachi.com) State Change CS_HANGUP -> CS_REPORTING
2009-06-11 12:14:44.155404 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_REPORTING
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:53 sofia/external/6473671811@sip.gafachi.com Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING going to sleep
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:410 (sofia/external/6473671811@sip.gafachi.com) State Change CS_REPORTING -> CS_DESTROY
2009-06-11 12:14:44.155404 [DEBUG] switch_core_session.c:1067 Session 4 (sofia/external/6473671811@sip.gafachi.com) Locked, Waiting on external entities
2009-06-11 12:14:44.155404 [NOTICE] switch_core_session.c:1085 Session 4 (sofia/external/6473671811@sip.gafachi.com) Ended
2009-06-11 12:14:44.155404 [NOTICE] switch_core_session.c:1087 Close Channel sofia/external/6473671811@sip.gafachi.com [CS_DESTROY]
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY
2009-06-11 12:14:44.155404 [DEBUG] mod_sofia.c:255 sofia/external/6473671811@sip.gafachi.com SOFIA DESTROY
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:60 sofia/external/6473671811@sip.gafachi.com Standard DESTROY
2009-06-11 12:14:44.155404 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY going to sleep
2009-06-11 12:14:46.131565 [NOTICE] switch_channel.c:602 New Channel sofia/external/6473671811@sip.gafachi.com [0e736a20-8f6b-4f0a-941a-fe00e277bb80]
2009-06-11 12:14:46.135599 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [received][100]
2009-06-11 12:14:46.135599 [DEBUG] sofia.c:3107 Remote SDP:
v=0
o=root 1258094781 1258094781 IN IP4 67.216.37.17
s=session
c=IN IP4 67.216.37.17
t=0 0
m=audio 16632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp:off - - - -
a=ptime:20

2009-06-11 12:14:46.135599 [DEBUG] sofia_glue.c:3059 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
2009-06-11 12:14:46.135599 [DEBUG] sofia_glue.c:2017 Set Codec sofia/external/6473671811@sip.gafachi.com PCMU/8000 20 ms 160 samples
2009-06-11 12:14:46.135599 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_NEW
2009-06-11 12:14:46.135599 [DEBUG] switch_core_state_machine.c:403 (sofia/external/6473671811@sip.gafachi.com) State NEW
2009-06-11 12:14:46.135599 [DEBUG] sofia_glue.c:3019 Set 2833 dtmf payload to 101
2009-06-11 12:14:46.135599 [DEBUG] sofia.c:3266 (sofia/external/6473671811@sip.gafachi.com) State Change CS_NEW -> CS_INIT
2009-06-11 12:14:46.135599 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_INIT
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT
2009-06-11 12:14:46.139548 [DEBUG] mod_sofia.c:83 sofia/external/6473671811@sip.gafachi.com SOFIA INIT
2009-06-11 12:14:46.139548 [DEBUG] mod_sofia.c:111 (sofia/external/6473671811@sip.gafachi.com) State Change CS_INIT -> CS_ROUTING
2009-06-11 12:14:46.139548 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:480 (sofia/external/6473671811@sip.gafachi.com) State INIT going to sleep
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_ROUTING
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING
2009-06-11 12:14:46.139548 [DEBUG] mod_sofia.c:130 sofia/external/6473671811@sip.gafachi.com SOFIA ROUTING
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:78 sofia/external/6473671811@sip.gafachi.com Standard ROUTING
2009-06-11 12:14:46.139548 [INFO] mod_dialplan_xml.c:252 Processing unknown->18664591152 in context public
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->unloop] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Absolute Condition [outside_call]
Dialplan: sofia/external/6473671811@sip.gafachi.com Action set(outside_call=true)
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_extensions] destination_number(18664591152) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->public_did] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (FAIL) [public_did] destination_number(18664591152) =~ /^(5551212)$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com parsing [public->gafachi-extension] continue=false
Dialplan: sofia/external/6473671811@sip.gafachi.com Regex (PASS) [gafachi-extension] destination_number(18664591152) =~ /^1866.*$/ break=on-false
Dialplan: sofia/external/6473671811@sip.gafachi.com Action respond(503)
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:114 (sofia/external/6473671811@sip.gafachi.com) State Change CS_ROUTING -> CS_EXECUTE
2009-06-11 12:14:46.139548 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:483 (sofia/external/6473671811@sip.gafachi.com) State ROUTING going to sleep
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_EXECUTE
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE
2009-06-11 12:14:46.139548 [DEBUG] mod_sofia.c:173 sofia/external/6473671811@sip.gafachi.com SOFIA EXECUTE
2009-06-11 12:14:46.139548 [DEBUG] switch_core_state_machine.c:151 sofia/external/6473671811@sip.gafachi.com Standard EXECUTE
EXECUTE sofia/external/6473671811@sip.gafachi.com set(outside_call=true)
2009-06-11 12:14:46.139548 [DEBUG] mod_dptools.c:748 sofia/external/6473671811@sip.gafachi.com SET [outside_call]=[true]
EXECUTE sofia/external/6473671811@sip.gafachi.com respond(503)
2009-06-11 12:14:46.147562 [DEBUG] mod_dptools.c:710 sofia/external/6473671811@sip.gafachi.com receive message [RESPOND]
2009-06-11 12:14:46.147562 [DEBUG] mod_sofia.c:1406 Responding with 503 [Service Unavailable]
2009-06-11 12:14:46.147562 [DEBUG] switch_core_session.c:630 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:46.147562 [DEBUG] sofia.c:3100 Channel sofia/external/6473671811@sip.gafachi.com entering state [terminated][503]
2009-06-11 12:14:46.147562 [NOTICE] sofia.c:3660 Hangup sofia/external/6473671811@sip.gafachi.com [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2009-06-11 12:14:46.147562 [DEBUG] switch_core_state_machine.c:490 (sofia/external/6473671811@sip.gafachi.com) State EXECUTE going to sleep
2009-06-11 12:14:46.147562 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_HANGUP
2009-06-11 12:14:46.147562 [DEBUG] switch_channel.c:1683 Send signal sofia/external/6473671811@sip.gafachi.com [KILL]
2009-06-11 12:14:46.147562 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP
2009-06-11 12:14:46.152178 [DEBUG] mod_sofia.c:306 sofia/external/6473671811@sip.gafachi.com Overriding SIP cause 503 with 503 from the other leg
2009-06-11 12:14:46.152178 [DEBUG] mod_sofia.c:338 Channel sofia/external/6473671811@sip.gafachi.com hanging up, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:46 sofia/external/6473671811@sip.gafachi.com Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:433 (sofia/external/6473671811@sip.gafachi.com) State HANGUP going to sleep
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:475 (sofia/external/6473671811@sip.gafachi.com) State Change CS_HANGUP -> CS_REPORTING
2009-06-11 12:14:46.152178 [DEBUG] switch_core_session.c:933 Send signal sofia/external/6473671811@sip.gafachi.com [BREAK]
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:397 (sofia/external/6473671811@sip.gafachi.com) Running State Change CS_REPORTING
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:53 sofia/external/6473671811@sip.gafachi.com Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:607 (sofia/external/6473671811@sip.gafachi.com) State REPORTING going to sleep
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:410 (sofia/external/6473671811@sip.gafachi.com) State Change CS_REPORTING -> CS_DESTROY
2009-06-11 12:14:46.152178 [DEBUG] switch_core_session.c:1067 Session 5 (sofia/external/6473671811@sip.gafachi.com) Locked, Waiting on external entities
2009-06-11 12:14:46.152178 [NOTICE] switch_core_session.c:1085 Session 5 (sofia/external/6473671811@sip.gafachi.com) Ended
2009-06-11 12:14:46.152178 [NOTICE] switch_core_session.c:1087 Close Channel sofia/external/6473671811@sip.gafachi.com [CS_DESTROY]
2009-06-11 12:14:46.152178 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY
2009-06-11 12:14:46.152178 [DEBUG] mod_sofia.c:255 sofia/external/6473671811@sip.gafachi.com SOFIA DESTROY
2009-06-11 12:14:46.157559 [DEBUG] switch_core_state_machine.c:60 sofia/external/6473671811@sip.gafachi.com Standard DESTROY
2009-06-11 12:14:46.157559 [DEBUG] switch_core_state_machine.c:559 (sofia/external/6473671811@sip.gafachi.com) State DESTROY going to sleep