freeswitch@a> freeswitch@a> bgapi originate skypopen/ANY/echo123 5000 +OK Job-UUID: 7bed9a35-afb5-4734-95ee-4187e8a5e0a3 2010-09-25 01:29:49.325133 [DEBUG] mod_skypopen.c:1110 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1110 ][none ][-1,-1,-1] 1 SESSION_REQUEST 5bc74275-7d0f-4739-9174-58765644c73c 2010-09-25 01:29:49.325133 [DEBUG] mod_skypopen.c:1125 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1125 ][none ][-1,-1,-1] Finding one available skype interface RR 2010-09-25 01:29:49.325133 [DEBUG] mod_skypopen.c:2172 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 2172 ][interface1][-1, 0, 0] returning as available skype interface name: interface1, state: 0 callflow: 0 2010-09-25 01:29:49.325133 [DEBUG] mod_skypopen.c:259 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 259 ][interface1][-1, 9, 0] skypopen_tech_init SUCCESS 2010-09-25 01:29:49.325133 [NOTICE] switch_channel.c:779 New Channel skypopen/ANY/interface1/echo123 [5bc74275-7d0f-4739-9174-58765644c73c] 2010-09-25 01:29:49.325133 [DEBUG] mod_skypopen.c:1216 (skypopen/ANY/interface1/echo123) State Change CS_NEW -> CS_INIT 2010-09-25 01:29:49.325133 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:29:49.325133 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 9, 0] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:29:49.325133 [DEBUG] skypopen_protocol.c:1063 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1063 ][interface1][-1, 9, 0] Calling Skype, rdest is: echo123 2010-09-25 01:29:49.325133 [DEBUG] skypopen_protocol.c:1502 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1502 ][interface1][-1, 9, 0] SENDING: |||CALL echo123|||| freeswitch@ds-99166.ds-10.com> 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_INIT 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:338 (skypopen/ANY/interface1/echo123) State INIT 2010-09-25 01:29:49.329135 [DEBUG] mod_skypopen.c:437 (skypopen/ANY/interface1/echo123) State Change CS_INIT -> CS_ROUTING 2010-09-25 01:29:49.329135 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:29:49.329135 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 9, 0] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:29:49.329135 [DEBUG] mod_skypopen.c:438 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 438 ][interface1][-1, 9, 0] interface1 CHANNEL INIT 5bc74275-7d0f-4739-9174-58765644c73c 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:338 (skypopen/ANY/interface1/echo123) State INIT going to sleep 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_ROUTING 2010-09-25 01:29:49.329135 [DEBUG] switch_channel.c:1517 (skypopen/ANY/interface1/echo123) Callstate Change DOWN -> RINGING 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:341 (skypopen/ANY/interface1/echo123) State ROUTING 2010-09-25 01:29:49.329135 [DEBUG] mod_skypopen.c:555 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 555 ][interface1][-1, 9, 0] interface1 CHANNEL ROUTING 2010-09-25 01:29:49.329135 [DEBUG] switch_ivr_originate.c:66 (skypopen/ANY/interface1/echo123) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2010-09-25 01:29:49.329135 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:29:49.329135 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 9, 0] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:341 (skypopen/ANY/interface1/echo123) State ROUTING going to sleep 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_CONSUME_MEDIA 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:360 (skypopen/ANY/interface1/echo123) State CONSUME_MEDIA 2010-09-25 01:29:49.329135 [DEBUG] mod_skypopen.c:631 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 631 ][interface1][-1, 9, 0] interface1 CHANNEL CONSUME_MEDIA 2010-09-25 01:29:49.329135 [DEBUG] switch_core_state_machine.c:360 (skypopen/ANY/interface1/echo123) State CONSUME_MEDIA going to sleep 2010-09-25 01:29:49.331137 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 9, 0] READING: |||CALL 74 STATUS UNPLACED||| 2010-09-25 01:29:49.331137 [DEBUG] skypopen_protocol.c:666 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 666 ][interface1][-1, 3,22] skype_call: 74 is now UNPLACED 2010-09-25 01:29:49.389135 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 3,22] READING: |||CALL 74 STATUS ROUTING||| 2010-09-25 01:29:49.389135 [DEBUG] skypopen_protocol.c:661 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 661 ][interface1][-1, 3,23] skype_call: 74 is now ROUTING 2010-09-25 01:29:49.663138 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 3,23] READING: |||CALL 74 STATUS RINGING||| 2010-09-25 01:29:49.663138 [DEBUG] skypopen_protocol.c:578 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 578 ][interface1][-1, 6,20] Our remote party in skype_call 74 is RINGING 2010-09-25 01:29:49.663138 [NOTICE] mod_skypopen.c:2071 Ring-Ready skypopen/ANY/interface1/echo123! 2010-09-25 01:29:49.663138 [DEBUG] mod_skypopen.c:2072 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 2072 ][interface1][-1, 6,20] skype_call: REMOTE PARTY RINGING 2010-09-25 01:29:51.561167 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 6,20] READING: |||CALL 74 VAA_INPUT_STATUS FALSE||| 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 6,20] READING: |||CALL 74 STATUS INPROGRESS||| 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:677 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 677 ][interface1][-1, 6,20] skype_call: 74 is now active 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:684 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 684 ][interface1][-1, 5,21] START start_audio_threads 2010-09-25 01:29:51.565166 [DEBUG] mod_skypopen.c:1981 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1981 ][interface1][-1, 5,21] started tcp_srv_thread thread. 2010-09-25 01:29:51.565166 [DEBUG] mod_skypopen.c:1991 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1991 ][interface1][-1, 5,21] started tcp_cli_thread thread. 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:83 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 83 ][interface1][-1, 5,21] Binded! *which_port=32769, tech_pvt->tcp_cli_port=10161, tech_pvt->tcp_srv_port=32769 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:88 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 88 ][interface1][-1, 5,21] 1 SO_RCVBUF is 87380, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:92 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 92 ][interface1][-1, 5,21] 1 SO_SNDBUF is 16384, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:113 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 113 ][interface1][-1, 5,21] 2 SO_RCVBUF is 87380, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:132 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 132 ][interface1][-1, 5,21] 2 SO_SNDBUF is 16384, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:136 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 136 ][interface1][-1, 5,21] TCP_NODELAY is 0 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:143 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 143 ][interface1][-1, 5,21] TCP_NODELAY is 0 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:777 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 777 ][interface1][-1, 5,21] started tcp_srv_thread thread. 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:83 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 83 ][interface1][-1, 5,21] Binded! *which_port=32770, tech_pvt->tcp_cli_port=32770, tech_pvt->tcp_srv_port=32769 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:88 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 88 ][interface1][-1, 5,21] 1 SO_RCVBUF is 87380, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:92 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 92 ][interface1][-1, 5,21] 1 SO_SNDBUF is 16384, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:113 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 113 ][interface1][-1, 5,21] 2 SO_RCVBUF is 87380, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:132 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 132 ][interface1][-1, 5,21] 2 SO_SNDBUF is 16384, size is 4 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:136 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 136 ][interface1][-1, 5,21] TCP_NODELAY is 0 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:143 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 143 ][interface1][-1, 5,21] TCP_NODELAY is 0 2010-09-25 01:29:51.565166 [DEBUG] skypopen_protocol.c:928 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 928 ][interface1][-1, 5,21] started tcp_cli_thread thread. 2010-09-25 01:29:51.669168 [DEBUG] skypopen_protocol.c:1502 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1502 ][interface1][-1, 5,21] SENDING: |||ALTER CALL 74 SET_INPUT PORT="32770"|||| 2010-09-25 01:29:51.671167 [DEBUG] skypopen_protocol.c:957 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 957 ][interface1][-1, 5,21] ACCEPTED here you send me 32770 2010-09-25 01:29:51.671167 [DEBUG] skypopen_protocol.c:962 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 962 ][interface1][-1, 5,21] 4 SO_RCVBUF is 87380, size is 4 2010-09-25 01:29:51.671167 [DEBUG] skypopen_protocol.c:966 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 966 ][interface1][-1, 5,21] 4 SO_SNDBUF is 16384, size is 4 2010-09-25 01:29:51.673169 [DEBUG] skypopen_protocol.c:1502 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1502 ][interface1][-1, 5,21] SENDING: |||#output ALTER CALL 74 SET_OUTPUT PORT="32769"|||| 2010-09-25 01:29:51.675166 [DEBUG] skypopen_protocol.c:1800 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1800 ][interface1][-1, 5,21] Outbound Channel Answered! session_uuid_str=5bc74275-7d0f-4739-9174-58765644c73c 2010-09-25 01:29:51.675166 [DEBUG] switch_channel.c:2590 (skypopen/ANY/interface1/echo123) Callstate Change RINGING -> ACTIVE 2010-09-25 01:29:51.675166 [NOTICE] mod_skypopen.c:2132 Channel [skypopen/ANY/interface1/echo123] has been answered 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:1001 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1001 ][interface1][-1, 5,21] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:1020 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1020 ][interface1][-1, 5,21] Synching audio 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:2140 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 2140 ][interface1][-1, 5,21] outbound_channel_answered! 2010-09-25 01:29:51.675166 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||ALTER CALL 74 SET_INPUT PORT="32770"||| 2010-09-25 01:29:51.675166 [DEBUG] skypopen_protocol.c:806 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 806 ][interface1][-1, 5,21] ACCEPTED here I send you 32769 2010-09-25 01:29:51.675166 [DEBUG] skypopen_protocol.c:811 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 811 ][interface1][-1, 5,21] 3 SO_RCVBUF is 87380, size is 4 2010-09-25 01:29:51.675166 [DEBUG] skypopen_protocol.c:815 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 815 ][interface1][-1, 5,21] 3 SO_SNDBUF is 16384, size is 4 2010-09-25 01:29:51.675166 [DEBUG] skypopen_protocol.c:849 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 849 ][interface1][-1, 5,21] len=320 2010-09-25 01:29:51.675166 [DEBUG] switch_ivr_originate.c:3360 Originate Resulted in Success: [skypopen/ANY/interface1/echo123] 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:1001 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1001 ][interface1][-1, 5,21] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:1020 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1020 ][interface1][-1, 5,21] Synching audio 2010-09-25 01:29:51.675166 [DEBUG] switch_ivr.c:1474 (skypopen/ANY/interface1/echo123) State Change CS_CONSUME_MEDIA -> CS_ROUTING 2010-09-25 01:29:51.675166 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 5,21] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=6 2010-09-25 01:29:51.675166 [DEBUG] switch_core_session.c:666 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:29:51.675166 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 5,21] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:29:51.675166 [NOTICE] switch_ivr.c:1480 Transfer skypopen/ANY/interface1/echo123 to XML[5000@default] 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_ROUTING 2010-09-25 01:29:51.677325 [DEBUG] switch_channel.c:1517 (skypopen/ANY/interface1/echo123) Callstate Change ACTIVE -> RINGING 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:341 (skypopen/ANY/interface1/echo123) State ROUTING 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:555 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 555 ][interface1][-1, 5,21] interface1 CHANNEL ROUTING 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:77 skypopen/ANY/interface1/echo123 Standard ROUTING 2010-09-25 01:29:51.677325 [INFO] mod_dialplan_xml.c:331 Processing <>->5000 in context default Dialplan: skypopen/ANY/interface1/echo123 parsing [default->unloop] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->tod_example] continue=true Dialplan: skypopen/ANY/interface1/echo123 Date/Time Match (FAIL) [tod_example] break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->holiday_example] continue=true Dialplan: skypopen/ANY/interface1/echo123 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->global-intercept] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [global-intercept] destination_number(5000) =~ /^886$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->group-intercept] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [group-intercept] destination_number(5000) =~ /^\*8$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->intercept-ext] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [intercept-ext] destination_number(5000) =~ /^\*\*(\d+)$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->redial] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [redial] destination_number(5000) =~ /^(redial|870)$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->global] continue=true Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: skypopen/ANY/interface1/echo123 Absolute Condition [global] Dialplan: skypopen/ANY/interface1/echo123 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: skypopen/ANY/interface1/echo123 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: skypopen/ANY/interface1/echo123 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: skypopen/ANY/interface1/echo123 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: skypopen/ANY/interface1/echo123 parsing [default->snom-demo-2] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [snom-demo-2] destination_number(5000) =~ /^9001$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->snom-demo-1] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [snom-demo-1] destination_number(5000) =~ /^9000$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->eavesdrop] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [eavesdrop] destination_number(5000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->eavesdrop] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [eavesdrop] destination_number(5000) =~ /^779$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->call_return] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [call_return] destination_number(5000) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->del-group] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [del-group] destination_number(5000) =~ /^80(\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->add-group] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [add-group] destination_number(5000) =~ /^81(\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->call-group-simo] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [call-group-simo] destination_number(5000) =~ /^82(\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->call-group-order] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [call-group-order] destination_number(5000) =~ /^83(\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->extension-intercom] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [extension-intercom] destination_number(5000) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->Local_Extension] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [Local_Extension] destination_number(5000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->Local_Extension_Skinny] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [Local_Extension_Skinny] destination_number(5000) =~ /^(11[01][0-9])$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->group_dial_sales] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [group_dial_sales] destination_number(5000) =~ /^2000$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->group_dial_support] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [group_dial_support] destination_number(5000) =~ /^2001$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->group_dial_billing] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [group_dial_billing] destination_number(5000) =~ /^2002$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->operator] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [operator] destination_number(5000) =~ /^(operator|0)$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->vmain] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [vmain] destination_number(5000) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->sip_uri] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [sip_uri] destination_number(5000) =~ /^sip:(.*)$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->nb_conferences] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [nb_conferences] destination_number(5000) =~ /^(30\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->wb_conferences] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [wb_conferences] destination_number(5000) =~ /^(31\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->uwb_conferences] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [uwb_conferences] destination_number(5000) =~ /^(32\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->cdquality_conferences] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [cdquality_conferences] destination_number(5000) =~ /^(33\d{2})$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(5000) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [mad_boss_intercom] destination_number(5000) =~ /^0911$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [mad_boss_intercom] destination_number(5000) =~ /^0912$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->mad_boss] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (FAIL) [mad_boss] destination_number(5000) =~ /^0913$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 parsing [default->ivr_demo] continue=false Dialplan: skypopen/ANY/interface1/echo123 Regex (PASS) [ivr_demo] destination_number(5000) =~ /^5000$/ break=on-false Dialplan: skypopen/ANY/interface1/echo123 Action answer() Dialplan: skypopen/ANY/interface1/echo123 Action sleep(2000) Dialplan: skypopen/ANY/interface1/echo123 Action ivr(demo_ivr) 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:119 (skypopen/ANY/interface1/echo123) State Change CS_ROUTING -> CS_EXECUTE 2010-09-25 01:29:51.677325 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 5,21] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:341 (skypopen/ANY/interface1/echo123) State ROUTING going to sleep 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_EXECUTE 2010-09-25 01:29:51.677325 [DEBUG] switch_channel.c:1519 (skypopen/ANY/interface1/echo123) Callstate Change RINGING -> ACTIVE 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:348 (skypopen/ANY/interface1/echo123) State EXECUTE 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:572 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 572 ][interface1][-1, 5,21] interface1 CHANNEL EXECUTE 2010-09-25 01:29:51.677325 [DEBUG] switch_core_state_machine.c:157 skypopen/ANY/interface1/echo123 Standard EXECUTE EXECUTE skypopen/ANY/interface1/echo123 hash(insert/95.131.64.12-spymap//5bc74275-7d0f-4739-9174-58765644c73c) 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=27 EXECUTE skypopen/ANY/interface1/echo123 hash(insert/95.131.64.12-last_dial//5000) 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=27 EXECUTE skypopen/ANY/interface1/echo123 hash(insert/95.131.64.12-last_dial/global/5bc74275-7d0f-4739-9174-58765644c73c) 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=27 EXECUTE skypopen/ANY/interface1/echo123 set(RFC2822_DATE=Sat, 25 Sep 2010 01:29:51 +0100) 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:51.677325 [DEBUG] mod_dptools.c:854 skypopen/ANY/interface1/echo123 SET [RFC2822_DATE]=[Sat, 25 Sep 2010 01:29:51 +0100] 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=27 EXECUTE skypopen/ANY/interface1/echo123 answer() 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=27 EXECUTE skypopen/ANY/interface1/echo123 sleep(2000) 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1001 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1001 ][interface1][-1, 5,21] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2010-09-25 01:29:51.677325 [DEBUG] mod_skypopen.c:1020 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1020 ][interface1][-1, 5,21] Synching audio 2010-09-25 01:29:51.679264 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||#output ALTER CALL 74 SET_OUTPUT PORT="32769"||| 2010-09-25 01:29:51.699162 [DEBUG] mod_skypopen.c:772 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 772 ][interface1][-1, 5,21] CHANNEL READ FRAME goto CNG 2010-09-25 01:29:51.761165 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 VAA_INPUT_STATUS TRUE||| 2010-09-25 01:29:51.763165 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 1||| 2010-09-25 01:29:52.759173 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 2||| 2010-09-25 01:29:53.689182 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=27 EXECUTE skypopen/ANY/interface1/echo123 ivr(demo_ivr) 2010-09-25 01:29:53.689182 [DEBUG] mod_skypopen.c:1048 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1048 ][interface1][-1, 5,21] MSG_ID=26 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-exit' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-sub' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-exec-app' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-play-sound' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-back' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:660 switch_ivr_menu_stack_xml_add binding 'menu-top' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:791 building menu 'demo_ivr' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '1' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '2' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '3' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '4' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '5' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:791 building menu 'demo_ivr_submenu' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-top' to '*' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-sub' to '6' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-exec-app' to '/^(10[01][0-9])$/' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:852 binding menu action 'menu-top' to '9' 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_menu.c:428 Executing IVR menu demo_ivr 2010-09-25 01:29:53.689182 [DEBUG] switch_ivr_play_say.c:63 No language specified - Using [en] 2010-09-25 01:29:53.693182 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-welcome_to_freeswitch.wav] (en:en) 2010-09-25 01:29:53.693182 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:29:53.759180 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 3||| 2010-09-25 01:29:54.759189 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 4||| 2010-09-25 01:29:55.759200 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 5||| 2010-09-25 01:29:56.309208 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:29:56.409209 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-this_ivr_will_let_you_test_features.wav] (en:en) 2010-09-25 01:29:56.409209 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:29:56.759216 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 6||| 2010-09-25 01:29:57.759219 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 7||| 2010-09-25 01:29:58.759229 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 8||| 2010-09-25 01:29:59.759239 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 9||| 2010-09-25 01:30:00.389255 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:00.509255 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-you_may_exit_by_hanging_up.wav] (en:en) 2010-09-25 01:30:00.509255 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:00.759250 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 10||| 2010-09-25 01:30:01.759259 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 11||| 2010-09-25 01:30:02.760271 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 12||| 2010-09-25 01:30:03.109276 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:03.209276 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-enter_ext_pound.wav] (en:en) 2010-09-25 01:30:03.209276 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:03.859283 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 13||| 2010-09-25 01:30:04.859293 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 14||| 2010-09-25 01:30:05.859303 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 15||| 2010-09-25 01:30:05.909304 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:06.009304 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[silence_stream://1500] (en:en) 2010-09-25 01:30:06.009304 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:06.759312 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 16||| 2010-09-25 01:30:07.509320 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:07.609320 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_call_the_freeswitch_conference.wav] (en:en) 2010-09-25 01:30:07.609320 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:07.759322 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 17||| 2010-09-25 01:30:08.760342 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 18||| 2010-09-25 01:30:09.249345 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:09.349347 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (en:en) 2010-09-25 01:30:09.349347 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:09.769349 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:09.859350 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 19||| 2010-09-25 01:30:09.869350 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en) 2010-09-25 01:30:09.869350 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:10.269354 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:10.369354 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/1.wav] (en:en) 2010-09-25 01:30:10.369354 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:10.759359 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 20||| 2010-09-25 01:30:10.759359 [DEBUG] skypopen_protocol.c:537 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 537 ][interface1][-1, 5,21] Synching audio on skype_call: 74. 2010-09-25 01:30:10.829359 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:10.929360 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (en:en) 2010-09-25 01:30:10.929360 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:11.759368 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 21||| 2010-09-25 01:30:12.749368 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:12.759369 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 22||| 2010-09-25 01:30:12.849371 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (en:en) 2010-09-25 01:30:12.849371 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:13.269374 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:13.369374 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en) 2010-09-25 01:30:13.369374 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:13.759379 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 23||| 2010-09-25 01:30:13.769381 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:13.869382 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/2.wav] (en:en) 2010-09-25 01:30:13.869382 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:14.269384 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:14.369384 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_listen_to_moh.wav] (en:en) 2010-09-25 01:30:14.369384 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:14.760391 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 24||| 2010-09-25 01:30:15.760402 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 25||| 2010-09-25 01:30:15.950409 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:16.050409 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (en:en) 2010-09-25 01:30:16.050409 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:16.470412 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:16.570414 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en) 2010-09-25 01:30:16.570414 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:16.760413 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 26||| 2010-09-25 01:30:16.970416 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:17.070418 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/3.wav] (en:en) 2010-09-25 01:30:17.070418 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:17.470423 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:17.570423 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-register_for_cluecon.wav] (en:en) 2010-09-25 01:30:17.570423 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:17.760421 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 27||| 2010-09-25 01:30:18.760431 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 28||| 2010-09-25 01:30:19.760440 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 29||| 2010-09-25 01:30:19.990448 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:20.090449 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/4.wav] (en:en) 2010-09-25 01:30:20.090449 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:20.530453 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:20.630454 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_hear_screaming_monkeys.wav] (en:en) 2010-09-25 01:30:20.630454 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:20.760450 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 30||| 2010-09-25 01:30:21.760463 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 31||| 2010-09-25 01:30:22.130470 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:22.230472 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (en:en) 2010-09-25 01:30:22.230472 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:22.650477 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:22.750477 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en) 2010-09-25 01:30:22.750477 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:22.760474 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 32||| 2010-09-25 01:30:23.150480 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:23.250482 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/5.wav] (en:en) 2010-09-25 01:30:23.250482 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:23.760483 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 33||| 2010-09-25 01:30:23.770488 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:23.870491 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_hear_sample_submenu.wav] (en:en) 2010-09-25 01:30:23.870491 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:24.760494 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 34||| 2010-09-25 01:30:25.760503 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 35||| 2010-09-25 01:30:26.250511 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:26.350512 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (en:en) 2010-09-25 01:30:26.350512 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:26.760515 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 36||| 2010-09-25 01:30:26.770519 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:26.890518 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en) 2010-09-25 01:30:26.890518 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:27.289520 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:27.389520 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/6.wav] (en:en) 2010-09-25 01:30:27.389520 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:27.759525 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 37||| 2010-09-25 01:30:27.929526 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:28.029527 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_repeat_these_options.wav] (en:en) 2010-09-25 01:30:28.029527 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:28.759536 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 38||| 2010-09-25 01:30:29.249538 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:29.349539 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (en:en) 2010-09-25 01:30:29.349539 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:29.759544 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 39||| 2010-09-25 01:30:29.769545 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:29.869546 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en) 2010-09-25 01:30:29.869546 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:30.269549 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:30.369551 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[digits/9.wav] (en:en) 2010-09-25 01:30:30.369551 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:30.759554 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 40||| 2010-09-25 01:30:30.759554 [DEBUG] skypopen_protocol.c:537 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 537 ][interface1][-1, 5,21] Synching audio on skype_call: 74. 2010-09-25 01:30:30.809555 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:30.909555 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[silence_stream://2000] (en:en) 2010-09-25 01:30:30.909555 [DEBUG] switch_ivr_play_say.c:1162 Codec Activated L16@16000hz 1 channels 20ms 2010-09-25 01:30:31.759564 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 41||| 2010-09-25 01:30:32.759574 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 42||| 2010-09-25 01:30:32.909576 [DEBUG] switch_ivr_play_say.c:1476 done playing file 2010-09-25 01:30:33.009576 [DEBUG] switch_ivr_menu.c:343 waiting for 4/4 digits t/o 2000 2010-09-25 01:30:33.760589 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 43||| 2010-09-25 01:30:34.759597 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 44||| 2010-09-25 01:30:35.759608 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 45||| 2010-09-25 01:30:36.759618 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 46||| 2010-09-25 01:30:37.759627 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 47||| 2010-09-25 01:30:38.759636 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 48||| 2010-09-25 01:30:39.760649 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 49||| 2010-09-25 01:30:40.759659 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 50||| 2010-09-25 01:30:41.759669 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5,21] READING: |||CALL 74 DURATION 51||| 2010-09-25 01:30:41.965672 [DEBUG] skypopen_protocol.c:872 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 872 ][interface1][-1, 5,21] CLOSED 2010-09-25 01:30:41.965672 [DEBUG] skypopen_protocol.c:887 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 887 ][interface1][-1, 5,21] Skype incoming audio GONE 2010-09-25 01:30:41.965672 [DEBUG] skypopen_protocol.c:896 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 896 ][interface1][-1, 5, 6] incoming audio (read) server (I am it) EXITING 2010-09-25 01:30:41.969674 [DEBUG] skypopen_protocol.c:1032 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1032 ][interface1][-1, 5, 6] Skype outbound audio GONE 2010-09-25 01:30:41.969674 [DEBUG] skypopen_protocol.c:1041 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1041 ][interface1][-1, 5, 6] outbound audio server (I am it) EXITING 2010-09-25 01:30:42.063675 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 5, 6] READING: |||CALL 74 STATUS FINISHED||| 2010-09-25 01:30:42.063675 [DEBUG] skypopen_protocol.c:613 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 613 ][interface1][-1, 5, 6] skype_call 74 is MY call, now I'm going DOWN 2010-09-25 01:30:42.063675 [DEBUG] mod_skypopen.c:1249 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1249 ][interface1][-1, 5, 6] skype call ended 2010-09-25 01:30:42.063675 [DEBUG] switch_channel.c:2357 (skypopen/ANY/interface1/echo123) Callstate Change ACTIVE -> HANGUP 2010-09-25 01:30:42.063675 [NOTICE] mod_skypopen.c:1260 Hangup skypopen/ANY/interface1/echo123 [CS_EXECUTE] [NORMAL_CLEARING] 2010-09-25 01:30:42.063675 [DEBUG] switch_channel.c:2373 Send signal skypopen/ANY/interface1/echo123 [KILL] 2010-09-25 01:30:42.063675 [DEBUG] mod_skypopen.c:593 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 593 ][interface1][-1, 5, 6] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_KILL 2010-09-25 01:30:42.063675 [DEBUG] skypopen_protocol.c:1502 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 1502 ][interface1][-1, 5, 6] SENDING: |||ALTER CALL END HANGUP|||| 2010-09-25 01:30:42.065678 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:30:42.065678 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 5, 6] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:30:42.069673 [DEBUG] mod_skypopen.c:836 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 836 ][interface1][-1, 1, 6] CHANNEL READ FALSE 2010-09-25 01:30:42.069673 [DEBUG] switch_ivr_menu.c:390 digits '' 2010-09-25 01:30:42.069673 [DEBUG] switch_ivr_menu.c:580 IVR menu 'demo_ivr' no input detected 2010-09-25 01:30:42.364688 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 0, 0] READING: |||CALL 74 VAA_INPUT_STATUS FALSE||| 2010-09-25 01:30:42.364688 [DEBUG] skypopen_protocol.c:176 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 176 ][interface1][-1, 0, 0] READING: |||ERROR 556 CALL: Invalid call ID given||| 2010-09-25 01:30:42.364688 [DEBUG] skypopen_protocol.c:230 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 230 ][interface1][-1, 0, 0] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 556 CALL: Invalid call ID given||| 2010-09-25 01:30:43.068694 [DEBUG] switch_ivr_menu.c:594 exit-sound 'voicemail/vm-goodbye.wav' 2010-09-25 01:30:43.068694 [DEBUG] switch_core_session.c:1917 skypopen/ANY/interface1/echo123 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:348 (skypopen/ANY/interface1/echo123) State EXECUTE going to sleep 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_HANGUP 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:535 (skypopen/ANY/interface1/echo123) State HANGUP 2010-09-25 01:30:43.068694 [DEBUG] mod_skypopen.c:528 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 528 ][interface1][-1,10, 0] interface1 CHANNEL HANGUP 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:46 skypopen/ANY/interface1/echo123 Standard HANGUP, cause: NORMAL_CLEARING 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:535 (skypopen/ANY/interface1/echo123) State HANGUP going to sleep 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:333 (skypopen/ANY/interface1/echo123) State Change CS_HANGUP -> CS_REPORTING 2010-09-25 01:30:43.068694 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:30:43.068694 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 0, 0] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:314 (skypopen/ANY/interface1/echo123) Running State Change CS_REPORTING 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:595 (skypopen/ANY/interface1/echo123) State REPORTING 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:53 skypopen/ANY/interface1/echo123 Standard REPORTING, cause: NORMAL_CLEARING 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:595 (skypopen/ANY/interface1/echo123) State REPORTING going to sleep 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:327 (skypopen/ANY/interface1/echo123) State Change CS_REPORTING -> CS_DESTROY 2010-09-25 01:30:43.068694 [DEBUG] switch_core_session.c:1047 Send signal skypopen/ANY/interface1/echo123 [BREAK] 2010-09-25 01:30:43.068694 [DEBUG] mod_skypopen.c:614 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 614 ][interface1][-1, 0, 0] skypopen/ANY/interface1/echo123 CHANNEL got SWITCH_SIG_BREAK 2010-09-25 01:30:43.068694 [DEBUG] switch_core_session.c:1210 Session 2 (skypopen/ANY/interface1/echo123) Locked, Waiting on external entities 2010-09-25 01:30:43.068694 [NOTICE] switch_core_session.c:1228 Session 2 (skypopen/ANY/interface1/echo123) Ended 2010-09-25 01:30:43.068694 [NOTICE] switch_core_session.c:1230 Close Channel skypopen/ANY/interface1/echo123 [CS_DESTROY] 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:427 (skypopen/ANY/interface1/echo123) Callstate Change HANGUP -> DOWN 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:430 (skypopen/ANY/interface1/echo123) Running State Change CS_DESTROY 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:440 (skypopen/ANY/interface1/echo123) State DESTROY 2010-09-25 01:30:43.068694 [DEBUG] mod_skypopen.c:451 rev git2svn-syncpoint-master-296-g25ddef5[(nil)|37 ][DEBUG_SKYPE 451 ][interface1][-1, 0, 0] interface1 CHANNEL DESTROY 5bc74275-7d0f-4739-9174-58765644c73c 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:60 skypopen/ANY/interface1/echo123 Standard DESTROY 2010-09-25 01:30:43.068694 [DEBUG] switch_core_state_machine.c:440 (skypopen/ANY/interface1/echo123) State DESTROY going to sleep freeswitch@a>