Dialplan: portaudio/5000 parsing [default->park] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [park] source(mod_portaudio) =~ /mod_sofia
/ break=on-false
Dialplan: portaudio/5000 parsing [default->unpark] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [unpark] source(mod_portaudio) =~ /mod_sof
ia/ break=on-false
Dialplan: portaudio/5000 parsing [default->wait] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [wait] destination_number(919818753995) =~
 /^wait$/ break=on-false
Dialplan: portaudio/5000 parsing [default->fax_receive] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [fax_receive] destination_number(919818753
995) =~ /^9178$/ break=on-false
Dialplan: portaudio/5000 parsing [default->fax_transmit] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [fax_transmit] destination_number(91981875
3995) =~ /^9179$/ break=on-false
Dialplan: portaudio/5000 parsing [default->ringback_180] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [ringback_180] destination_number(91981875
3995) =~ /^9180$/ break=on-false
Dialplan: portaudio/5000 parsing [default->ringback_183_uk_ring] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [ringback_183_uk_ring] destination_number(
919818753995) =~ /^9181$/ break=on-false
Dialplan: portaudio/5000 parsing [default->ringback_183_music_ring] continue=fal
se
Dialplan: portaudio/5000 Regex (FAIL) [ringback_183_music_ring] destination_numb
er(919818753995) =~ /^9182$/ break=on-false
Dialplan: portaudio/5000 parsing [default->ringback_post_answer_uk_ring] continu
e=false
Dialplan: portaudio/5000 Regex (FAIL) [ringback_post_answer_uk_ring] destination
_number(919818753995) =~ /^9183$/ break=on-false
Dialplan: portaudio/5000 parsing [default->ringback_post_answer_music] continue=
false
Dialplan: portaudio/5000 Regex (FAIL) [ringback_post_answer_music] destination_n
umber(919818753995) =~ /^9184$/ break=on-false
Dialplan: portaudio/5000 parsing [default->ClueCon] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [ClueCon] destination_number(919818753995)
 =~ /^9191$/ break=on-false
Dialplan: portaudio/5000 parsing [default->show_info] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [show_info] destination_number(91981875399
5) =~ /^9192$/ break=on-false
Dialplan: portaudio/5000 parsing [default->video_record] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [video_record] destination_number(91981875
3995) =~ /^9193$/ break=on-false
Dialplan: portaudio/5000 parsing [default->video_playback] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [video_playback] destination_number(919818
753995) =~ /^9194$/ break=on-false
Dialplan: portaudio/5000 parsing [default->delay_echo] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [delay_echo] destination_number(9198187539
95) =~ /^9195$/ break=on-false
Dialplan: portaudio/5000 parsing [default->echo] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [echo] destination_number(919818753995) =~
 /^9196$/ break=on-false
Dialplan: portaudio/5000 parsing [default->milliwatt] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [milliwatt] destination_number(91981875399
5) =~ /^9197$/ break=on-false
Dialplan: portaudio/5000 parsing [default->tone_stream] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [tone_stream] destination_number(919818753
995) =~ /^9198$/ break=on-false
Dialplan: portaudio/5000 parsing [default->zrtp_enrollement] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [zrtp_enrollement] destination_number(9198
18753995) =~ /^9787$/ break=on-false
Dialplan: portaudio/5000 parsing [default->hold_music] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [hold_music] destination_number(9198187539
95) =~ /^9664$/ break=on-false
Dialplan: portaudio/5000 parsing [default->laugh break] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [laugh break] destination_number(919818753
995) =~ /^9386$/ break=on-false
Dialplan: portaudio/5000 parsing [default->101] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [101] destination_number(919818753995) =~
/^101$/ break=on-false
Dialplan: portaudio/5000 parsing [default->pizza_demo] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [pizza_demo] destination_number(9198187539
95) =~ /^(pizza|74992)$/ break=on-false
Dialplan: portaudio/5000 parsing [default->Talking Clock Time] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [Talking Clock Time] destination_number(91
9818753995) =~ /^9170$/ break=on-false
Dialplan: portaudio/5000 parsing [default->Talking Clock Date] continue=false
Dialplan: portaudio/5000 Regex (FAIL) [Talking Clock Date] destination_number(91
9818753995) =~ /^9171$/ break=on-false
Dialplan: portaudio/5000 parsing [default->Talking Clock Date and Time] continue
=false
Dialplan: portaudio/5000 Regex (FAIL) [Talking Clock Date and Time] destination_
number(919818753995) =~ /^9172$/ break=on-false
Dialplan: portaudio/5000 parsing [default->Dial Out Custom Gateway] continue=fal
se
Dialplan: portaudio/5000 Regex (PASS) [Dial Out Custom Gateway] destination_numb
er(919818753995) =~ /^9(1\d{10})$/ break=on-false
Dialplan: portaudio/5000 Action set(effective_caller_id_number=${outbound_caller
_id_number})
Dialplan: portaudio/5000 Action set(effective_caller_id_name=${outbound_caller_i
d_name})
Dialplan: portaudio/5000 Action bridge(sofia/gateway/192.168.1.140/19818753995)

