2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 192.168.0.0/16 (deny) [] to list wan.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:970 Created ip list nat.auto default (deny) 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:972 Adding 10.10.2.3/255.255.0.0 (deny) to list nat.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 10.0.0.0/8 (allow) [] to list nat.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 172.16.0.0/12 (allow) [] to list nat.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 192.168.0.0/16 (allow) [] to list nat.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:981 Created ip list loopback.auto default (deny) 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 127.0.0.0/8 (allow) [] to list loopback.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:987 Created ip list localnet.auto default (deny) 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:990 Adding 10.10.2.3/255.255.0.0 (allow) to list localnet.auto 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 192.168.42.0/24 (deny) [] to list lan 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:1086 Adding 192.168.42.0/24 (deny) to list lan 2011-07-28 10:09:39.924231 [DEBUG] mod_event_socket.c:2646 Socket up listening on 127.0.0.1:8021 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 192.168.42.42/32 (allow) [] to list lan 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:1086 Adding 192.168.42.42/32 (allow) to list lan 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 20.2.200.20/32 (allow) [] to list custom_carrier 2011-07-28 10:09:39.924231 [NOTICE] switch_core.c:1086 Adding 20.2.200.20/32 (allow) to list custom_carrier 2011-07-28 10:09:39.924231 [NOTICE] switch_utils.c:195 Adding 20.2.200.20/32 (allow) [1001@10.10.2.3] to list domains 2011-07-28 10:10:24.199658 [DEBUG] sofia.c:5900 IP 10.10.2.3 Rejected by acl "domains". Falling back to Digest auth. 2011-07-28 10:10:24.260664 [DEBUG] sofia.c:5900 IP 10.10.2.3 Rejected by acl "domains". Falling back to Digest auth. 2011-07-28 10:10:24.317669 [NOTICE] switch_channel.c:675 New Channel sofia/internal/1001@10.10.2.3:5070 [0f6116fe-ddc0-4f71-a6f7-5efca43d7dff] 2011-07-28 10:10:24.323670 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_NEW 2011-07-28 10:10:24.323670 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/1001@10.10.2.3:5070) State NEW 2011-07-28 10:10:24.376675 [DEBUG] sofia.c:4200 Channel sofia/internal/1001@10.10.2.3:5070 entering state [received][100] 2011-07-28 10:10:24.376675 [DEBUG] sofia.c:4211 Remote SDP: v=0 o=- 12956346624194657 1 IN IP4 10.10.2.3 s=CounterPath X-Lite 4.0 c=IN IP4 10.10.2.3 t=0 0 a=ice-ufrag:3b6883 a=ice-pwd:9be9ba15c4e904298e5b47f96429ef1b m=audio 58268 RTP/AVP 107 0 8 101 a=rtpmap:107 BV32/16000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=candidate:1 1 UDP 659136 10.10.2.3 58268 typ host a=candidate:1 2 UDP 659134 10.10.2.3 58269 typ host 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [BV32:107:16000:20]/[G7221:115:32000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [BV32:107:16000:20]/[G7221:107:16000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [BV32:107:16000:20]/[G722:9:8000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [BV32:107:16000:20]/[PCMU:0:8000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [BV32:107:16000:20]/[PCMA:8:8000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [BV32:107:16000:20]/[GSM:3:8000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [PCMU:0:8000:20]/[G7221:115:32000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [PCMU:0:8000:20]/[G7221:107:16000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [PCMU:0:8000:20]/[G722:9:8000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3671 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20] 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:2376 Set Codec sofia/internal/1001@10.10.2.3:5070 PCMU/8000 20 ms 160 samples 2011-07-28 10:10:24.377675 [DEBUG] sofia_glue.c:3610 Set 2833 dtmf send/recv payload to 101 2011-07-28 10:10:24.377675 [DEBUG] sofia.c:4357 (sofia/internal/1001@10.10.2.3:5070) State Change CS_NEW -> CS_INIT 2011-07-28 10:10:24.377675 [DEBUG] switch_core_session.c:1022 Send signal sofia/internal/1001@10.10.2.3:5070 [BREAK] 2011-07-28 10:10:24.378676 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_INIT 2011-07-28 10:10:24.378676 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/1001@10.10.2.3:5070) State INIT 2011-07-28 10:10:24.378676 [DEBUG] mod_sofia.c:83 sofia/internal/1001@10.10.2.3:5070 SOFIA INIT 2011-07-28 10:10:24.378676 [DEBUG] mod_sofia.c:117 (sofia/internal/1001@10.10.2.3:5070) State Change CS_INIT -> CS_ROUTING 2011-07-28 10:10:24.378676 [DEBUG] switch_core_session.c:1022 Send signal sofia/internal/1001@10.10.2.3:5070 [BREAK] 2011-07-28 10:10:24.378676 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/1001@10.10.2.3:5070) State INIT going to sleep 2011-07-28 10:10:24.378676 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_ROUTING 2011-07-28 10:10:24.378676 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/1001@10.10.2.3:5070) State ROUTING 2011-07-28 10:10:24.378676 [DEBUG] mod_sofia.c:140 sofia/internal/1001@10.10.2.3:5070 SOFIA ROUTING 2011-07-28 10:10:24.378676 [DEBUG] switch_core_state_machine.c:77 sofia/internal/1001@10.10.2.3:5070 Standard ROUTING 2011-07-28 10:10:24.378676 [INFO] mod_dialplan_xml.c:331 Processing 1001->914152484142 in context default Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->unloop] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1001@10.10.2.3:5070 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 Action set(open=true) Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1001@10.10.2.3:5070 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [global-intercept] destination_number(914152484142) =~ /^\*886$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [group-intercept] destination_number(914152484142) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [intercept-ext] destination_number(914152484142) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->redial] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [redial] destination_number(914152484142) =~ /^(redial|\*870)$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->global] continue=true Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1001@10.10.2.3:5070 Absolute Condition [global] Dialplan: sofia/internal/1001@10.10.2.3:5070 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1001@10.10.2.3:5070 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1001@10.10.2.3:5070 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1001@10.10.2.3:5070 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [snom-demo-2] destination_number(914152484142) =~ /^\*9001$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [snom-demo-1] destination_number(914152484142) =~ /^\*9000$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [eavesdrop] destination_number(914152484142) =~ /^\*88(\d{2,7})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [eavesdrop] destination_number(914152484142) =~ /^\*779$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->call_privacy] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [call_privacy] destination_number(914152484142) =~ /^\*67(\d+)$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->call_return] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [call_return] destination_number(914152484142) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->del-group] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [del-group] destination_number(914152484142) =~ /^\*\*80(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->add-group] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [add-group] destination_number(914152484142) =~ /^\*\*81(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [call-group-simo] destination_number(914152484142) =~ /^\*\*82(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [call-group-order] destination_number(914152484142) =~ /^\*83(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [extension-intercom] destination_number(914152484142) =~ /^\*8(\d{2,7})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [Local_Extension_Skinny] destination_number(914152484142) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->send_to_voicemail] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [send_to_voicemail] destination_number(914152484142) =~ /^\*99(\d{2,7})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (FAIL) [pizza_demo] destination_number(914152484142) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 parsing [default->Dial Out Custom Gateway] continue=false Dialplan: sofia/internal/1001@10.10.2.3:5070 Regex (PASS) [Dial Out Custom Gateway] destination_number(914152484142) =~ /^9(1\d{10})$/ break=on-false Dialplan: sofia/internal/1001@10.10.2.3:5070 Action bridge(sofia/gateway/custom_carrier/14152484142) 2011-07-28 10:10:24.380676 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/1001@10.10.2.3:5070) State Change CS_ROUTING -> CS_EXECUTE 2011-07-28 10:10:24.380676 [DEBUG] switch_core_session.c:1022 Send signal sofia/internal/1001@10.10.2.3:5070 [BREAK] 2011-07-28 10:10:24.380676 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/1001@10.10.2.3:5070) State ROUTING going to sleep 2011-07-28 10:10:24.380676 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_EXECUTE 2011-07-28 10:10:24.380676 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/1001@10.10.2.3:5070) State EXECUTE 2011-07-28 10:10:24.380676 [DEBUG] mod_sofia.c:233 sofia/internal/1001@10.10.2.3:5070 SOFIA EXECUTE 2011-07-28 10:10:24.380676 [DEBUG] switch_core_state_machine.c:157 sofia/internal/1001@10.10.2.3:5070 Standard EXECUTE EXECUTE sofia/internal/1001@10.10.2.3:5070 set(open=true) 2011-07-28 10:10:24.380676 [DEBUG] mod_dptools.c:817 sofia/internal/1001@10.10.2.3:5070 SET [open]=[true] EXECUTE sofia/internal/1001@10.10.2.3:5070 hash(insert/10.10.2.3-spymap/1001/0f6116fe-ddc0-4f71-a6f7-5efca43d7dff) EXECUTE sofia/internal/1001@10.10.2.3:5070 hash(insert/10.10.2.3-last_dial/1001/914152484142) EXECUTE sofia/internal/1001@10.10.2.3:5070 hash(insert/10.10.2.3-last_dial/global/0f6116fe-ddc0-4f71-a6f7-5efca43d7dff) EXECUTE sofia/internal/1001@10.10.2.3:5070 set(RFC2822_DATE=Thu, 28 Jul 2011 10:10:24 Pacific Daylight Time) 2011-07-28 10:10:24.382676 [DEBUG] mod_dptools.c:817 sofia/internal/1001@10.10.2.3:5070 SET [RFC2822_DATE]=[Thu, 28 Jul 2011 10:10:24 Pacific Daylight Time] EXECUTE sofia/internal/1001@10.10.2.3:5070 bridge(sofia/gateway/custom_carrier/14152484142) 2011-07-28 10:10:24.382676 [NOTICE] switch_channel.c:675 New Channel sofia/external/14152484142 [6c372374-70b9-4b14-b502-7d39d52be62f] 2011-07-28 10:10:24.382676 [DEBUG] mod_sofia.c:3695 (sofia/external/14152484142) State Change CS_NEW -> CS_INIT 2011-07-28 10:10:24.382676 [DEBUG] switch_core_session.c:1022 Send signal sofia/external/14152484142 [BREAK] 2011-07-28 10:10:24.385676 [DEBUG] switch_core_state_machine.c:314 (sofia/external/14152484142) Running State Change CS_INIT 2011-07-28 10:10:24.385676 [DEBUG] switch_core_state_machine.c:338 (sofia/external/14152484142) State INIT 2011-07-28 10:10:24.385676 [DEBUG] mod_sofia.c:83 sofia/external/14152484142 SOFIA INIT 2011-07-28 10:10:24.385676 [DEBUG] mod_sofia.c:117 (sofia/external/14152484142) State Change CS_INIT -> CS_ROUTING 2011-07-28 10:10:24.385676 [DEBUG] switch_core_session.c:1022 Send signal sofia/external/14152484142 [BREAK] 2011-07-28 10:10:24.385676 [DEBUG] switch_core_state_machine.c:338 (sofia/external/14152484142) State INIT going to sleep 2011-07-28 10:10:24.385676 [DEBUG] switch_core_state_machine.c:314 (sofia/external/14152484142) Running State Change CS_ROUTING 2011-07-28 10:10:24.385676 [DEBUG] switch_core_state_machine.c:341 (sofia/external/14152484142) State ROUTING 2011-07-28 10:10:24.385676 [DEBUG] mod_sofia.c:140 sofia/external/14152484142 SOFIA ROUTING 2011-07-28 10:10:24.385676 [DEBUG] switch_ivr_originate.c:66 (sofia/external/14152484142) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-07-28 10:10:24.386676 [DEBUG] switch_core_session.c:1022 Send signal sofia/external/14152484142 [BREAK] 2011-07-28 10:10:24.386676 [DEBUG] switch_core_state_machine.c:341 (sofia/external/14152484142) State ROUTING going to sleep 2011-07-28 10:10:24.386676 [DEBUG] switch_core_state_machine.c:314 (sofia/external/14152484142) Running State Change CS_CONSUME_MEDIA 2011-07-28 10:10:24.386676 [DEBUG] switch_core_state_machine.c:360 (sofia/external/14152484142) State CONSUME_MEDIA 2011-07-28 10:10:24.386676 [DEBUG] switch_core_state_machine.c:360 (sofia/external/14152484142) State CONSUME_MEDIA going to sleep 2011-07-28 10:10:24.387676 [DEBUG] sofia.c:4200 Channel sofia/external/14152484142 entering state [calling][0] 2011-07-28 10:10:24.388677 [DEBUG] sofia.c:4200 Channel sofia/external/14152484142 entering state [terminated][503] 2011-07-28 10:10:24.388677 [NOTICE] sofia.c:4836 Hangup sofia/external/14152484142 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2011-07-28 10:10:24.388677 [DEBUG] switch_channel.c:2145 Send signal sofia/external/14152484142 [KILL] 2011-07-28 10:10:24.388677 [DEBUG] switch_core_session.c:1022 Send signal sofia/external/14152484142 [BREAK] 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:314 (sofia/external/14152484142) Running State Change CS_HANGUP 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:498 (sofia/external/14152484142) State HANGUP 2011-07-28 10:10:24.388677 [DEBUG] mod_sofia.c:435 sofia/external/14152484142 Overriding SIP cause 503 with 503 from the other leg 2011-07-28 10:10:24.388677 [DEBUG] mod_sofia.c:441 Channel sofia/external/14152484142 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:46 sofia/external/14152484142 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:498 (sofia/external/14152484142) State HANGUP going to sleep 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:333 (sofia/external/14152484142) State Change CS_HANGUP -> CS_REPORTING 2011-07-28 10:10:24.388677 [DEBUG] switch_core_session.c:1022 Send signal sofia/external/14152484142 [BREAK] 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:314 (sofia/external/14152484142) Running State Change CS_REPORTING 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:589 (sofia/external/14152484142) State REPORTING 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:53 sofia/external/14152484142 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:589 (sofia/external/14152484142) State REPORTING going to sleep 2011-07-28 10:10:24.388677 [DEBUG] switch_core_state_machine.c:327 (sofia/external/14152484142) State Change CS_REPORTING -> CS_DESTROY 2011-07-28 10:10:24.388677 [DEBUG] switch_core_session.c:1022 Send signal sofia/external/14152484142 [BREAK] 2011-07-28 10:10:24.388677 [DEBUG] switch_core_session.c:1170 Session 2 (sofia/external/14152484142) Locked, Waiting on external entities 2011-07-28 10:10:24.389677 [DEBUG] switch_ivr_originate.c:3308 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2011-07-28 10:10:24.389677 [INFO] mod_dptools.c:2356 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.389677 [NOTICE] switch_core_session.c:1188 Session 2 (sofia/external/14152484142) Ended 2011-07-28 10:10:24.389677 [NOTICE] mod_dptools.c:2419 Hangup sofia/internal/1001@10.10.2.3:5070 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2011-07-28 10:10:24.389677 [NOTICE] switch_core_session.c:1190 Close Channel sofia/external/14152484142 [CS_DESTROY] 2011-07-28 10:10:24.389677 [DEBUG] switch_core_state_machine.c:428 (sofia/external/14152484142) Running State Change CS_DESTROY 2011-07-28 10:10:24.389677 [DEBUG] switch_core_state_machine.c:438 (sofia/external/14152484142) State DESTROY 2011-07-28 10:10:24.389677 [DEBUG] switch_channel.c:2145 Send signal sofia/internal/1001@10.10.2.3:5070 [KILL] 2011-07-28 10:10:24.389677 [DEBUG] mod_sofia.c:350 sofia/external/14152484142 SOFIA DESTROY 2011-07-28 10:10:24.389677 [DEBUG] switch_core_session.c:1022 Send signal sofia/internal/1001@10.10.2.3:5070 [BREAK] 2011-07-28 10:10:24.389677 [DEBUG] switch_core_state_machine.c:60 sofia/external/14152484142 Standard DESTROY 2011-07-28 10:10:24.389677 [DEBUG] switch_core_state_machine.c:438 (sofia/external/14152484142) State DESTROY going to sleep 2011-07-28 10:10:24.389677 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/1001@10.10.2.3:5070) State EXECUTE going to sleep 2011-07-28 10:10:24.389677 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_HANGUP 2011-07-28 10:10:24.390677 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1001@10.10.2.3:5070) State HANGUP 2011-07-28 10:10:24.390677 [DEBUG] mod_sofia.c:435 sofia/internal/1001@10.10.2.3:5070 Overriding SIP cause 503 with 503 from the other leg 2011-07-28 10:10:24.390677 [DEBUG] mod_sofia.c:441 Channel sofia/internal/1001@10.10.2.3:5070 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.613699 [DEBUG] mod_sofia.c:503 Responding to INVITE with: 503 2011-07-28 10:10:24.613699 [DEBUG] switch_core_state_machine.c:46 sofia/internal/1001@10.10.2.3:5070 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.613699 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1001@10.10.2.3:5070) State HANGUP going to sleep 2011-07-28 10:10:24.613699 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/1001@10.10.2.3:5070) State Change CS_HANGUP -> CS_REPORTING 2011-07-28 10:10:24.613699 [DEBUG] switch_core_session.c:1022 Send signal sofia/internal/1001@10.10.2.3:5070 [BREAK] 2011-07-28 10:10:24.613699 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_REPORTING 2011-07-28 10:10:24.613699 [DEBUG] switch_core_state_machine.c:589 (sofia/internal/1001@10.10.2.3:5070) State REPORTING 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:53 sofia/internal/1001@10.10.2.3:5070 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:589 (sofia/internal/1001@10.10.2.3:5070) State REPORTING going to sleep 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/1001@10.10.2.3:5070) State Change CS_REPORTING -> CS_DESTROY 2011-07-28 10:10:24.614699 [DEBUG] switch_core_session.c:1022 Send signal sofia/internal/1001@10.10.2.3:5070 [BREAK] 2011-07-28 10:10:24.614699 [DEBUG] switch_core_session.c:1170 Session 1 (sofia/internal/1001@10.10.2.3:5070) Locked, Waiting on external entities 2011-07-28 10:10:24.614699 [NOTICE] switch_core_session.c:1188 Session 1 (sofia/internal/1001@10.10.2.3:5070) Ended 2011-07-28 10:10:24.614699 [NOTICE] switch_core_session.c:1190 Close Channel sofia/internal/1001@10.10.2.3:5070 [CS_DESTROY] 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:428 (sofia/internal/1001@10.10.2.3:5070) Running State Change CS_DESTROY 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:438 (sofia/internal/1001@10.10.2.3:5070) State DESTROY 2011-07-28 10:10:24.614699 [DEBUG] mod_sofia.c:350 sofia/internal/1001@10.10.2.3:5070 SOFIA DESTROY 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@10.10.2.3:5070 Standard DESTROY 2011-07-28 10:10:24.614699 [DEBUG] switch_core_state_machine.c:438 (sofia/internal/1001@10.10.2.3:5070) State DESTROY going to sleep