skype to x-lite birdge hangup imediately when answered
Dear all, I am tring skypopen with latest git-head. There are just 1 skype instance. When forward skype call to 5000, it works fine. It also works fine with originate skypopen/interface1/***** &bridge(user/1001) But when I try to forward skype to 1001 with the following dial plan, call hang up imediately when answered. <extension name="skypetest"> <condition field="destination_number" expression="^(5100)$"> <action application="bridge" data="user/1001"/> </condition> </extension> I am working on l ubuntu 10.10 server edition and skype static 2.0.0.72 here is the skype configure =============full mod_skypopen.conf.xml===================== <configuration name="skypopen.conf" description="Skypopen Configuration"> <global_settings> <param name="debug" value="8"/> <param name="dialplan" value="XML"/> <param name="context" value="default"/> <param name="destination" value="5100"/> <param name="skype_user" value="user1"/> <param name="report_incoming_chatmessages" value="true"/> <param name="silent_mode" value="false"/> <param name="write_silence_when_idle" value="true"/> </global_settings> <!-- one entry here per each skypopen interface --> <per_interface_settings> <interface id="1" name="interface1"> <param name="X11-display" value="localhost:10.0"/> <param name="skype_user" value="niqizhi"/> </interface> </per_interface_settings> </configuration> the debug message of the call is listed below. May I ask what is the possiable cause? Thanks. 2011-03-05 03:15:13.353532 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 CONF_ID 0||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS RINGING||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:595 [32b8f10|9350fb9] [DEBUG_SKYPE 595 ][interface1 ][IDLE,IDLE] NO ACTIVE calls in this moment, skype_call 142 is RINGING, to ask PARTNER_DISPNAME and PARTNER_HANDLE 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][IDLE,IDLE] SENDING: |||GET CALL 142 PARTNER_DISPNAME|||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][IDLE,IDLE] SENDING: |||GET CALL 142 PARTNER_HANDLE|||| 2011-03-05 03:15:13.576818 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 PARTNER_DISPNAME Eric Ni||| 2011-03-05 03:15:13.609592 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 PARTNER_HANDLE eric.nqz||| 2011-03-05 03:15:13.609592 [DEBUG] skypopen_protocol.c:506 [32b8f10|9350fb9] [DEBUG_SKYPE 506 ][interface1 ][IDLE,IDLE] Call 142 go to skypopen_partner_handle_ring 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2626 [32b8f10|9350fb9] [DEBUG_SKYPE 2626 ][interface1 ][IDLE,IDLE] NOT FOUND 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2244 [32b8f10|9350fb9] [DEBUG_SKYPE 2244 ][interface1 ][PRERING,IDLE] 2 SESSION_REQUEST c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:244 [32b8f10|9350fb9] [DEBUG_SKYPE 244 ][interface1 ][PRERING,IDLE] codecs UP 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:273 [32b8f10|9350fb9] [DEBUG_SKYPE 273 ][interface1 ][PRERING,IDLE] skypopen_tech_init SUCCESS 2011-03-05 03:15:13.609592 [NOTICE] switch_channel.c:812 New Channel skypopen/interface1 [c958d9be-46d6-11e0-bb71-d9b9e6428344] 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2268 (skypopen/interface1) State Change CS_NEW -> CS_INIT 2011-03-05 03:15:13.609592 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2280 [32b8f10|9350fb9] [DEBUG_SKYPE 2280 ][interface1 ][PRERING,IDLE] new_inbound_channel 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_INIT 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:356 (skypopen/interface1) State INIT 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:463 (skypopen/interface1) State Change CS_INIT -> CS_ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:464 [32b8f10|9350fb9] [DEBUG_SKYPE 464 ][interface1 ][PRERING,IDLE] interface1 CHANNEL INIT c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:356 (skypopen/interface1) State INIT going to sleep 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_channel.c:1664 (skypopen/interface1) Callstate Change DOWN -> RINGING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:359 (skypopen/interface1) State ROUTING 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:664 [32b8f10|9350fb9] [DEBUG_SKYPE 664 ][interface1 ][PRERING,IDLE] interface1 CHANNEL ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:77 skypopen/interface1 Standard ROUTING 2011-03-05 03:15:13.610977 [INFO] mod_dialplan_xml.c:331 Processing Eric Ni <eric.nqz>->5100 in context default Dialplan: skypopen/interface1 parsing [default->unloop] continue=false Dialplan: skypopen/interface1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: skypopen/interface1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: skypopen/interface1 parsing [default->tod_example] continue=true Dialplan: skypopen/interface1 Date/Time Match (FAIL) [tod_example] break=on-false Dialplan: skypopen/interface1 parsing [default->holiday_example] continue=true Dialplan: skypopen/interface1 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: skypopen/interface1 parsing [default->global-intercept] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [global-intercept] destination_number(5100) =~ /^886$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group-intercept] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group-intercept] destination_number(5100) =~ /^\*8$/ break=on-false Dialplan: skypopen/interface1 parsing [default->intercept-ext] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [intercept-ext] destination_number(5100) =~ /^\*\*(\d+)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->redial] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [redial] destination_number(5100) =~ /^(redial|870)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->global] continue=true Dialplan: skypopen/interface1 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: skypopen/interface1 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: skypopen/interface1 Absolute Condition [global] Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: skypopen/interface1 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: skypopen/interface1 parsing [default->snom-demo-2] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [snom-demo-2] destination_number(5100) =~ /^9001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->snom-demo-1] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [snom-demo-1] destination_number(5100) =~ /^9000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->eavesdrop] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [eavesdrop] destination_number(5100) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->eavesdrop] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [eavesdrop] destination_number(5100) =~ /^779$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call_return] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call_return] destination_number(5100) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: skypopen/interface1 parsing [default->del-group] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [del-group] destination_number(5100) =~ /^80(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->add-group] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [add-group] destination_number(5100) =~ /^81(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call-group-simo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call-group-simo] destination_number(5100) =~ /^82(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call-group-order] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call-group-order] destination_number(5100) =~ /^83(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->extension-intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [extension-intercom] destination_number(5100) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->Local_Extension] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [Local_Extension] destination_number(5100) =~ /^(10[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->Local_Extension_Skinny] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [Local_Extension_Skinny] destination_number(5100) =~ /^(11[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_sales] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_sales] destination_number(5100) =~ /^2000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_support] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_support] destination_number(5100) =~ /^2001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_billing] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_billing] destination_number(5100) =~ /^2002$/ break=on-false Dialplan: skypopen/interface1 parsing [default->operator] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [operator] destination_number(5100) =~ /^(operator|0)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->vmain] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [vmain] destination_number(5100) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: skypopen/interface1 parsing [default->sip_uri] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [sip_uri] destination_number(5100) =~ /^sip:(.*)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->nb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [nb_conferences] destination_number(5100) =~ /^(30\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->wb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [wb_conferences] destination_number(5100) =~ /^(31\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->uwb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [uwb_conferences] destination_number(5100) =~ /^(32\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->cdquality_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [cdquality_conferences] destination_number(5100) =~ /^(33\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(5100) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss_intercom] destination_number(5100) =~ /^0911$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss_intercom] destination_number(5100) =~ /^0912$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss] destination_number(5100) =~ /^0913$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ivr_demo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ivr_demo] destination_number(5100) =~ /^5000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->dynamic_conference] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [dynamic_conference] destination_number(5100) =~ /^5001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->rtp_multicast_page] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [rtp_multicast_page] destination_number(5100) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] destination_number(5100) =~ /^5900$/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] destination_number(5100) =~ /^5901$/ break=on-false Dialplan: skypopen/interface1 parsing [default->valet_park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [valet_park] destination_number(5100) =~ /^(6000)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->valet_park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [valet_park] destination_number(5100) =~ /^(60\d[1-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->wait] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [wait] destination_number(5100) =~ /^wait$/ break=on-false Dialplan: skypopen/interface1 parsing [default->fax_receive] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [fax_receive] destination_number(5100) =~ /^9178$/ break=on-false Dialplan: skypopen/interface1 parsing [default->fax_transmit] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [fax_transmit] destination_number(5100) =~ /^9179$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_180] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_180] destination_number(5100) =~ /^9180$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_183_uk_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_183_uk_ring] destination_number(5100) =~ /^9181$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_183_music_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_183_music_ring] destination_number(5100) =~ /^9182$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(5100) =~ /^9183$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_post_answer_music] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_post_answer_music] destination_number(5100) =~ /^9184$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ClueCon] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ClueCon] destination_number(5100) =~ /^9191$/ break=on-false Dialplan: skypopen/interface1 parsing [default->show_info] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [show_info] destination_number(5100) =~ /^9192$/ break=on-false Dialplan: skypopen/interface1 parsing [default->video_record] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [video_record] destination_number(5100) =~ /^9193$/ break=on-false Dialplan: skypopen/interface1 parsing [default->video_playback] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [video_playback] destination_number(5100) =~ /^9194$/ break=on-false Dialplan: skypopen/interface1 parsing [default->delay_echo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [delay_echo] destination_number(5100) =~ /^9195$/ break=on-false Dialplan: skypopen/interface1 parsing [default->echo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [echo] destination_number(5100) =~ /^9196$/ break=on-false Dialplan: skypopen/interface1 parsing [default->milliwatt] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [milliwatt] destination_number(5100) =~ /^9197$/ break=on-false Dialplan: skypopen/interface1 parsing [default->tone_stream] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [tone_stream] destination_number(5100) =~ /^9198$/ break=on-false Dialplan: skypopen/interface1 parsing [default->zrtp_enrollement] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [zrtp_enrollement] destination_number(5100) =~ /^9787$/ break=on-false Dialplan: skypopen/interface1 parsing [default->hold_music] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [hold_music] destination_number(5100) =~ /^9664$/ break=on-false Dialplan: skypopen/interface1 parsing [default->pizza_demo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [pizza_demo] destination_number(5100) =~ /^(pizza|74992)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->skypetest] continue=false Dialplan: skypopen/interface1 Regex (PASS) [skypetest] destination_number(5100) =~ /^(5100)$/ break=on-false Dialplan: skypopen/interface1 Action bridge(user/1001) 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:119 (skypopen/interface1) State Change CS_ROUTING -> CS_EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:359 (skypopen/interface1) State ROUTING going to sleep 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:366 (skypopen/interface1) State EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:681 [32b8f10|9350fb9] [DEBUG_SKYPE 681 ][interface1 ][PRERING,IDLE] interface1 CHANNEL EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:157 skypopen/interface1 Standard EXECUTE EXECUTE skypopen/interface1 hash(insert/178.79.156.136-spymap/eric.nqz/c958d9be-46d6-11e0-bb71-d9b9e6428344) 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 hash(insert/178.79.156.136-last_dial/eric.nqz/5100) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 hash(insert/178.79.156.136-last_dial/global/c958d9be-46d6-11e0-bb71-d9b9e6428344) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 set(RFC2822_DATE=Sat, 05 Mar 2011 03:15:13 +0000) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_dptools.c:1059 skypopen/interface1 SET [RFC2822_DATE]=[Sat, 05 Mar 2011 03:15:13 +0000] 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 bridge(user/1001) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.614232 [DEBUG] switch_ivr_originate.c:1971 variable string 0 = [sip_invite_domain=178.79.156.136] 2011-03-05 03:15:13.614232 [DEBUG] switch_ivr_originate.c:1971 variable string 1 = [presence_id=1001@178.79.156.136] 2011-03-05 03:15:13.614232 [NOTICE] switch_channel.c:812 New Channel sofia/internal/sip:1001@90.198.86.129:62954[c959849a-46d6-11e0-bb72-d9b9e6428344] 2011-03-05 03:15:13.614232 [DEBUG] mod_sofia.c:4151 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_NEW -> CS_INIT 2011-03-05 03:15:13.614232 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.614232 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_INIT 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:1001@90.198.86.129:62954) State INIT 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:84 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA INIT 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:124 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_INIT -> CS_ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:1001@90.198.86.129:62954) State INIT going to sleep 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_channel.c:1664 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change DOWN -> RINGING 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:1001@90.198.86.129:62954) State ROUTING 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:147 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:1001@90.198.86.129:62954) State ROUTING going to sleep 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:1001@90.198.86.129:62954) State CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [calling][0] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:1001@90.198.86.129:62954) State CONSUME_MEDIA going to sleep 2011-03-05 03:15:13.758128 [INFO] sofia.c:729 sofia/internal/ sip:1001@90.198.86.129:62954 Update Callee ID to "Outbound Call" <1001> 2011-03-05 03:15:13.759171 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [proceeding][180] 2011-03-05 03:15:13.759171 [NOTICE] sofia.c:4761 Ring-Ready sofia/internal/ sip:1001@90.198.86.129:62954! 2011-03-05 03:15:13.759171 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=7 2011-03-05 03:15:13.759171 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.759171 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.759171 [NOTICE] switch_ivr_originate.c:479 Ring Ready skypopen/interface1! 2011-03-05 03:15:13.759171 [NOTICE] switch_ivr_originate.c:479 Ring-Ready skypopen/interface1! 2011-03-05 03:15:15.372653 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [completing][200] 2011-03-05 03:15:15.372653 [DEBUG] sofia.c:4694 Remote SDP: v=0 o=- 1 2 IN IP4 90.198.86.129 s=CounterPath eyeBeam 1.5 c=IN IP4 90.198.86.129 t=0 0 m=audio 56446 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2011-03-05 03:15:15.373722 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [ready][200] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[L16:10:16000:20:256000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:115:32000:20:48000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:107:16000:20:32000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:2760 Set Codec sofia/internal/sip:1001@90.198.86.129:62954 PCMA/8000 20 ms 160 samples 64000 bits 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4635 Set 2833 dtmf send payload to 101 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:2990 AUDIO RTP [sofia/internal/sip:1001@90.198.86.129:62954] 178.79.156.136 port 32054 -> 90.198.86.129 port 56446 codec: 8 ms: 20 2011-03-05 03:15:15.373722 [DEBUG] switch_rtp.c:1621 Starting timer [soft] 160 bytes per 20ms 2011-03-05 03:15:15.374777 [DEBUG] sofia_glue.c:3235 Set 2833 dtmf send payload to 101 2011-03-05 03:15:15.374777 [DEBUG] sofia_glue.c:3240 Set 2833 dtmf receive payload to 101 2011-03-05 03:15:15.374777 [DEBUG] switch_channel.c:2795 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change RINGING -> ACTIVE 2011-03-05 03:15:15.374777 [DEBUG] switch_channel.c:2807 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.374777 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.374777 [NOTICE] sofia.c:5267 Channel [sofia/internal/ sip:1001@90.198.86.129:62954] has been answered 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:1115 [32b8f10|9350fb9] [DEBUG_SKYPE 1115 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_ANSWER 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2723 [32b8f10|9350fb9] [DEBUG_SKYPE 2723 ][interface1 ][PRERING,IDLE] NOT FOUND 2011-03-05 03:15:15.375852 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][PREANSW,IDLE] SENDING: |||ALTER CALL 142 ANSWER|||| 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2734 [32b8f10|9350fb9] [DEBUG_SKYPE 2734 ][interface1 ][PREANSW,IDLE] We answered a Skype RING on skype_call 142 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2742 [32b8f10|9350fb9] [DEBUG_SKYPE 2742 ][interface1 ][PREANSW,IDLE] NEW! name: interface1, state: 11, value=eric.nqz, tech_pvt->callid_number=eric.nqz, tech_pvt->skype_user=niqizhi 2011-03-05 03:15:15.472676 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][PREANSW,IDLE] READING: |||ALTER CALL 142 ANSWER||| 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1142 [32b8f10|9350fb9] [DEBUG_SKYPE 1142 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.884213 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.884213 [DEBUG] switch_channel.c:2795 (skypopen/interface1) Callstate Change RINGING -> ACTIVE 2011-03-05 03:15:15.884213 [NOTICE] switch_ivr_originate.c:3363 Channel [skypopen/interface1] has been answered 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.884213 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:709 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1173 [32b8f10|9350fb9] [DEBUG_SKYPE 1173 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_BRIDGE 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1195 [32b8f10|9350fb9] [DEBUG_SKYPE 1195 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.885293 [DEBUG] switch_ivr_bridge.c:1234 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:369 (sofia/internal/sip:1001@90.198.86.129:62954) State EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] mod_sofia.c:552 SOFIA EXCHANGE_MEDIA 2011-03-05 03:15:15.886388 [DEBUG] switch_core_session.c:771 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.886388 [DEBUG] switch_core_session.c:771 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.886388 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:500 skypopen/interface1 ending bridge by request from read function 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:581 BRIDGE THREAD DONE [skypopen/interface1] 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:601 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] switch_ivr_bridge.c:581 BRIDGE THREAD DONE [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.909404 [DEBUG] switch_ivr_bridge.c:601 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.909404 [DEBUG] switch_channel.c:2545 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change ACTIVE -> HANGUP 2011-03-05 03:15:15.909404 [NOTICE] switch_ivr_bridge.c:653 Hangup sofia/internal/sip:1001@90.198.86.129:62954 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2011-03-05 03:15:15.909404 [DEBUG] switch_channel.c:2561 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [KILL] 2011-03-05 03:15:15.909404 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:369 (sofia/internal/sip:1001@90.198.86.129:62954) State EXCHANGE_MEDIA going to sleep 2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_HANGUP 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:1001@90.198.86.129:62954) State HANGUP 2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:457 Channel sofia/internal/ sip:1001@90.198.86.129:62954 hanging up, cause: NORMAL_CLEARING 2011-03-05 03:15:15.910537 [DEBUG] switch_ivr_bridge.c:1305 sofia/internal/ sip:1001@90.198.86.129:62954 skip receive message [UNBRIDGE] (channel is hungup already) 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PREANSW,IDLE] MSG_ID=5 2011-03-05 03:15:15.910537 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PREANSW,IDLE] MSG_ID=27 2011-03-05 03:15:15.910537 [NOTICE] switch_core_state_machine.c:189 skypopen/interface1 has executed the last dialplan instruction, hanging up. 2011-03-05 03:15:15.910537 [DEBUG] switch_channel.c:2545 (skypopen/interface1) Callstate Change ACTIVE -> HANGUP 2011-03-05 03:15:15.910537 [NOTICE] switch_core_state_machine.c:191 Hangup skypopen/interface1 [CS_EXECUTE] [NORMAL_CLEARING] 2011-03-05 03:15:15.910537 [DEBUG] switch_channel.c:2561 Send signal skypopen/interface1 [KILL] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:700 [32b8f10|9350fb9] [DEBUG_SKYPE 700 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_KILL 2011-03-05 03:15:15.910537 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][HANG_RQ,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:366 (skypopen/interface1) State EXECUTE going to sleep 2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:500 Sending BYE to sofia/internal/sip:1001@90.198.86.129:62954 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_HANGUP 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:560 (skypopen/interface1) State HANGUP 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:623 [32b8f10|9350fb9] [DEBUG_SKYPE 623 ][interface1 ][HANG_RQ,IDLE] hanging up skype call: 142 2011-03-05 03:15:15.911571 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][HANG_RQ,IDLE] SENDING: |||ALTER CALL 142 END HANGUP|||| 2011-03-05 03:15:15.911571 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][HANG_RQ,IDLE] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:629 [32b8f10|9350fb9] [DEBUG_SKYPE 629 ][interface1 ][HANG_RQ,IDLE] interface1 CHANNEL HANGUP 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:648 (skypopen/interface1) State Change CS_HANGUP -> CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][DOWN,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:560 (skypopen/interface1) State HANGUP going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1288 Session 24 (skypopen/interface1) Locked, Waiting on external entities 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1306 Session 24 (skypopen/interface1) Ended 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1308 Close Channel skypopen/interface1 [CS_DESTROY] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1001@90.198.86.129:62954 Standard HANGUP, cause: NORMAL_CLEARING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:1001@90.198.86.129:62954) State HANGUP going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_HANGUP -> CS_REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:1001@90.198.86.129:62954) State REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1001@90.198.86.129:62954 Standard REPORTING, cause: NORMAL_CLEARING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:1001@90.198.86.129:62954) State REPORTING going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:449 (skypopen/interface1) Callstate Change HANGUP -> DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:452 (skypopen/interface1) Running State Change CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (skypopen/interface1) State DESTROY 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:479 [32b8f10|9350fb9] [DEBUG_SKYPE 479 ][interface1 ][DOWN,IDLE] interface1 CHANNEL DESTROY c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:493 [32b8f10|9350fb9] [DEBUG_SKYPE 493 ][interface1 ][DOWN,IDLE] audio tcp threads to DIE 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:503 [32b8f10|9350fb9] [DEBUG_SKYPE 503 ][interface1 ][DOWN,IDLE] audio tcp srv thread DEAD 0 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:513 [32b8f10|9350fb9] [DEBUG_SKYPE 513 ][interface1 ][DOWN,IDLE] audio tcp cli thread DEAD 0 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_REPORTING -> CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:524 [32b8f10|9350fb9] [DEBUG_SKYPE 524 ][interface1 ][DOWN,IDLE] codecs DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1288 Session 25 (sofia/internal/sip:1001@90.198.86.129:62954) Locked, Waiting on external entities 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:579 [32b8f10|9350fb9] [DEBUG_SKYPE 579 ][interface1 ][IDLE,IDLE] CHANNEL DESTROYED c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:60 skypopen/interface1 Standard DESTROY 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1306 Session 25 (sofia/internal/sip:1001@90.198.86.129:62954) Ended 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (skypopen/interface1) State DESTROY going to sleep 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1308 Close Channel sofia/internal/sip:1001@90.198.86.129:62954 [CS_DESTROY] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/sip:1001@90.198.86.129:62954) Callstate Change HANGUP -> DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:1001@90.198.86.129:62954) State DESTROY 2011-03-05 03:15:15.911571 [DEBUG] mod_sofia.c:362 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1001@90.198.86.129:62954 Standard DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:1001@90.198.86.129:62954) State DESTROY going to sleep 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS INPROGRESS||| 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:719 [32b8f10|9350fb9] [DEBUG_SKYPE 719 ][interface1 ][IDLE,IDLE] no tech_pvt->session_uuid_str 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:725 [32b8f10|9350fb9] [DEBUG_SKYPE 725 ][interface1 ][IDLE,IDLE] skype_call: 142 is now active 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:732 [32b8f10|9350fb9] [DEBUG_SKYPE 732 ][interface1 ][UP,INPROGRS] START start_audio_threads 2011-03-05 03:15:16.149772 [DEBUG] mod_skypopen.c:2203 [32b8f10|9350fb9] [DEBUG_SKYPE 2203 ][interface1 ][UP,INPROGRS] started tcp_srv_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:89 [32b8f10|9350fb9] [DEBUG_SKYPE 89 ][interface1 ][UP,INPROGRS] Binded! *which_port=32783, tech_pvt->tcp_cli_port=32782, tech_pvt->tcp_srv_port=32783 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:94 [32b8f10|9350fb9] [DEBUG_SKYPE 94 ][interface1 ][UP,INPROGRS] 1 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:98 [32b8f10|9350fb9] [DEBUG_SKYPE 98 ][interface1 ][UP,INPROGRS] 1 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] mod_skypopen.c:2219 [32b8f10|9350fb9] [DEBUG_SKYPE 2219 ][interface1 ][UP,INPROGRS] started tcp_cli_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:115 [32b8f10|9350fb9] [DEBUG_SKYPE 115 ][interface1 ][UP,INPROGRS] 2 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:130 [32b8f10|9350fb9] [DEBUG_SKYPE 130 ][interface1 ][UP,INPROGRS] 2 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:89 [32b8f10|9350fb9] [DEBUG_SKYPE 89 ][interface1 ][UP,INPROGRS] Binded! *which_port=32784, tech_pvt->tcp_cli_port=32784, tech_pvt->tcp_srv_port=32783 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:134 [32b8f10|9350fb9] [DEBUG_SKYPE 134 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:94 [32b8f10|9350fb9] [DEBUG_SKYPE 94 ][interface1 ][UP,INPROGRS] 1 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:141 [32b8f10|9350fb9] [DEBUG_SKYPE 141 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:98 [32b8f10|9350fb9] [DEBUG_SKYPE 98 ][interface1 ][UP,INPROGRS] 1 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:833 [32b8f10|9350fb9] [DEBUG_SKYPE 833 ][interface1 ][UP,INPROGRS] started tcp_srv_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:115 [32b8f10|9350fb9] [DEBUG_SKYPE 115 ][interface1 ][UP,INPROGRS] 2 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:130 [32b8f10|9350fb9] [DEBUG_SKYPE 130 ][interface1 ][UP,INPROGRS] 2 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:134 [32b8f10|9350fb9] [DEBUG_SKYPE 134 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:141 [32b8f10|9350fb9] [DEBUG_SKYPE 141 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:997 [32b8f10|9350fb9] [DEBUG_SKYPE 997 ][interface1 ][UP,INPROGRS] started tcp_cli_thread thread. 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 SET_INPUT PORT="32784"|||| 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||#output ALTER CALL 142 SET_OUTPUT PORT="32783"|||| 2011-03-05 03:15:16.250297 [WARNING] skypopen_protocol.c:2036 [32b8f10|9350fb9] [WARNINGA 2036 ][interface1 ][UP,INPROGRS] no tech_pvt->session_uuid_str after INPROGRESS, let's hangup 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 VIDEO_SEND_STATUS AVAILABLE||| 2011-03-05 03:15:16.290473 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 VIDEO_STATUS VIDEO_BOTH_ENABLED||| 2011-03-05 03:15:16.363839 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 DURATION 1||| 2011-03-05 03:15:16.432605 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ALTER CALL 142 END HANGUP||| 2011-03-05 03:15:16.494506 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.495584 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][UP,INPROGRS] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.710271 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:247 [32b8f10|9350fb9] [DEBUG_SKYPE 247 ][interface1 ][UP,INPROGRS] Skype client was not able to correctly manage tcp audio sockets, probably got a local or remote hangup: |||ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 END HANGUP|||| 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1413 [32b8f10|9350fb9] [DEBUG_SKYPE 1413 ][interface1 ][DOWN,INPROGRS] skype call ended 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1433 [32b8f10|9350fb9] [DEBUG_SKYPE 1433 ][interface1 ][DOWN,INPROGRS] no session 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1436 [32b8f10|9350fb9] [DEBUG_SKYPE 1436 ][interface1 ][DOWN,INPROGRS] audio tcp threads to DIE 2011-03-05 03:15:16.712434 [DEBUG] skypopen_protocol.c:960 [32b8f10|9350fb9] [DEBUG_SKYPE 960 ][interface1 ][DOWN,INPROGRS] incoming audio (read) server (I am it) EXITING 2011-03-05 03:15:16.715692 [DEBUG] mod_skypopen.c:1446 [32b8f10|9350fb9] [DEBUG_SKYPE 1446 ][interface1 ][DOWN,INPROGRS] audio tcp srv thread DEAD 1 2011-03-05 03:15:16.750763 [DEBUG] skypopen_protocol.c:1112 [32b8f10|9350fb9] [DEBUG_SKYPE 1112 ][interface1 ][DOWN,INPROGRS] outbound audio server (I am it) EXITING 2011-03-05 03:15:16.751849 [DEBUG] mod_skypopen.c:1456 [32b8f10|9350fb9] [DEBUG_SKYPE 1456 ][interface1 ][DOWN,INPROGRS] audio tcp cli thread DEAD 7 2011-03-05 03:15:16.751849 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||#output ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.779660 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.780762 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.828877 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.828877 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.869183 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.869183 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.911668 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS FINISHED||| 2011-03-05 03:15:16.911668 [DEBUG] skypopen_protocol.c:661 [32b8f10|9350fb9] [DEBUG_SKYPE 661 ][interface1 ][IDLE,IDLE] skype_call 142 is MY call, now I'm going DOWN 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1413 [32b8f10|9350fb9] [DEBUG_SKYPE 1413 ][interface1 ][IDLE,IDLE] skype call ended 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1433 [32b8f10|9350fb9] [DEBUG_SKYPE 1433 ][interface1 ][IDLE,IDLE] no session 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1436 [32b8f10|9350fb9] [DEBUG_SKYPE 1436 ][interface1 ][DOWN,IDLE] audio tcp threads to DIE 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1446 [32b8f10|9350fb9] [DEBUG_SKYPE 1446 ][interface1 ][DOWN,IDLE] audio tcp srv thread DEAD 0 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1456 [32b8f10|9350fb9] [DEBUG_SKYPE 1456 ][interface1 ][DOWN,IDLE] audio tcp cli thread DEAD 0
Hi Yi, could you please test your extension inserting an action "answer" before the action "bridge" ? -giovanni On 3/5/11, Yihui Li <xyangni@gmail.com> wrote:
Dear all,
I am tring skypopen with latest git-head. There are just 1 skype instance. When forward skype call to 5000, it works fine. It also works fine with originate skypopen/interface1/***** &bridge(user/1001)
But when I try to forward skype to 1001 with the following dial plan, call hang up imediately when answered.
<extension name="skypetest"> <condition field="destination_number" expression="^(5100)$"> <action application="bridge" data="user/1001"/> </condition> </extension>
I am working on l ubuntu 10.10 server edition and skype static 2.0.0.72
here is the skype configure =============full mod_skypopen.conf.xml===================== <configuration name="skypopen.conf" description="Skypopen Configuration"> <global_settings> <param name="debug" value="8"/> <param name="dialplan" value="XML"/> <param name="context" value="default"/> <param name="destination" value="5100"/> <param name="skype_user" value="user1"/> <param name="report_incoming_chatmessages" value="true"/> <param name="silent_mode" value="false"/> <param name="write_silence_when_idle" value="true"/> </global_settings> <!-- one entry here per each skypopen interface --> <per_interface_settings> <interface id="1" name="interface1"> <param name="X11-display" value="localhost:10.0"/> <param name="skype_user" value="niqizhi"/> </interface> </per_interface_settings> </configuration>
the debug message of the call is listed below. May I ask what is the possiable cause? Thanks.
2011-03-05 03:15:13.353532 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 CONF_ID 0||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS RINGING||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:595 [32b8f10|9350fb9] [DEBUG_SKYPE 595 ][interface1 ][IDLE,IDLE] NO ACTIVE calls in this moment, skype_call 142 is RINGING, to ask PARTNER_DISPNAME and PARTNER_HANDLE 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][IDLE,IDLE] SENDING: |||GET CALL 142 PARTNER_DISPNAME|||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][IDLE,IDLE] SENDING: |||GET CALL 142 PARTNER_HANDLE|||| 2011-03-05 03:15:13.576818 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 PARTNER_DISPNAME Eric Ni||| 2011-03-05 03:15:13.609592 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 PARTNER_HANDLE eric.nqz||| 2011-03-05 03:15:13.609592 [DEBUG] skypopen_protocol.c:506 [32b8f10|9350fb9] [DEBUG_SKYPE 506 ][interface1 ][IDLE,IDLE] Call 142 go to skypopen_partner_handle_ring 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2626 [32b8f10|9350fb9] [DEBUG_SKYPE 2626 ][interface1 ][IDLE,IDLE] NOT FOUND 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2244 [32b8f10|9350fb9] [DEBUG_SKYPE 2244 ][interface1 ][PRERING,IDLE] 2 SESSION_REQUEST c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:244 [32b8f10|9350fb9] [DEBUG_SKYPE 244 ][interface1 ][PRERING,IDLE] codecs UP 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:273 [32b8f10|9350fb9] [DEBUG_SKYPE 273 ][interface1 ][PRERING,IDLE] skypopen_tech_init SUCCESS 2011-03-05 03:15:13.609592 [NOTICE] switch_channel.c:812 New Channel skypopen/interface1 [c958d9be-46d6-11e0-bb71-d9b9e6428344] 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2268 (skypopen/interface1) State Change CS_NEW -> CS_INIT 2011-03-05 03:15:13.609592 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2280 [32b8f10|9350fb9] [DEBUG_SKYPE 2280 ][interface1 ][PRERING,IDLE] new_inbound_channel 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_INIT 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:356 (skypopen/interface1) State INIT 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:463 (skypopen/interface1) State Change CS_INIT -> CS_ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:464 [32b8f10|9350fb9] [DEBUG_SKYPE 464 ][interface1 ][PRERING,IDLE] interface1 CHANNEL INIT c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:356 (skypopen/interface1) State INIT going to sleep 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_channel.c:1664 (skypopen/interface1) Callstate Change DOWN -> RINGING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:359 (skypopen/interface1) State ROUTING 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:664 [32b8f10|9350fb9] [DEBUG_SKYPE 664 ][interface1 ][PRERING,IDLE] interface1 CHANNEL ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:77 skypopen/interface1 Standard ROUTING 2011-03-05 03:15:13.610977 [INFO] mod_dialplan_xml.c:331 Processing Eric Ni <eric.nqz>->5100 in context default Dialplan: skypopen/interface1 parsing [default->unloop] continue=false Dialplan: skypopen/interface1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: skypopen/interface1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: skypopen/interface1 parsing [default->tod_example] continue=true Dialplan: skypopen/interface1 Date/Time Match (FAIL) [tod_example] break=on-false Dialplan: skypopen/interface1 parsing [default->holiday_example] continue=true Dialplan: skypopen/interface1 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: skypopen/interface1 parsing [default->global-intercept] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [global-intercept] destination_number(5100) =~ /^886$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group-intercept] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group-intercept] destination_number(5100) =~ /^\*8$/ break=on-false Dialplan: skypopen/interface1 parsing [default->intercept-ext] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [intercept-ext] destination_number(5100) =~ /^\*\*(\d+)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->redial] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [redial] destination_number(5100) =~ /^(redial|870)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->global] continue=true Dialplan: skypopen/interface1 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: skypopen/interface1 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: skypopen/interface1 Absolute Condition [global] Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: skypopen/interface1 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: skypopen/interface1 parsing [default->snom-demo-2] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [snom-demo-2] destination_number(5100) =~ /^9001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->snom-demo-1] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [snom-demo-1] destination_number(5100) =~ /^9000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->eavesdrop] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [eavesdrop] destination_number(5100) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->eavesdrop] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [eavesdrop] destination_number(5100) =~ /^779$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call_return] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call_return] destination_number(5100) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: skypopen/interface1 parsing [default->del-group] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [del-group] destination_number(5100) =~ /^80(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->add-group] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [add-group] destination_number(5100) =~ /^81(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call-group-simo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call-group-simo] destination_number(5100) =~ /^82(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call-group-order] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call-group-order] destination_number(5100) =~ /^83(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->extension-intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [extension-intercom] destination_number(5100) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->Local_Extension] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [Local_Extension] destination_number(5100) =~ /^(10[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->Local_Extension_Skinny] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [Local_Extension_Skinny] destination_number(5100) =~ /^(11[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_sales] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_sales] destination_number(5100) =~ /^2000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_support] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_support] destination_number(5100) =~ /^2001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_billing] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_billing] destination_number(5100) =~ /^2002$/ break=on-false Dialplan: skypopen/interface1 parsing [default->operator] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [operator] destination_number(5100) =~ /^(operator|0)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->vmain] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [vmain] destination_number(5100) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: skypopen/interface1 parsing [default->sip_uri] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [sip_uri] destination_number(5100) =~ /^sip:(.*)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->nb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [nb_conferences] destination_number(5100) =~ /^(30\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->wb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [wb_conferences] destination_number(5100) =~ /^(31\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->uwb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [uwb_conferences] destination_number(5100) =~ /^(32\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->cdquality_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [cdquality_conferences] destination_number(5100) =~ /^(33\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(5100) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss_intercom] destination_number(5100) =~ /^0911$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss_intercom] destination_number(5100) =~ /^0912$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss] destination_number(5100) =~ /^0913$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ivr_demo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ivr_demo] destination_number(5100) =~ /^5000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->dynamic_conference] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [dynamic_conference] destination_number(5100) =~ /^5001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->rtp_multicast_page] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [rtp_multicast_page] destination_number(5100) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] destination_number(5100) =~ /^5900$/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] destination_number(5100) =~ /^5901$/ break=on-false Dialplan: skypopen/interface1 parsing [default->valet_park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [valet_park] destination_number(5100) =~ /^(6000)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->valet_park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [valet_park] destination_number(5100) =~ /^(60\d[1-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->wait] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [wait] destination_number(5100) =~ /^wait$/ break=on-false Dialplan: skypopen/interface1 parsing [default->fax_receive] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [fax_receive] destination_number(5100) =~ /^9178$/ break=on-false Dialplan: skypopen/interface1 parsing [default->fax_transmit] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [fax_transmit] destination_number(5100) =~ /^9179$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_180] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_180] destination_number(5100) =~ /^9180$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_183_uk_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_183_uk_ring] destination_number(5100) =~ /^9181$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_183_music_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_183_music_ring] destination_number(5100) =~ /^9182$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(5100) =~ /^9183$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_post_answer_music] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_post_answer_music] destination_number(5100) =~ /^9184$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ClueCon] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ClueCon] destination_number(5100) =~ /^9191$/ break=on-false Dialplan: skypopen/interface1 parsing [default->show_info] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [show_info] destination_number(5100) =~ /^9192$/ break=on-false Dialplan: skypopen/interface1 parsing [default->video_record] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [video_record] destination_number(5100) =~ /^9193$/ break=on-false Dialplan: skypopen/interface1 parsing [default->video_playback] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [video_playback] destination_number(5100) =~ /^9194$/ break=on-false Dialplan: skypopen/interface1 parsing [default->delay_echo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [delay_echo] destination_number(5100) =~ /^9195$/ break=on-false Dialplan: skypopen/interface1 parsing [default->echo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [echo] destination_number(5100) =~ /^9196$/ break=on-false Dialplan: skypopen/interface1 parsing [default->milliwatt] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [milliwatt] destination_number(5100) =~ /^9197$/ break=on-false Dialplan: skypopen/interface1 parsing [default->tone_stream] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [tone_stream] destination_number(5100) =~ /^9198$/ break=on-false Dialplan: skypopen/interface1 parsing [default->zrtp_enrollement] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [zrtp_enrollement] destination_number(5100) =~ /^9787$/ break=on-false Dialplan: skypopen/interface1 parsing [default->hold_music] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [hold_music] destination_number(5100) =~ /^9664$/ break=on-false Dialplan: skypopen/interface1 parsing [default->pizza_demo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [pizza_demo] destination_number(5100) =~ /^(pizza|74992)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->skypetest] continue=false Dialplan: skypopen/interface1 Regex (PASS) [skypetest] destination_number(5100) =~ /^(5100)$/ break=on-false Dialplan: skypopen/interface1 Action bridge(user/1001) 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:119 (skypopen/interface1) State Change CS_ROUTING -> CS_EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:359 (skypopen/interface1) State ROUTING going to sleep 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:366 (skypopen/interface1) State EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:681 [32b8f10|9350fb9] [DEBUG_SKYPE 681 ][interface1 ][PRERING,IDLE] interface1 CHANNEL EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:157 skypopen/interface1 Standard EXECUTE EXECUTE skypopen/interface1 hash(insert/178.79.156.136-spymap/eric.nqz/c958d9be-46d6-11e0-bb71-d9b9e6428344) 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 hash(insert/178.79.156.136-last_dial/eric.nqz/5100) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 hash(insert/178.79.156.136-last_dial/global/c958d9be-46d6-11e0-bb71-d9b9e6428344) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 set(RFC2822_DATE=Sat, 05 Mar 2011 03:15:13 +0000) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_dptools.c:1059 skypopen/interface1 SET [RFC2822_DATE]=[Sat, 05 Mar 2011 03:15:13 +0000] 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 bridge(user/1001) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.614232 [DEBUG] switch_ivr_originate.c:1971 variable string 0 = [sip_invite_domain=178.79.156.136] 2011-03-05 03:15:13.614232 [DEBUG] switch_ivr_originate.c:1971 variable string 1 = [presence_id=1001@178.79.156.136] 2011-03-05 03:15:13.614232 [NOTICE] switch_channel.c:812 New Channel sofia/internal/sip:1001@90.198.86.129:62954[c959849a-46d6-11e0-bb72-d9b9e6428344] 2011-03-05 03:15:13.614232 [DEBUG] mod_sofia.c:4151 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_NEW -> CS_INIT 2011-03-05 03:15:13.614232 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.614232 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_INIT 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:1001@90.198.86.129:62954) State INIT 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:84 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA INIT 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:124 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_INIT -> CS_ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:1001@90.198.86.129:62954) State INIT going to sleep 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_channel.c:1664 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change DOWN -> RINGING 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:1001@90.198.86.129:62954) State ROUTING 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:147 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:1001@90.198.86.129:62954) State ROUTING going to sleep 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:1001@90.198.86.129:62954) State CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [calling][0] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:1001@90.198.86.129:62954) State CONSUME_MEDIA going to sleep 2011-03-05 03:15:13.758128 [INFO] sofia.c:729 sofia/internal/ sip:1001@90.198.86.129:62954 Update Callee ID to "Outbound Call" <1001> 2011-03-05 03:15:13.759171 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [proceeding][180] 2011-03-05 03:15:13.759171 [NOTICE] sofia.c:4761 Ring-Ready sofia/internal/ sip:1001@90.198.86.129:62954! 2011-03-05 03:15:13.759171 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=7 2011-03-05 03:15:13.759171 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.759171 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.759171 [NOTICE] switch_ivr_originate.c:479 Ring Ready skypopen/interface1! 2011-03-05 03:15:13.759171 [NOTICE] switch_ivr_originate.c:479 Ring-Ready skypopen/interface1! 2011-03-05 03:15:15.372653 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [completing][200] 2011-03-05 03:15:15.372653 [DEBUG] sofia.c:4694 Remote SDP: v=0 o=- 1 2 IN IP4 90.198.86.129 s=CounterPath eyeBeam 1.5 c=IN IP4 90.198.86.129 t=0 0 m=audio 56446 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15
2011-03-05 03:15:15.373722 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [ready][200] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[L16:10:16000:20:256000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:115:32000:20:48000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:107:16000:20:32000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:2760 Set Codec sofia/internal/sip:1001@90.198.86.129:62954 PCMA/8000 20 ms 160 samples 64000 bits 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4635 Set 2833 dtmf send payload to 101 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:2990 AUDIO RTP [sofia/internal/sip:1001@90.198.86.129:62954] 178.79.156.136 port 32054 -> 90.198.86.129 port 56446 codec: 8 ms: 20 2011-03-05 03:15:15.373722 [DEBUG] switch_rtp.c:1621 Starting timer [soft] 160 bytes per 20ms 2011-03-05 03:15:15.374777 [DEBUG] sofia_glue.c:3235 Set 2833 dtmf send payload to 101 2011-03-05 03:15:15.374777 [DEBUG] sofia_glue.c:3240 Set 2833 dtmf receive payload to 101 2011-03-05 03:15:15.374777 [DEBUG] switch_channel.c:2795 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change RINGING -> ACTIVE 2011-03-05 03:15:15.374777 [DEBUG] switch_channel.c:2807 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.374777 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.374777 [NOTICE] sofia.c:5267 Channel [sofia/internal/ sip:1001@90.198.86.129:62954] has been answered 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:1115 [32b8f10|9350fb9] [DEBUG_SKYPE 1115 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_ANSWER 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2723 [32b8f10|9350fb9] [DEBUG_SKYPE 2723 ][interface1 ][PRERING,IDLE] NOT FOUND 2011-03-05 03:15:15.375852 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][PREANSW,IDLE] SENDING: |||ALTER CALL 142 ANSWER|||| 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2734 [32b8f10|9350fb9] [DEBUG_SKYPE 2734 ][interface1 ][PREANSW,IDLE] We answered a Skype RING on skype_call 142 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2742 [32b8f10|9350fb9] [DEBUG_SKYPE 2742 ][interface1 ][PREANSW,IDLE] NEW! name: interface1, state: 11, value=eric.nqz, tech_pvt->callid_number=eric.nqz, tech_pvt->skype_user=niqizhi 2011-03-05 03:15:15.472676 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][PREANSW,IDLE] READING: |||ALTER CALL 142 ANSWER||| 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1142 [32b8f10|9350fb9] [DEBUG_SKYPE 1142 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.884213 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.884213 [DEBUG] switch_channel.c:2795 (skypopen/interface1) Callstate Change RINGING -> ACTIVE 2011-03-05 03:15:15.884213 [NOTICE] switch_ivr_originate.c:3363 Channel [skypopen/interface1] has been answered 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.884213 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:709 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1173 [32b8f10|9350fb9] [DEBUG_SKYPE 1173 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_BRIDGE 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1195 [32b8f10|9350fb9] [DEBUG_SKYPE 1195 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.885293 [DEBUG] switch_ivr_bridge.c:1234 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:369 (sofia/internal/sip:1001@90.198.86.129:62954) State EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] mod_sofia.c:552 SOFIA EXCHANGE_MEDIA 2011-03-05 03:15:15.886388 [DEBUG] switch_core_session.c:771 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.886388 [DEBUG] switch_core_session.c:771 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.886388 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:500 skypopen/interface1 ending bridge by request from read function 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:581 BRIDGE THREAD DONE [skypopen/interface1] 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:601 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] switch_ivr_bridge.c:581 BRIDGE THREAD DONE [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.909404 [DEBUG] switch_ivr_bridge.c:601 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.909404 [DEBUG] switch_channel.c:2545 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change ACTIVE -> HANGUP 2011-03-05 03:15:15.909404 [NOTICE] switch_ivr_bridge.c:653 Hangup sofia/internal/sip:1001@90.198.86.129:62954 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2011-03-05 03:15:15.909404 [DEBUG] switch_channel.c:2561 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [KILL] 2011-03-05 03:15:15.909404 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:369 (sofia/internal/sip:1001@90.198.86.129:62954) State EXCHANGE_MEDIA going to sleep 2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_HANGUP 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:1001@90.198.86.129:62954) State HANGUP 2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:457 Channel sofia/internal/ sip:1001@90.198.86.129:62954 hanging up, cause: NORMAL_CLEARING 2011-03-05 03:15:15.910537 [DEBUG] switch_ivr_bridge.c:1305 sofia/internal/ sip:1001@90.198.86.129:62954 skip receive message [UNBRIDGE] (channel is hungup already) 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PREANSW,IDLE] MSG_ID=5 2011-03-05 03:15:15.910537 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PREANSW,IDLE] MSG_ID=27 2011-03-05 03:15:15.910537 [NOTICE] switch_core_state_machine.c:189 skypopen/interface1 has executed the last dialplan instruction, hanging up. 2011-03-05 03:15:15.910537 [DEBUG] switch_channel.c:2545 (skypopen/interface1) Callstate Change ACTIVE -> HANGUP 2011-03-05 03:15:15.910537 [NOTICE] switch_core_state_machine.c:191 Hangup skypopen/interface1 [CS_EXECUTE] [NORMAL_CLEARING] 2011-03-05 03:15:15.910537 [DEBUG] switch_channel.c:2561 Send signal skypopen/interface1 [KILL] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:700 [32b8f10|9350fb9] [DEBUG_SKYPE 700 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_KILL 2011-03-05 03:15:15.910537 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][HANG_RQ,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:366 (skypopen/interface1) State EXECUTE going to sleep 2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:500 Sending BYE to sofia/internal/sip:1001@90.198.86.129:62954 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_HANGUP 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:560 (skypopen/interface1) State HANGUP 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:623 [32b8f10|9350fb9] [DEBUG_SKYPE 623 ][interface1 ][HANG_RQ,IDLE] hanging up skype call: 142 2011-03-05 03:15:15.911571 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][HANG_RQ,IDLE] SENDING: |||ALTER CALL 142 END HANGUP|||| 2011-03-05 03:15:15.911571 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][HANG_RQ,IDLE] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:629 [32b8f10|9350fb9] [DEBUG_SKYPE 629 ][interface1 ][HANG_RQ,IDLE] interface1 CHANNEL HANGUP 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:648 (skypopen/interface1) State Change CS_HANGUP -> CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][DOWN,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:560 (skypopen/interface1) State HANGUP going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1288 Session 24 (skypopen/interface1) Locked, Waiting on external entities 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1306 Session 24 (skypopen/interface1) Ended 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1308 Close Channel skypopen/interface1 [CS_DESTROY] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1001@90.198.86.129:62954 Standard HANGUP, cause: NORMAL_CLEARING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:1001@90.198.86.129:62954) State HANGUP going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_HANGUP -> CS_REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:1001@90.198.86.129:62954) State REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1001@90.198.86.129:62954 Standard REPORTING, cause: NORMAL_CLEARING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:1001@90.198.86.129:62954) State REPORTING going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:449 (skypopen/interface1) Callstate Change HANGUP -> DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:452 (skypopen/interface1) Running State Change CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (skypopen/interface1) State DESTROY 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:479 [32b8f10|9350fb9] [DEBUG_SKYPE 479 ][interface1 ][DOWN,IDLE] interface1 CHANNEL DESTROY c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:493 [32b8f10|9350fb9] [DEBUG_SKYPE 493 ][interface1 ][DOWN,IDLE] audio tcp threads to DIE 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:503 [32b8f10|9350fb9] [DEBUG_SKYPE 503 ][interface1 ][DOWN,IDLE] audio tcp srv thread DEAD 0 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:513 [32b8f10|9350fb9] [DEBUG_SKYPE 513 ][interface1 ][DOWN,IDLE] audio tcp cli thread DEAD 0 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_REPORTING -> CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:524 [32b8f10|9350fb9] [DEBUG_SKYPE 524 ][interface1 ][DOWN,IDLE] codecs DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1288 Session 25 (sofia/internal/sip:1001@90.198.86.129:62954) Locked, Waiting on external entities 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:579 [32b8f10|9350fb9] [DEBUG_SKYPE 579 ][interface1 ][IDLE,IDLE] CHANNEL DESTROYED c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:60 skypopen/interface1 Standard DESTROY 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1306 Session 25 (sofia/internal/sip:1001@90.198.86.129:62954) Ended 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (skypopen/interface1) State DESTROY going to sleep 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1308 Close Channel sofia/internal/sip:1001@90.198.86.129:62954 [CS_DESTROY] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/sip:1001@90.198.86.129:62954) Callstate Change HANGUP -> DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:1001@90.198.86.129:62954) State DESTROY 2011-03-05 03:15:15.911571 [DEBUG] mod_sofia.c:362 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1001@90.198.86.129:62954 Standard DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:1001@90.198.86.129:62954) State DESTROY going to sleep 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS INPROGRESS||| 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:719 [32b8f10|9350fb9] [DEBUG_SKYPE 719 ][interface1 ][IDLE,IDLE] no tech_pvt->session_uuid_str 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:725 [32b8f10|9350fb9] [DEBUG_SKYPE 725 ][interface1 ][IDLE,IDLE] skype_call: 142 is now active 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:732 [32b8f10|9350fb9] [DEBUG_SKYPE 732 ][interface1 ][UP,INPROGRS] START start_audio_threads 2011-03-05 03:15:16.149772 [DEBUG] mod_skypopen.c:2203 [32b8f10|9350fb9] [DEBUG_SKYPE 2203 ][interface1 ][UP,INPROGRS] started tcp_srv_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:89 [32b8f10|9350fb9] [DEBUG_SKYPE 89 ][interface1 ][UP,INPROGRS] Binded! *which_port=32783, tech_pvt->tcp_cli_port=32782, tech_pvt->tcp_srv_port=32783 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:94 [32b8f10|9350fb9] [DEBUG_SKYPE 94 ][interface1 ][UP,INPROGRS] 1 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:98 [32b8f10|9350fb9] [DEBUG_SKYPE 98 ][interface1 ][UP,INPROGRS] 1 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] mod_skypopen.c:2219 [32b8f10|9350fb9] [DEBUG_SKYPE 2219 ][interface1 ][UP,INPROGRS] started tcp_cli_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:115 [32b8f10|9350fb9] [DEBUG_SKYPE 115 ][interface1 ][UP,INPROGRS] 2 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:130 [32b8f10|9350fb9] [DEBUG_SKYPE 130 ][interface1 ][UP,INPROGRS] 2 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:89 [32b8f10|9350fb9] [DEBUG_SKYPE 89 ][interface1 ][UP,INPROGRS] Binded! *which_port=32784, tech_pvt->tcp_cli_port=32784, tech_pvt->tcp_srv_port=32783 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:134 [32b8f10|9350fb9] [DEBUG_SKYPE 134 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:94 [32b8f10|9350fb9] [DEBUG_SKYPE 94 ][interface1 ][UP,INPROGRS] 1 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:141 [32b8f10|9350fb9] [DEBUG_SKYPE 141 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:98 [32b8f10|9350fb9] [DEBUG_SKYPE 98 ][interface1 ][UP,INPROGRS] 1 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:833 [32b8f10|9350fb9] [DEBUG_SKYPE 833 ][interface1 ][UP,INPROGRS] started tcp_srv_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:115 [32b8f10|9350fb9] [DEBUG_SKYPE 115 ][interface1 ][UP,INPROGRS] 2 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:130 [32b8f10|9350fb9] [DEBUG_SKYPE 130 ][interface1 ][UP,INPROGRS] 2 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:134 [32b8f10|9350fb9] [DEBUG_SKYPE 134 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:141 [32b8f10|9350fb9] [DEBUG_SKYPE 141 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:997 [32b8f10|9350fb9] [DEBUG_SKYPE 997 ][interface1 ][UP,INPROGRS] started tcp_cli_thread thread. 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 SET_INPUT PORT="32784"|||| 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||#output ALTER CALL 142 SET_OUTPUT PORT="32783"|||| 2011-03-05 03:15:16.250297 [WARNING] skypopen_protocol.c:2036 [32b8f10|9350fb9] [WARNINGA 2036 ][interface1 ][UP,INPROGRS] no tech_pvt->session_uuid_str after INPROGRESS, let's hangup 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 VIDEO_SEND_STATUS AVAILABLE||| 2011-03-05 03:15:16.290473 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 VIDEO_STATUS VIDEO_BOTH_ENABLED||| 2011-03-05 03:15:16.363839 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 DURATION 1||| 2011-03-05 03:15:16.432605 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ALTER CALL 142 END HANGUP||| 2011-03-05 03:15:16.494506 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.495584 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][UP,INPROGRS] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.710271 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:247 [32b8f10|9350fb9] [DEBUG_SKYPE 247 ][interface1 ][UP,INPROGRS] Skype client was not able to correctly manage tcp audio sockets, probably got a local or remote hangup: |||ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 END HANGUP|||| 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1413 [32b8f10|9350fb9] [DEBUG_SKYPE 1413 ][interface1 ][DOWN,INPROGRS] skype call ended 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1433 [32b8f10|9350fb9] [DEBUG_SKYPE 1433 ][interface1 ][DOWN,INPROGRS] no session 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1436 [32b8f10|9350fb9] [DEBUG_SKYPE 1436 ][interface1 ][DOWN,INPROGRS] audio tcp threads to DIE 2011-03-05 03:15:16.712434 [DEBUG] skypopen_protocol.c:960 [32b8f10|9350fb9] [DEBUG_SKYPE 960 ][interface1 ][DOWN,INPROGRS] incoming audio (read) server (I am it) EXITING 2011-03-05 03:15:16.715692 [DEBUG] mod_skypopen.c:1446 [32b8f10|9350fb9] [DEBUG_SKYPE 1446 ][interface1 ][DOWN,INPROGRS] audio tcp srv thread DEAD 1 2011-03-05 03:15:16.750763 [DEBUG] skypopen_protocol.c:1112 [32b8f10|9350fb9] [DEBUG_SKYPE 1112 ][interface1 ][DOWN,INPROGRS] outbound audio server (I am it) EXITING 2011-03-05 03:15:16.751849 [DEBUG] mod_skypopen.c:1456 [32b8f10|9350fb9] [DEBUG_SKYPE 1456 ][interface1 ][DOWN,INPROGRS] audio tcp cli thread DEAD 7 2011-03-05 03:15:16.751849 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||#output ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.779660 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.780762 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.828877 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.828877 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.869183 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.869183 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.911668 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS FINISHED||| 2011-03-05 03:15:16.911668 [DEBUG] skypopen_protocol.c:661 [32b8f10|9350fb9] [DEBUG_SKYPE 661 ][interface1 ][IDLE,IDLE] skype_call 142 is MY call, now I'm going DOWN 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1413 [32b8f10|9350fb9] [DEBUG_SKYPE 1413 ][interface1 ][IDLE,IDLE] skype call ended 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1433 [32b8f10|9350fb9] [DEBUG_SKYPE 1433 ][interface1 ][IDLE,IDLE] no session 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1436 [32b8f10|9350fb9] [DEBUG_SKYPE 1436 ][interface1 ][DOWN,IDLE] audio tcp threads to DIE 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1446 [32b8f10|9350fb9] [DEBUG_SKYPE 1446 ][interface1 ][DOWN,IDLE] audio tcp srv thread DEAD 0 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1456 [32b8f10|9350fb9] [DEBUG_SKYPE 1456 ][interface1 ][DOWN,IDLE] audio tcp cli thread DEAD 0
-- Sent from my mobile device Sincerely, Giovanni Maruzzelli Cell : +39-347-2665618
Hi Giovanni, I have tested your suggestion, the call works fine, when answered in dial plan before bridge. On Sat, Mar 5, 2011 at 5:01 AM, Giovanni Maruzzelli <gmaruzz@gmail.com>wrote:
Hi Yi,
could you please test your extension inserting an action "answer" before the action "bridge" ?
-giovanni
On 3/5/11, Yihui Li <xyangni@gmail.com> wrote:
Dear all,
I am tring skypopen with latest git-head. There are just 1 skype instance. When forward skype call to 5000, it works fine. It also works fine with originate skypopen/interface1/***** &bridge(user/1001)
But when I try to forward skype to 1001 with the following dial plan, call hang up imediately when answered.
<extension name="skypetest"> <condition field="destination_number" expression="^(5100)$"> <action application="bridge" data="user/1001"/> </condition> </extension>
I am working on l ubuntu 10.10 server edition and skype static 2.0.0.72
here is the skype configure =============full mod_skypopen.conf.xml===================== <configuration name="skypopen.conf" description="Skypopen Configuration"> <global_settings> <param name="debug" value="8"/> <param name="dialplan" value="XML"/> <param name="context" value="default"/> <param name="destination" value="5100"/> <param name="skype_user" value="user1"/> <param name="report_incoming_chatmessages" value="true"/> <param name="silent_mode" value="false"/> <param name="write_silence_when_idle" value="true"/> </global_settings> <!-- one entry here per each skypopen interface --> <per_interface_settings> <interface id="1" name="interface1"> <param name="X11-display" value="localhost:10.0"/> <param name="skype_user" value="niqizhi"/> </interface> </per_interface_settings> </configuration>
the debug message of the call is listed below. May I ask what is the possiable cause? Thanks.
2011-03-05 03:15:13.353532 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 CONF_ID 0||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS RINGING||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:595 [32b8f10|9350fb9] [DEBUG_SKYPE 595 ][interface1 ][IDLE,IDLE] NO ACTIVE calls in this moment, skype_call 142 is RINGING, to ask PARTNER_DISPNAME and PARTNER_HANDLE 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][IDLE,IDLE] SENDING: |||GET CALL 142 PARTNER_DISPNAME|||| 2011-03-05 03:15:13.438727 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][IDLE,IDLE] SENDING: |||GET CALL 142 PARTNER_HANDLE|||| 2011-03-05 03:15:13.576818 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 PARTNER_DISPNAME Eric Ni||| 2011-03-05 03:15:13.609592 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 PARTNER_HANDLE eric.nqz||| 2011-03-05 03:15:13.609592 [DEBUG] skypopen_protocol.c:506 [32b8f10|9350fb9] [DEBUG_SKYPE 506 ][interface1 ][IDLE,IDLE] Call 142 go to skypopen_partner_handle_ring 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2626 [32b8f10|9350fb9] [DEBUG_SKYPE 2626 ][interface1 ][IDLE,IDLE] NOT FOUND 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2244 [32b8f10|9350fb9] [DEBUG_SKYPE 2244 ][interface1 ][PRERING,IDLE] 2 SESSION_REQUEST c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:244 [32b8f10|9350fb9] [DEBUG_SKYPE 244 ][interface1 ][PRERING,IDLE] codecs UP 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:273 [32b8f10|9350fb9] [DEBUG_SKYPE 273 ][interface1 ][PRERING,IDLE] skypopen_tech_init SUCCESS 2011-03-05 03:15:13.609592 [NOTICE] switch_channel.c:812 New Channel skypopen/interface1 [c958d9be-46d6-11e0-bb71-d9b9e6428344] 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2268 (skypopen/interface1) State Change CS_NEW -> CS_INIT 2011-03-05 03:15:13.609592 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.609592 [DEBUG] mod_skypopen.c:2280 [32b8f10|9350fb9] [DEBUG_SKYPE 2280 ][interface1 ][PRERING,IDLE] new_inbound_channel 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_INIT 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:356 (skypopen/interface1) State INIT 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:463 (skypopen/interface1) State Change CS_INIT -> CS_ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:464 [32b8f10|9350fb9] [DEBUG_SKYPE 464 ][interface1 ][PRERING,IDLE] interface1 CHANNEL INIT c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:356 (skypopen/interface1) State INIT going to sleep 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_channel.c:1664 (skypopen/interface1) Callstate Change DOWN -> RINGING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:359 (skypopen/interface1) State ROUTING 2011-03-05 03:15:13.610977 [DEBUG] mod_skypopen.c:664 [32b8f10|9350fb9] [DEBUG_SKYPE 664 ][interface1 ][PRERING,IDLE] interface1 CHANNEL ROUTING 2011-03-05 03:15:13.610977 [DEBUG] switch_core_state_machine.c:77 skypopen/interface1 Standard ROUTING 2011-03-05 03:15:13.610977 [INFO] mod_dialplan_xml.c:331 Processing Eric Ni <eric.nqz>->5100 in context default Dialplan: skypopen/interface1 parsing [default->unloop] continue=false Dialplan: skypopen/interface1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: skypopen/interface1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: skypopen/interface1 parsing [default->tod_example] continue=true Dialplan: skypopen/interface1 Date/Time Match (FAIL) [tod_example] break=on-false Dialplan: skypopen/interface1 parsing [default->holiday_example] continue=true Dialplan: skypopen/interface1 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: skypopen/interface1 parsing [default->global-intercept] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [global-intercept] destination_number(5100) =~ /^886$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group-intercept] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group-intercept] destination_number(5100) =~ /^\*8$/ break=on-false Dialplan: skypopen/interface1 parsing [default->intercept-ext] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [intercept-ext] destination_number(5100) =~ /^\*\*(\d+)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->redial] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [redial] destination_number(5100) =~ /^(redial|870)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->global] continue=true Dialplan: skypopen/interface1 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: skypopen/interface1 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: skypopen/interface1 Absolute Condition [global] Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: skypopen/interface1 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: skypopen/interface1 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: skypopen/interface1 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: skypopen/interface1 parsing [default->snom-demo-2] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [snom-demo-2] destination_number(5100) =~ /^9001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->snom-demo-1] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [snom-demo-1] destination_number(5100) =~ /^9000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->eavesdrop] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [eavesdrop] destination_number(5100) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->eavesdrop] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [eavesdrop] destination_number(5100) =~ /^779$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call_return] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call_return] destination_number(5100) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: skypopen/interface1 parsing [default->del-group] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [del-group] destination_number(5100) =~ /^80(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->add-group] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [add-group] destination_number(5100) =~ /^81(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call-group-simo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call-group-simo] destination_number(5100) =~ /^82(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->call-group-order] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [call-group-order] destination_number(5100) =~ /^83(\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->extension-intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [extension-intercom] destination_number(5100) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->Local_Extension] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [Local_Extension] destination_number(5100) =~ /^(10[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->Local_Extension_Skinny] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [Local_Extension_Skinny] destination_number(5100) =~ /^(11[01][0-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_sales] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_sales] destination_number(5100) =~ /^2000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_support] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_support] destination_number(5100) =~ /^2001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->group_dial_billing] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [group_dial_billing] destination_number(5100) =~ /^2002$/ break=on-false Dialplan: skypopen/interface1 parsing [default->operator] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [operator] destination_number(5100) =~ /^(operator|0)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->vmain] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [vmain] destination_number(5100) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: skypopen/interface1 parsing [default->sip_uri] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [sip_uri] destination_number(5100) =~ /^sip:(.*)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->nb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [nb_conferences] destination_number(5100) =~ /^(30\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->wb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [wb_conferences] destination_number(5100) =~ /^(31\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->uwb_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [uwb_conferences] destination_number(5100) =~ /^(32\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->cdquality_conferences] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [cdquality_conferences] destination_number(5100) =~ /^(33\d{2})$/ break=on-false Dialplan: skypopen/interface1 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(5100) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss_intercom] destination_number(5100) =~ /^0911$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss_intercom] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss_intercom] destination_number(5100) =~ /^0912$/ break=on-false Dialplan: skypopen/interface1 parsing [default->mad_boss] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [mad_boss] destination_number(5100) =~ /^0913$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ivr_demo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ivr_demo] destination_number(5100) =~ /^5000$/ break=on-false Dialplan: skypopen/interface1 parsing [default->dynamic_conference] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [dynamic_conference] destination_number(5100) =~ /^5001$/ break=on-false Dialplan: skypopen/interface1 parsing [default->rtp_multicast_page] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [rtp_multicast_page] destination_number(5100) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] destination_number(5100) =~ /^5900$/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] destination_number(5100) =~ /^5901$/ break=on-false Dialplan: skypopen/interface1 parsing [default->valet_park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [valet_park] destination_number(5100) =~ /^(6000)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->valet_park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [valet_park] destination_number(5100) =~ /^(60\d[1-9])$/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->park] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [park] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->unpark] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [unpark] source(mod_skypopen) =~ /mod_sofia/ break=on-false Dialplan: skypopen/interface1 parsing [default->wait] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [wait] destination_number(5100) =~ /^wait$/ break=on-false Dialplan: skypopen/interface1 parsing [default->fax_receive] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [fax_receive] destination_number(5100) =~ /^9178$/ break=on-false Dialplan: skypopen/interface1 parsing [default->fax_transmit] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [fax_transmit] destination_number(5100) =~ /^9179$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_180] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_180] destination_number(5100) =~ /^9180$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_183_uk_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_183_uk_ring] destination_number(5100) =~ /^9181$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_183_music_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_183_music_ring] destination_number(5100) =~ /^9182$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(5100) =~ /^9183$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ringback_post_answer_music] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ringback_post_answer_music] destination_number(5100) =~ /^9184$/ break=on-false Dialplan: skypopen/interface1 parsing [default->ClueCon] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [ClueCon] destination_number(5100) =~ /^9191$/ break=on-false Dialplan: skypopen/interface1 parsing [default->show_info] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [show_info] destination_number(5100) =~ /^9192$/ break=on-false Dialplan: skypopen/interface1 parsing [default->video_record] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [video_record] destination_number(5100) =~ /^9193$/ break=on-false Dialplan: skypopen/interface1 parsing [default->video_playback] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [video_playback] destination_number(5100) =~ /^9194$/ break=on-false Dialplan: skypopen/interface1 parsing [default->delay_echo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [delay_echo] destination_number(5100) =~ /^9195$/ break=on-false Dialplan: skypopen/interface1 parsing [default->echo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [echo] destination_number(5100) =~ /^9196$/ break=on-false Dialplan: skypopen/interface1 parsing [default->milliwatt] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [milliwatt] destination_number(5100) =~ /^9197$/ break=on-false Dialplan: skypopen/interface1 parsing [default->tone_stream] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [tone_stream] destination_number(5100) =~ /^9198$/ break=on-false Dialplan: skypopen/interface1 parsing [default->zrtp_enrollement] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [zrtp_enrollement] destination_number(5100) =~ /^9787$/ break=on-false Dialplan: skypopen/interface1 parsing [default->hold_music] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [hold_music] destination_number(5100) =~ /^9664$/ break=on-false Dialplan: skypopen/interface1 parsing [default->pizza_demo] continue=false Dialplan: skypopen/interface1 Regex (FAIL) [pizza_demo] destination_number(5100) =~ /^(pizza|74992)$/ break=on-false Dialplan: skypopen/interface1 parsing [default->skypetest] continue=false Dialplan: skypopen/interface1 Regex (PASS) [skypetest] destination_number(5100) =~ /^(5100)$/ break=on-false Dialplan: skypopen/interface1 Action bridge(user/1001) 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:119 (skypopen/interface1) State Change CS_ROUTING -> CS_EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:359 (skypopen/interface1) State ROUTING going to sleep 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:366 (skypopen/interface1) State EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:681 [32b8f10|9350fb9] [DEBUG_SKYPE 681 ][interface1 ][PRERING,IDLE] interface1 CHANNEL EXECUTE 2011-03-05 03:15:13.612058 [DEBUG] switch_core_state_machine.c:157 skypopen/interface1 Standard EXECUTE EXECUTE skypopen/interface1
hash(insert/178.79.156.136-spymap/eric.nqz/c958d9be-46d6-11e0-bb71-d9b9e6428344)
2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.612058 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 hash(insert/178.79.156.136-last_dial/eric.nqz/5100) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1
hash(insert/178.79.156.136-last_dial/global/c958d9be-46d6-11e0-bb71-d9b9e6428344)
2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 set(RFC2822_DATE=Sat, 05 Mar 2011 03:15:13 +0000) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.613142 [DEBUG] mod_dptools.c:1059 skypopen/interface1 SET [RFC2822_DATE]=[Sat, 05 Mar 2011 03:15:13 +0000] 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=27 EXECUTE skypopen/interface1 bridge(user/1001) 2011-03-05 03:15:13.613142 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=26 2011-03-05 03:15:13.614232 [DEBUG] switch_ivr_originate.c:1971 variable string 0 = [sip_invite_domain=178.79.156.136] 2011-03-05 03:15:13.614232 [DEBUG] switch_ivr_originate.c:1971 variable string 1 = [presence_id=1001@178.79.156.136] 2011-03-05 03:15:13.614232 [NOTICE] switch_channel.c:812 New Channel sofia/internal/sip:1001@90.198.86.129:62954 [c959849a-46d6-11e0-bb72-d9b9e6428344] 2011-03-05 03:15:13.614232 [DEBUG] mod_sofia.c:4151 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_NEW -> CS_INIT 2011-03-05 03:15:13.614232 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.614232 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_INIT 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:1001@90.198.86.129:62954) State INIT 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:84 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA INIT 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:124 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_INIT -> CS_ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:1001@90.198.86.129:62954) State INIT going to sleep 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_channel.c:1664 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change DOWN -> RINGING 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:1001@90.198.86.129:62954) State ROUTING 2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:147 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA ROUTING 2011-03-05 03:15:13.615308 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:1001@90.198.86.129:62954) State ROUTING going to sleep 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:1001@90.198.86.129:62954) State CONSUME_MEDIA 2011-03-05 03:15:13.615308 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [calling][0] 2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:1001@90.198.86.129:62954) State CONSUME_MEDIA going to sleep 2011-03-05 03:15:13.758128 [INFO] sofia.c:729 sofia/internal/ sip:1001@90.198.86.129:62954 Update Callee ID to "Outbound Call" <1001> 2011-03-05 03:15:13.759171 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [proceeding][180] 2011-03-05 03:15:13.759171 [NOTICE] sofia.c:4761 Ring-Ready sofia/internal/ sip:1001@90.198.86.129:62954! 2011-03-05 03:15:13.759171 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PRERING,IDLE] MSG_ID=7 2011-03-05 03:15:13.759171 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:13.759171 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:13.759171 [NOTICE] switch_ivr_originate.c:479 Ring Ready skypopen/interface1! 2011-03-05 03:15:13.759171 [NOTICE] switch_ivr_originate.c:479 Ring-Ready skypopen/interface1! 2011-03-05 03:15:15.372653 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [completing][200] 2011-03-05 03:15:15.372653 [DEBUG] sofia.c:4694 Remote SDP: v=0 o=- 1 2 IN IP4 90.198.86.129 s=CounterPath eyeBeam 1.5 c=IN IP4 90.198.86.129 t=0 0 m=audio 56446 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15
2011-03-05 03:15:15.373722 [DEBUG] sofia.c:4683 Channel sofia/internal/ sip:1001@90.198.86.129:62954 entering state [ready][200] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[L16:10:16000:20:256000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:115:32000:20:48000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:107:16000:20:32000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4529 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:2760 Set Codec sofia/internal/sip:1001@90.198.86.129:62954 PCMA/8000 20 ms 160 samples 64000 bits 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:4635 Set 2833 dtmf send payload to 101 2011-03-05 03:15:15.373722 [DEBUG] sofia_glue.c:2990 AUDIO RTP [sofia/internal/sip:1001@90.198.86.129:62954] 178.79.156.136 port 32054 -> 90.198.86.129 port 56446 codec: 8 ms: 20 2011-03-05 03:15:15.373722 [DEBUG] switch_rtp.c:1621 Starting timer [soft] 160 bytes per 20ms 2011-03-05 03:15:15.374777 [DEBUG] sofia_glue.c:3235 Set 2833 dtmf send payload to 101 2011-03-05 03:15:15.374777 [DEBUG] sofia_glue.c:3240 Set 2833 dtmf receive payload to 101 2011-03-05 03:15:15.374777 [DEBUG] switch_channel.c:2795 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change RINGING -> ACTIVE 2011-03-05 03:15:15.374777 [DEBUG] switch_channel.c:2807 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.374777 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.374777 [NOTICE] sofia.c:5267 Channel [sofia/internal/ sip:1001@90.198.86.129:62954] has been answered 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:1115 [32b8f10|9350fb9] [DEBUG_SKYPE 1115 ][interface1 ][PRERING,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_ANSWER 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2723 [32b8f10|9350fb9] [DEBUG_SKYPE 2723 ][interface1 ][PRERING,IDLE] NOT FOUND 2011-03-05 03:15:15.375852 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][PREANSW,IDLE] SENDING: |||ALTER CALL 142 ANSWER|||| 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2734 [32b8f10|9350fb9] [DEBUG_SKYPE 2734 ][interface1 ][PREANSW,IDLE] We answered a Skype RING on skype_call 142 2011-03-05 03:15:15.375852 [DEBUG] mod_skypopen.c:2742 [32b8f10|9350fb9] [DEBUG_SKYPE 2742 ][interface1 ][PREANSW,IDLE] NEW! name: interface1, state: 11, value=eric.nqz, tech_pvt->callid_number=eric.nqz, tech_pvt->skype_user=niqizhi 2011-03-05 03:15:15.472676 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][PREANSW,IDLE] READING: |||ALTER CALL 142 ANSWER||| 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1142 [32b8f10|9350fb9] [DEBUG_SKYPE 1142 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.884213 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.884213 [DEBUG] switch_channel.c:2795 (skypopen/interface1) Callstate Change RINGING -> ACTIVE 2011-03-05 03:15:15.884213 [NOTICE] switch_ivr_originate.c:3363 Channel [skypopen/interface1] has been answered 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.884213 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.884213 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_ivr_originate.c:3408 Originate Resulted in Success: [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1148 [32b8f10|9350fb9] [DEBUG_SKYPE 1148 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_AUDIO_SYNC 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1170 [32b8f10|9350fb9] [DEBUG_SKYPE 1170 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:709 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1173 [32b8f10|9350fb9] [DEBUG_SKYPE 1173 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_MESSAGE_INDICATE_BRIDGE 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:1195 [32b8f10|9350fb9] [DEBUG_SKYPE 1195 ][interface1 ][PREANSW,IDLE] Synching audio 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.885293 [DEBUG] switch_ivr_bridge.c:1234 (sofia/internal/ sip:1001@90.198.86.129:62954) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:369 (sofia/internal/sip:1001@90.198.86.129:62954) State EXCHANGE_MEDIA 2011-03-05 03:15:15.885293 [DEBUG] mod_sofia.c:552 SOFIA EXCHANGE_MEDIA 2011-03-05 03:15:15.886388 [DEBUG] switch_core_session.c:771 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.886388 [DEBUG] switch_core_session.c:771 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.886388 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:500 skypopen/interface1 ending bridge by request from read function 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:581 BRIDGE THREAD DONE [skypopen/interface1] 2011-03-05 03:15:15.906103 [DEBUG] switch_ivr_bridge.c:601 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] switch_ivr_bridge.c:581 BRIDGE THREAD DONE [sofia/internal/sip:1001@90.198.86.129:62954] 2011-03-05 03:15:15.909404 [DEBUG] switch_ivr_bridge.c:601 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.909404 [DEBUG] switch_channel.c:2545 (sofia/internal/ sip:1001@90.198.86.129:62954) Callstate Change ACTIVE -> HANGUP 2011-03-05 03:15:15.909404 [NOTICE] switch_ivr_bridge.c:653 Hangup sofia/internal/sip:1001@90.198.86.129:62954 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2011-03-05 03:15:15.909404 [DEBUG] switch_channel.c:2561 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [KILL] 2011-03-05 03:15:15.909404 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:369 (sofia/internal/sip:1001@90.198.86.129:62954) State EXCHANGE_MEDIA going to sleep 2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_HANGUP 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:1001@90.198.86.129:62954) State HANGUP 2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:457 Channel sofia/internal/ sip:1001@90.198.86.129:62954 hanging up, cause: NORMAL_CLEARING 2011-03-05 03:15:15.910537 [DEBUG] switch_ivr_bridge.c:1305 sofia/internal/ sip:1001@90.198.86.129:62954 skip receive message [UNBRIDGE] (channel is hungup already) 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PREANSW,IDLE] MSG_ID=5 2011-03-05 03:15:15.910537 [DEBUG] switch_core_session.c:709 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:1201 [32b8f10|9350fb9] [DEBUG_SKYPE 1201 ][interface1 ][PREANSW,IDLE] MSG_ID=27 2011-03-05 03:15:15.910537 [NOTICE] switch_core_state_machine.c:189 skypopen/interface1 has executed the last dialplan instruction, hanging up. 2011-03-05 03:15:15.910537 [DEBUG] switch_channel.c:2545 (skypopen/interface1) Callstate Change ACTIVE -> HANGUP 2011-03-05 03:15:15.910537 [NOTICE] switch_core_state_machine.c:191 Hangup skypopen/interface1 [CS_EXECUTE] [NORMAL_CLEARING] 2011-03-05 03:15:15.910537 [DEBUG] switch_channel.c:2561 Send signal skypopen/interface1 [KILL] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:700 [32b8f10|9350fb9] [DEBUG_SKYPE 700 ][interface1 ][PREANSW,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_KILL 2011-03-05 03:15:15.910537 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][HANG_RQ,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:366 (skypopen/interface1) State EXECUTE going to sleep 2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:500 Sending BYE to sofia/internal/sip:1001@90.198.86.129:62954 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:320 (skypopen/interface1) Running State Change CS_HANGUP 2011-03-05 03:15:15.910537 [DEBUG] switch_core_state_machine.c:560 (skypopen/interface1) State HANGUP 2011-03-05 03:15:15.910537 [DEBUG] mod_skypopen.c:623 [32b8f10|9350fb9] [DEBUG_SKYPE 623 ][interface1 ][HANG_RQ,IDLE] hanging up skype call: 142 2011-03-05 03:15:15.911571 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][HANG_RQ,IDLE] SENDING: |||ALTER CALL 142 END HANGUP|||| 2011-03-05 03:15:15.911571 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][HANG_RQ,IDLE] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:629 [32b8f10|9350fb9] [DEBUG_SKYPE 629 ][interface1 ][HANG_RQ,IDLE] interface1 CHANNEL HANGUP 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:648 (skypopen/interface1) State Change CS_HANGUP -> CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal skypopen/interface1 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:727 [32b8f10|9350fb9] [DEBUG_SKYPE 727 ][interface1 ][DOWN,IDLE] skypopen/interface1 CHANNEL got SWITCH_SIG_BREAK 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:560 (skypopen/interface1) State HANGUP going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1288 Session 24 (skypopen/interface1) Locked, Waiting on external entities 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1306 Session 24 (skypopen/interface1) Ended 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1308 Close Channel skypopen/interface1 [CS_DESTROY] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1001@90.198.86.129:62954 Standard HANGUP, cause: NORMAL_CLEARING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:1001@90.198.86.129:62954) State HANGUP going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_HANGUP -> CS_REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:1001@90.198.86.129:62954) State REPORTING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1001@90.198.86.129:62954 Standard REPORTING, cause: NORMAL_CLEARING 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:1001@90.198.86.129:62954) State REPORTING going to sleep 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:449 (skypopen/interface1) Callstate Change HANGUP -> DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:452 (skypopen/interface1) Running State Change CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (skypopen/interface1) State DESTROY 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:479 [32b8f10|9350fb9] [DEBUG_SKYPE 479 ][interface1 ][DOWN,IDLE] interface1 CHANNEL DESTROY c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:493 [32b8f10|9350fb9] [DEBUG_SKYPE 493 ][interface1 ][DOWN,IDLE] audio tcp threads to DIE 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:503 [32b8f10|9350fb9] [DEBUG_SKYPE 503 ][interface1 ][DOWN,IDLE] audio tcp srv thread DEAD 0 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:513 [32b8f10|9350fb9] [DEBUG_SKYPE 513 ][interface1 ][DOWN,IDLE] audio tcp cli thread DEAD 0 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/sip:1001@90.198.86.129:62954) State Change CS_REPORTING -> CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:1001@90.198.86.129:62954 [BREAK] 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:524 [32b8f10|9350fb9] [DEBUG_SKYPE 524 ][interface1 ][DOWN,IDLE] codecs DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_session.c:1288 Session 25 (sofia/internal/sip:1001@90.198.86.129:62954) Locked, Waiting on external entities 2011-03-05 03:15:15.911571 [DEBUG] mod_skypopen.c:579 [32b8f10|9350fb9] [DEBUG_SKYPE 579 ][interface1 ][IDLE,IDLE] CHANNEL DESTROYED c958d9be-46d6-11e0-bb71-d9b9e6428344 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:60 skypopen/interface1 Standard DESTROY 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1306 Session 25 (sofia/internal/sip:1001@90.198.86.129:62954) Ended 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (skypopen/interface1) State DESTROY going to sleep 2011-03-05 03:15:15.911571 [NOTICE] switch_core_session.c:1308 Close Channel sofia/internal/sip:1001@90.198.86.129:62954 [CS_DESTROY] 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/sip:1001@90.198.86.129:62954) Callstate Change HANGUP -> DOWN 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:1001@90.198.86.129:62954) Running State Change CS_DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:1001@90.198.86.129:62954) State DESTROY 2011-03-05 03:15:15.911571 [DEBUG] mod_sofia.c:362 sofia/internal/ sip:1001@90.198.86.129:62954 SOFIA DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1001@90.198.86.129:62954 Standard DESTROY 2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:1001@90.198.86.129:62954) State DESTROY going to sleep 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS INPROGRESS||| 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:719 [32b8f10|9350fb9] [DEBUG_SKYPE 719 ][interface1 ][IDLE,IDLE] no tech_pvt->session_uuid_str 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:725 [32b8f10|9350fb9] [DEBUG_SKYPE 725 ][interface1 ][IDLE,IDLE] skype_call: 142 is now active 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:732 [32b8f10|9350fb9] [DEBUG_SKYPE 732 ][interface1 ][UP,INPROGRS] START start_audio_threads 2011-03-05 03:15:16.149772 [DEBUG] mod_skypopen.c:2203 [32b8f10|9350fb9] [DEBUG_SKYPE 2203 ][interface1 ][UP,INPROGRS] started tcp_srv_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:89 [32b8f10|9350fb9] [DEBUG_SKYPE 89 ][interface1 ][UP,INPROGRS] Binded! *which_port=32783, tech_pvt->tcp_cli_port=32782, tech_pvt->tcp_srv_port=32783 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:94 [32b8f10|9350fb9] [DEBUG_SKYPE 94 ][interface1 ][UP,INPROGRS] 1 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:98 [32b8f10|9350fb9] [DEBUG_SKYPE 98 ][interface1 ][UP,INPROGRS] 1 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] mod_skypopen.c:2219 [32b8f10|9350fb9] [DEBUG_SKYPE 2219 ][interface1 ][UP,INPROGRS] started tcp_cli_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:115 [32b8f10|9350fb9] [DEBUG_SKYPE 115 ][interface1 ][UP,INPROGRS] 2 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:130 [32b8f10|9350fb9] [DEBUG_SKYPE 130 ][interface1 ][UP,INPROGRS] 2 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:89 [32b8f10|9350fb9] [DEBUG_SKYPE 89 ][interface1 ][UP,INPROGRS] Binded! *which_port=32784, tech_pvt->tcp_cli_port=32784, tech_pvt->tcp_srv_port=32783 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:134 [32b8f10|9350fb9] [DEBUG_SKYPE 134 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:94 [32b8f10|9350fb9] [DEBUG_SKYPE 94 ][interface1 ][UP,INPROGRS] 1 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:141 [32b8f10|9350fb9] [DEBUG_SKYPE 141 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:98 [32b8f10|9350fb9] [DEBUG_SKYPE 98 ][interface1 ][UP,INPROGRS] 1 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:833 [32b8f10|9350fb9] [DEBUG_SKYPE 833 ][interface1 ][UP,INPROGRS] started tcp_srv_thread thread. 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:115 [32b8f10|9350fb9] [DEBUG_SKYPE 115 ][interface1 ][UP,INPROGRS] 2 SO_RCVBUF is 87380, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:130 [32b8f10|9350fb9] [DEBUG_SKYPE 130 ][interface1 ][UP,INPROGRS] 2 SO_SNDBUF is 16384, size is 4 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:134 [32b8f10|9350fb9] [DEBUG_SKYPE 134 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:141 [32b8f10|9350fb9] [DEBUG_SKYPE 141 ][interface1 ][UP,INPROGRS] TCP_NODELAY is 0 2011-03-05 03:15:16.149772 [DEBUG] skypopen_protocol.c:997 [32b8f10|9350fb9] [DEBUG_SKYPE 997 ][interface1 ][UP,INPROGRS] started tcp_cli_thread thread. 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 SET_INPUT PORT="32784"|||| 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||#output ALTER CALL 142 SET_OUTPUT PORT="32783"|||| 2011-03-05 03:15:16.250297 [WARNING] skypopen_protocol.c:2036 [32b8f10|9350fb9] [WARNINGA 2036 ][interface1 ][UP,INPROGRS] no tech_pvt->session_uuid_str after INPROGRESS, let's hangup 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:16.250297 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 VIDEO_SEND_STATUS AVAILABLE||| 2011-03-05 03:15:16.290473 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 VIDEO_STATUS VIDEO_BOTH_ENABLED||| 2011-03-05 03:15:16.363839 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||CALL 142 DURATION 1||| 2011-03-05 03:15:16.432605 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ALTER CALL 142 END HANGUP||| 2011-03-05 03:15:16.494506 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.495584 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][UP,INPROGRS] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.710271 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][UP,INPROGRS] READING: |||ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:247 [32b8f10|9350fb9] [DEBUG_SKYPE 247 ][interface1 ][UP,INPROGRS] Skype client was not able to correctly manage tcp audio sockets, probably got a local or remote hangup: |||ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 HANGUP|||| 2011-03-05 03:15:16.711346 [DEBUG] skypopen_protocol.c:1619 [32b8f10|9350fb9] [DEBUG_SKYPE 1619 ][interface1 ][UP,INPROGRS] SENDING: |||ALTER CALL 142 END HANGUP|||| 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1413 [32b8f10|9350fb9] [DEBUG_SKYPE 1413 ][interface1 ][DOWN,INPROGRS] skype call ended 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1433 [32b8f10|9350fb9] [DEBUG_SKYPE 1433 ][interface1 ][DOWN,INPROGRS] no session 2011-03-05 03:15:16.711346 [DEBUG] mod_skypopen.c:1436 [32b8f10|9350fb9] [DEBUG_SKYPE 1436 ][interface1 ][DOWN,INPROGRS] audio tcp threads to DIE 2011-03-05 03:15:16.712434 [DEBUG] skypopen_protocol.c:960 [32b8f10|9350fb9] [DEBUG_SKYPE 960 ][interface1 ][DOWN,INPROGRS] incoming audio (read) server (I am it) EXITING 2011-03-05 03:15:16.715692 [DEBUG] mod_skypopen.c:1446 [32b8f10|9350fb9] [DEBUG_SKYPE 1446 ][interface1 ][DOWN,INPROGRS] audio tcp srv thread DEAD 1 2011-03-05 03:15:16.750763 [DEBUG] skypopen_protocol.c:1112 [32b8f10|9350fb9] [DEBUG_SKYPE 1112 ][interface1 ][DOWN,INPROGRS] outbound audio server (I am it) EXITING 2011-03-05 03:15:16.751849 [DEBUG] mod_skypopen.c:1456 [32b8f10|9350fb9] [DEBUG_SKYPE 1456 ][interface1 ][DOWN,INPROGRS] audio tcp cli thread DEAD 7 2011-03-05 03:15:16.751849 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||#output ERROR 589 ALTER CALL: unable to alter input/output||| 2011-03-05 03:15:16.779660 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.780762 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.828877 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.828877 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.869183 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.869183 [DEBUG] skypopen_protocol.c:228 [32b8f10|9350fb9] [DEBUG_SKYPE 228 ][interface1 ][IDLE,IDLE] Skype got ERROR about a failed action (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL: Action failed||| 2011-03-05 03:15:16.911668 [DEBUG] skypopen_protocol.c:173 [32b8f10|9350fb9] [DEBUG_SKYPE 173 ][interface1 ][IDLE,IDLE] READING: |||CALL 142 STATUS FINISHED||| 2011-03-05 03:15:16.911668 [DEBUG] skypopen_protocol.c:661 [32b8f10|9350fb9] [DEBUG_SKYPE 661 ][interface1 ][IDLE,IDLE] skype_call 142 is MY call, now I'm going DOWN 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1413 [32b8f10|9350fb9] [DEBUG_SKYPE 1413 ][interface1 ][IDLE,IDLE] skype call ended 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1433 [32b8f10|9350fb9] [DEBUG_SKYPE 1433 ][interface1 ][IDLE,IDLE] no session 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1436 [32b8f10|9350fb9] [DEBUG_SKYPE 1436 ][interface1 ][DOWN,IDLE] audio tcp threads to DIE 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1446 [32b8f10|9350fb9] [DEBUG_SKYPE 1446 ][interface1 ][DOWN,IDLE] audio tcp srv thread DEAD 0 2011-03-05 03:15:16.911668 [DEBUG] mod_skypopen.c:1456 [32b8f10|9350fb9] [DEBUG_SKYPE 1456 ][interface1 ][DOWN,IDLE] audio tcp cli thread DEAD 0
-- Sent from my mobile device
Sincerely,
Giovanni Maruzzelli Cell : +39-347-2665618
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
participants (2)
-
Giovanni Maruzzelli
-
Yihui Li