[Freeswitch-users] skype to x-lite birdge hangup imediately when answered
Yihui Li
xyangni at gmail.com
Sat Mar 5 06:43:26 MSK 2011
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 at 178.79.156.136]
2011-03-05 03:15:13.614232 [NOTICE] switch_channel.c:812 New Channel
sofia/internal/sip:1001 at 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 at 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 at 90.198.86.129:62954 [BREAK]
2011-03-05 03:15:13.614232 [DEBUG] switch_core_state_machine.c:320
(sofia/internal/sip:1001 at 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 at 90.198.86.129:62954) State INIT
2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:84 sofia/internal/
sip:1001 at 90.198.86.129:62954 SOFIA INIT
2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:124 (sofia/internal/
sip:1001 at 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 at 90.198.86.129:62954 [BREAK]
2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:356
(sofia/internal/sip:1001 at 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 at 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 at 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 at 90.198.86.129:62954) State ROUTING
2011-03-05 03:15:13.615308 [DEBUG] mod_sofia.c:147 sofia/internal/
sip:1001 at 90.198.86.129:62954 SOFIA ROUTING
2011-03-05 03:15:13.615308 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1001 at 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 at 90.198.86.129:62954 [BREAK]
2011-03-05 03:15:13.615308 [DEBUG] switch_core_state_machine.c:359
(sofia/internal/sip:1001 at 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 at 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 at 90.198.86.129:62954) State CONSUME_MEDIA
2011-03-05 03:15:13.615308 [DEBUG] sofia.c:4683 Channel sofia/internal/
sip:1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 90.198.86.129:62954 [BREAK]
2011-03-05 03:15:15.885293 [DEBUG] switch_core_state_machine.c:320
(sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 90.198.86.129:62954 [BREAK]
2011-03-05 03:15:15.909404 [DEBUG] switch_core_state_machine.c:369
(sofia/internal/sip:1001 at 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 at 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 at 90.198.86.129:62954) State HANGUP
2011-03-05 03:15:15.910537 [DEBUG] mod_sofia.c:457 Channel sofia/internal/
sip:1001 at 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 at 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 at 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 at 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 at 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 at 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 at 90.198.86.129:62954 [BREAK]
2011-03-05 03:15:15.911571 [DEBUG] switch_core_state_machine.c:320
(sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 90.198.86.129:62954) State DESTROY
2011-03-05 03:15:15.911571 [DEBUG] mod_sofia.c:362 sofia/internal/
sip:1001 at 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 at 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 at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110305/894026ba/attachment-0001.html
More information about the FreeSWITCH-users
mailing list