2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:214 (portaudio/50
00) State Change CS_ROUTING -> CS_EXECUTE
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:526 (portaudio/50
00) State ROUTING going to sleep
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:470 (portaudio/50
00) Running State Change CS_EXECUTE
2014-10-27 16:54:01.212343 [DEBUG] switch_channel.c:2182 (portaudio/5000) Callst
ate Change RINGING -> ACTIVE
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:533 (portaudio/50
00) State EXECUTE
2014-10-27 16:54:01.212343 [DEBUG] mod_PortAudio.c:433 portaudio/5000 CHANNEL EX
ECUTE
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:256 portaudio/500
0 Standard EXECUTE
EXECUTE portaudio/5000 set(open=true)
2014-10-27 16:54:01.212343 [DEBUG] mod_dptools.c:1435 portaudio/5000 SET [open]=
[true]
EXECUTE portaudio/5000 set(effective_caller_id_number=)
2014-10-27 16:54:01.212343 [DEBUG] mod_dptools.c:1435 portaudio/5000 SET [effect
ive_caller_id_number]=[UNDEF]
EXECUTE portaudio/5000 set(effective_caller_id_name=)
2014-10-27 16:54:01.212343 [DEBUG] mod_dptools.c:1435 portaudio/5000 SET [effect
ive_caller_id_name]=[UNDEF]
EXECUTE portaudio/5000 bridge(sofia/gateway/192.168.1.140/19818753995)
2014-10-27 16:54:01.212343 [DEBUG] switch_channel.c:1766 (portaudio/5000) Callst
ate Change ACTIVE -> RING_WAIT
2014-10-27 16:54:01.212343 [DEBUG] switch_ivr_originate.c:2079 Parsing global va
riables
2014-10-27 16:54:01.212343 [NOTICE] switch_channel.c:1053 New Channel sofia/exte
rnal-ipv6/19818753995 [9cd76fde-ebee-4efa-bc76-b3d9e35a56f2]
2014-10-27 16:54:01.212343 [DEBUG] mod_sofia.c:4565 (sofia/external-ipv6/1981875
3995) State Change CS_NEW -> CS_INIT
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al-ipv6/19818753995) Running State Change CS_INIT
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:510 (sofia/extern
al-ipv6/19818753995) State INIT
2014-10-27 16:54:01.212343 [DEBUG] mod_sofia.c:87 sofia/external-ipv6/1981875399
5 SOFIA INIT
2014-10-27 16:54:01.212343 [DEBUG] sofia_glue.c:1226 sofia/external-ipv6/1981875
3995 sending invite version: 1.5.12b  64bit
Local SDP:
v=0
o=FreeSWITCH 1414432819 1414432820 IN IP6 2001:0:9d38:90d7:306e:1611:3f57:fe73
s=FreeSWITCH
c=IN IP6 2001:0:9d38:90d7:306e:1611:3f57:fe73
t=0 0
m=audio 21222 RTP/AVP 98 0 8 3 101 13
a=rtpmap:98 L16/48000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:40 sofia/external
-ipv6/19818753995 Standard INIT
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:48 (sofia/externa
l-ipv6/19818753995) State Change CS_INIT -> CS_ROUTING
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:510 (sofia/extern
al-ipv6/19818753995) State INIT going to sleep
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al-ipv6/19818753995) Running State Change CS_ROUTING
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] sofia.c:6364 Channel sofia/external-ipv6/1981
8753995 entering state [calling][0]
2014-10-27 16:54:01.212343 [DEBUG] sofia.c:6364 Channel sofia/external-ipv6/1981
8753995 entering state [terminated][503]
2014-10-27 16:54:01.212343 [NOTICE] sofia.c:7247 Hangup sofia/external-ipv6/1981
8753995 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2014-10-27 16:54:01.212343 [DEBUG] switch_channel.c:3218 Send signal sofia/exter
nal-ipv6/19818753995 [KILL]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:526 (sofia/extern
al-ipv6/19818753995) State ROUTING
2014-10-27 16:54:01.212343 [DEBUG] mod_sofia.c:123 sofia/external-ipv6/198187539
95 SOFIA ROUTING
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:526 (sofia/extern
al-ipv6/19818753995) State ROUTING going to sleep
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al-ipv6/19818753995) Running State Change CS_HANGUP
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:733 (sofia/extern
al-ipv6/19818753995) Callstate Change DOWN -> HANGUP
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:735 (sofia/extern
al-ipv6/19818753995) State HANGUP
2014-10-27 16:54:01.212343 [DEBUG] mod_sofia.c:413 Channel sofia/external-ipv6/1
9818753995 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:58 sofia/external
-ipv6/19818753995 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:735 (sofia/extern
al-ipv6/19818753995) State HANGUP going to sleep
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:502 (sofia/extern
al-ipv6/19818753995) State Change CS_HANGUP -> CS_REPORTING
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al-ipv6/19818753995) Running State Change CS_REPORTING
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:821 (sofia/extern
al-ipv6/19818753995) State REPORTING
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:102 sofia/externa
l-ipv6/19818753995 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:821 (sofia/extern
al-ipv6/19818753995) State REPORTING going to sleep
2014-10-27 16:54:01.212343 [DEBUG] switch_core_state_machine.c:496 (sofia/extern
al-ipv6/19818753995) State Change CS_REPORTING -> CS_DESTROY
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external-ipv6/19818753995 [BREAK]
2014-10-27 16:54:01.212343 [DEBUG] switch_core_session.c:1614 Session 3 (sofia/e
xternal-ipv6/19818753995) Locked, Waiting on external entities
2014-10-27 16:54:01.232344 [DEBUG] switch_ivr_originate.c:3695 Originate Resulte
d in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2014-10-27 16:54:01.232344 [DEBUG] switch_channel.c:1979 (portaudio/5000) Callst
ate Change RING_WAIT -> ACTIVE
2014-10-27 16:54:01.232344 [INFO] mod_dptools.c:3234 Originate Failed.  Cause: N
ORMAL_TEMPORARY_FAILURE
2014-10-27 16:54:01.232344 [NOTICE] switch_core_session.c:1632 Session 3 (sofia/
external-ipv6/19818753995) Ended
2014-10-27 16:54:01.232344 [NOTICE] switch_core_session.c:1636 Close Channel sof
ia/external-ipv6/19818753995 [CS_DESTROY]
2014-10-27 16:54:01.232344 [NOTICE] switch_channel.c:4677 Hangup portaudio/5000
[CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:624 (sofia/extern
al-ipv6/19818753995) Running State Change CS_DESTROY
2014-10-27 16:54:01.232344 [DEBUG] switch_channel.c:3218 Send signal portaudio/5
000 [KILL]
2014-10-27 16:54:01.232344 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-10-27 16:54:01.232344 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:634 (sofia/extern
al-ipv6/19818753995) State DESTROY
2014-10-27 16:54:01.232344 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-10-27 16:54:01.232344 [DEBUG] mod_sofia.c:323 sofia/external-ipv6/198187539
95 SOFIA DESTROY
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:109 sofia/externa
l-ipv6/19818753995 Standard DESTROY
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:634 (sofia/extern
al-ipv6/19818753995) State DESTROY going to sleep
2014-10-27 16:54:01.232344 [DEBUG] switch_core_session.c:2887 portaudio/5000 ski
p receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:533 (portaudio/50
00) State EXECUTE going to sleep
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:470 (portaudio/50
00) Running State Change CS_HANGUP
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:733 (portaudio/50
00) Callstate Change ACTIVE -> HANGUP
2014-10-27 16:54:01.232344 [DEBUG] switch_core_state_machine.c:735 (portaudio/50
00) State HANGUP
2014-10-27 16:54:01.752374 [DEBUG] mod_PortAudio.c:781 portaudio/5000 CHANNEL HA
NGUP
2014-10-27 16:54:01.752374 [DEBUG] switch_core_state_machine.c:58 portaudio/5000
 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2014-10-27 16:54:01.752374 [DEBUG] switch_core_state_machine.c:735 (portaudio/50
00) State HANGUP going to sleep
2014-10-27 16:54:01.752374 [DEBUG] switch_core_state_machine.c:502 (portaudio/50
00) State Change CS_HANGUP -> CS_REPORTING
2014-10-27 16:54:01.752374 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-10-27 16:54:01.752374 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-10-27 16:54:01.752374 [DEBUG] switch_core_state_machine.c:470 (portaudio/50
00) Running State Change CS_REPORTING
2014-10-27 16:54:01.752374 [DEBUG] switch_core_state_machine.c:821 (portaudio/50
00) State REPORTING
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:102 portaudio/500
0 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:821 (portaudio/50
00) State REPORTING going to sleep
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:496 (portaudio/50
00) State Change CS_REPORTING -> CS_DESTROY
2014-10-27 16:54:01.772375 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-10-27 16:54:01.772375 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-10-27 16:54:01.772375 [DEBUG] switch_core_session.c:1614 Session 2 (portaud
io/5000) Locked, Waiting on external entities
2014-10-27 16:54:01.772375 [NOTICE] switch_core_session.c:1632 Session 2 (portau
dio/5000) Ended
2014-10-27 16:54:01.772375 [NOTICE] switch_core_session.c:1636 Close Channel por
taudio/5000 [CS_DESTROY]
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:624 (portaudio/50
00) Running State Change CS_DESTROY
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:634 (portaudio/50
00) State DESTROY
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:109 portaudio/500
0 Standard DESTROY
2014-10-27 16:54:01.772375 [DEBUG] switch_core_state_machine.c:634 (portaudio/50
00) State DESTROY going to sleep