EXECUTE portaudio/5000 bridge(sofia/gateway/sip.nexmo.com/19818753995)
2014-11-06 11:05:16.228234 [DEBUG] switch_channel.c:1766 (portaudio/5000) Callst
ate Change ACTIVE -> RING_WAIT
2014-11-06 11:05:16.228234 [DEBUG] switch_ivr_originate.c:2079 Parsing global va
riables
2014-11-06 11:05:16.228234 [NOTICE] switch_channel.c:1053 New Channel sofia/exte
rnal/19818753995 [77faaf98-1ad1-42bd-886f-82bec668772a]
2014-11-06 11:05:16.228234 [DEBUG] mod_sofia.c:4565 (sofia/external/19818753995)
 State Change CS_NEW -> CS_INIT
2014-11-06 11:05:16.228234 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al/19818753995) Running State Change CS_INIT
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:510 (sofia/extern
al/19818753995) State INIT
2014-11-06 11:05:16.228234 [DEBUG] mod_sofia.c:87 sofia/external/19818753995 SOF
IA INIT
2014-11-06 11:05:16.228234 [DEBUG] sofia_glue.c:1226 sofia/external/19818753995
sending invite version: 1.5.12b  64bit
Local SDP:
v=0
o=FreeSWITCH 1415272186 1415272187 IN IP4 192.168.1.140
s=FreeSWITCH
c=IN IP4 192.168.1.140
t=0 0
m=audio 28530 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-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:40 sofia/external
/19818753995 Standard INIT
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:48 (sofia/externa
l/19818753995) State Change CS_INIT -> CS_ROUTING
2014-11-06 11:05:16.228234 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:510 (sofia/extern
al/19818753995) State INIT going to sleep
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al/19818753995) Running State Change CS_ROUTING
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:526 (sofia/extern
al/19818753995) State ROUTING
2014-11-06 11:05:16.228234 [DEBUG] mod_sofia.c:123 sofia/external/19818753995 SO
FIA ROUTING
2014-11-06 11:05:16.228234 [DEBUG] switch_ivr_originate.c:67 (sofia/external/198
18753995) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2014-11-06 11:05:16.228234 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:526 (sofia/extern
al/19818753995) State ROUTING going to sleep
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al/19818753995) Running State Change CS_CONSUME_MEDIA
2014-11-06 11:05:16.228234 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:16.228234 [DEBUG] sofia.c:6364 Channel sofia/external/198187539
95 entering state [calling][0]
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:545 (sofia/extern
al/19818753995) State CONSUME_MEDIA
2014-11-06 11:05:16.228234 [DEBUG] switch_core_state_machine.c:545 (sofia/extern
al/19818753995) State CONSUME_MEDIA going to sleep
2014-11-06 11:05:17.628314 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:17.628314 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:17.628314 [DEBUG] sofia.c:6364 Channel sofia/external/198187539
95 entering state [calling][0]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1052 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] sofia.c:6364 Channel sofia/external/198187539
95 entering state [terminated][904]
2014-11-06 11:05:18.068339 [NOTICE] sofia.c:7247 Hangup sofia/external/198187539
95 [CS_CONSUME_MEDIA] [NORMAL_UNSPECIFIED]
2014-11-06 11:05:18.068339 [DEBUG] switch_channel.c:3218 Send signal sofia/exter
nal/19818753995 [KILL]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al/19818753995) Running State Change CS_HANGUP
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:733 (sofia/extern
al/19818753995) Callstate Change DOWN -> HANGUP
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:735 (sofia/extern
al/19818753995) State HANGUP
2014-11-06 11:05:18.068339 [DEBUG] mod_sofia.c:413 Channel sofia/external/198187
53995 hanging up, cause: NORMAL_UNSPECIFIED
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:58 sofia/external
/19818753995 Standard HANGUP, cause: NORMAL_UNSPECIFIED
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:735 (sofia/extern
al/19818753995) State HANGUP going to sleep
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:502 (sofia/extern
al/19818753995) State Change CS_HANGUP -> CS_REPORTING
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:470 (sofia/extern
al/19818753995) Running State Change CS_REPORTING
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:821 (sofia/extern
al/19818753995) State REPORTING
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:102 sofia/externa
l/19818753995 Standard REPORTING, cause: NORMAL_UNSPECIFIED
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:821 (sofia/extern
al/19818753995) State REPORTING going to sleep
2014-11-06 11:05:18.068339 [DEBUG] switch_core_state_machine.c:496 (sofia/extern
al/19818753995) State Change CS_REPORTING -> CS_DESTROY
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1387 Send signal sofia/
external/19818753995 [BREAK]
2014-11-06 11:05:18.068339 [DEBUG] switch_core_session.c:1614 Session 2 (sofia/e
xternal/19818753995) Locked, Waiting on external entities
2014-11-06 11:05:18.088340 [DEBUG] switch_ivr_originate.c:3695 Originate Resulte
d in Error Cause: 31 [NORMAL_UNSPECIFIED]
2014-11-06 11:05:18.088340 [DEBUG] switch_channel.c:1979 (portaudio/5000) Callst
ate Change RING_WAIT -> ACTIVE
2014-11-06 11:05:18.088340 [INFO] mod_dptools.c:3234 Originate Failed.  Cause: N
ORMAL_UNSPECIFIED
2014-11-06 11:05:18.088340 [NOTICE] switch_channel.c:4677 Hangup portaudio/5000
[CS_EXECUTE] [NORMAL_UNSPECIFIED]
2014-11-06 11:05:18.088340 [DEBUG] switch_channel.c:3218 Send signal portaudio/5
000 [KILL]
2014-11-06 11:05:18.088340 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-11-06 11:05:18.088340 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-11-06 11:05:18.088340 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-11-06 11:05:18.088340 [DEBUG] switch_core_session.c:2887 portaudio/5000 ski
p receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:533 (portaudio/50
00) State EXECUTE going to sleep
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:470 (portaudio/50
00) Running State Change CS_HANGUP
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:733 (portaudio/50
00) Callstate Change ACTIVE -> HANGUP
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:735 (portaudio/50
00) State HANGUP
2014-11-06 11:05:18.088340 [NOTICE] switch_core_session.c:1632 Session 2 (sofia/
external/19818753995) Ended
2014-11-06 11:05:18.088340 [NOTICE] switch_core_session.c:1636 Close Channel sof
ia/external/19818753995 [CS_DESTROY]
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:624 (sofia/extern
al/19818753995) Running State Change CS_DESTROY
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:634 (sofia/extern
al/19818753995) State DESTROY
2014-11-06 11:05:18.088340 [DEBUG] mod_sofia.c:323 sofia/external/19818753995 SO
FIA DESTROY
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:109 sofia/externa
l/19818753995 Standard DESTROY
2014-11-06 11:05:18.088340 [DEBUG] switch_core_state_machine.c:634 (sofia/extern
al/19818753995) State DESTROY going to sleep
2014-11-06 11:05:18.648372 [DEBUG] mod_PortAudio.c:781 portaudio/5000 CHANNEL HA
NGUP
2014-11-06 11:05:18.648372 [DEBUG] switch_core_state_machine.c:58 portaudio/5000
 Standard HANGUP, cause: NORMAL_UNSPECIFIED
2014-11-06 11:05:18.648372 [DEBUG] switch_core_state_machine.c:735 (portaudio/50
00) State HANGUP going to sleep
2014-11-06 11:05:18.648372 [DEBUG] switch_core_state_machine.c:502 (portaudio/50
00) State Change CS_HANGUP -> CS_REPORTING
2014-11-06 11:05:18.648372 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-11-06 11:05:18.648372 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-11-06 11:05:18.648372 [DEBUG] switch_core_state_machine.c:470 (portaudio/50
00) Running State Change CS_REPORTING
2014-11-06 11:05:18.648372 [DEBUG] switch_core_state_machine.c:821 (portaudio/50
00) State REPORTING
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:102 portaudio/500
0 Standard REPORTING, cause: NORMAL_UNSPECIFIED
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:821 (portaudio/50
00) State REPORTING going to sleep
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:496 (portaudio/50
00) State Change CS_REPORTING -> CS_DESTROY
2014-11-06 11:05:18.668373 [DEBUG] switch_core_session.c:1387 Send signal portau
dio/5000 [BREAK]
2014-11-06 11:05:18.668373 [DEBUG] mod_PortAudio.c:801 portaudio/5000 CHANNEL KI
LL
2014-11-06 11:05:18.668373 [DEBUG] switch_core_session.c:1614 Session 1 (portaud
io/5000) Locked, Waiting on external entities
2014-11-06 11:05:18.668373 [NOTICE] switch_core_session.c:1632 Session 1 (portau
dio/5000) Ended
2014-11-06 11:05:18.668373 [NOTICE] switch_core_session.c:1636 Close Channel por
taudio/5000 [CS_DESTROY]
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:624 (portaudio/50
00) Running State Change CS_DESTROY
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:634 (portaudio/50
00) State DESTROY
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:109 portaudio/500
0 Standard DESTROY
2014-11-06 11:05:18.668373 [DEBUG] switch_core_state_machine.c:634 (portaudio/50
00) State DESTROY going to sleep