[Freeswitch-users] mod_skypopen Refusing Skype Calls Once a Call is Answered Via a Desktop Skype Client
Jason Jeffords
jason at cloudtree.net
Tue Sep 28 11:14:36 PDT 2010
We have found another failure case, this time without any extra Skype
instances.
1) Call a Skype userid on FreeSWITCH which bridges to a SIP endpoint
2) Hang up the Skype Client before the far end answers
3) The far end will keep ringing for a while, wait until it finishes
4) Now call the same Skype userid on FreeSWITCH
5) Answer the far end - there is no audio
6) Hang up either end
7) Now call the same Skype userid on FreeSWITCH - This time the Skype
client will be rejected
That Skype instance is now broken no matter where you call it from
until FreeSWITCH is restarted.
This is exactly the same behavior as occurs with multiple Skype
clients. The problem appears to be mod_skypopen is not handling
hangups/cancels before the B leg answers.
Jason
On Tue, Sep 28, 2010 at 1:36 PM, Jason Jeffords <jason at cloudtree.net> wrote:
> We are seeing a "STATUS FINISHED" indication from Skype when a call
> is answered remotely. When this occurs, mod_skypopen says:
>
> 2010-09-28 17:22:55.741952 [DEBUG] skypopen_protocol.c:635 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 635
> ][interface2][-1, 7, 0] skype_call 74 is NOT MY call, ignoring
>
> In this example (see below) call 74 is in progress and the SIP messages
> are already sent. When the FINISHED indication is received, could the
> call be canceled (e.g. this is equivalent to the Skype caller hanging up
> on their end).
>
> Jason
>
> 2010-09-28 17:22:47.962165 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1, 0, 0] READING: |||CALL 74 CONF_ID 0|||
> 2010-09-28 17:22:47.991943 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1, 0, 0] READING: |||CALL 74 STATUS RINGING|||
> 2010-09-28 17:22:47.991943 [DEBUG] skypopen_protocol.c:579 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 579
> ][interface2][-1, 0, 0] NO ACTIVE calls in this moment, skype_call 74
> is RINGING, to ask PARTNER_DISPNAME and PARTNER_HANDLE
> 2010-09-28 17:22:47.991943 [DEBUG] skypopen_protocol.c:1541 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
> ][interface2][-1, 0, 0] SENDING: |||GET CALL 74 PARTNER_DISPNAME||||
> 2010-09-28 17:22:48.002019 [DEBUG] skypopen_protocol.c:1541 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
> ][interface2][-1, 0, 0] SENDING: |||GET CALL 74 PARTNER_HANDLE||||
> 2010-09-28 17:22:48.041940 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1, 0, 0] READING: |||CALL 74 PARTNER_DISPNAME Thomas
> Hazel|||
> 2010-09-28 17:22:48.041940 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1, 0, 0] READING: |||CALL 74 PARTNER_HANDLE
> stratusware|||
> 2010-09-28 17:22:48.041940 [DEBUG] skypopen_protocol.c:496 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 496
> ][interface2][-1, 0, 0] Call 74 go to skypopen_partner_handle_ring
> 2010-09-28 17:22:48.041940 [DEBUG] mod_skypopen.c:2437 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2437
> ][interface2][-1, 0, 0] NOT FOUND
> 2010-09-28 17:22:48.041940 [DEBUG] mod_skypopen.c:2049 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2049
> ][interface2][-1, 7, 0] 2 SESSION_REQUEST
> 03aeed34-cb25-11df-a2b6-3dee1bbd18ba
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:272 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 272
> ][interface2][-1, 7, 0] skypopen_tech_init SUCCESS
> 2010-09-28 17:22:48.061934 [NOTICE] switch_channel.c:779 New Channel
> skypopen/interface2 [03aeed34-cb25-11df-a2b6-3dee1bbd18ba]
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:2073
> (skypopen/interface2) State Change CS_NEW -> CS_INIT
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_session.c:1039 Send
> signal skypopen/interface2 [BREAK]
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:627 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
> ][interface2][-1, 7, 0] skypopen/interface2 CHANNEL got
> SWITCH_SIG_BREAK
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:2085 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2085
> ][interface2][-1, 7, 0] new_inbound_channel
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_state_machine.c:314
> (skypopen/interface2) Running State Change CS_INIT
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_state_machine.c:338
> (skypopen/interface2) State INIT
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:450
> (skypopen/interface2) State Change CS_INIT -> CS_ROUTING
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_session.c:1039 Send
> signal skypopen/interface2 [BREAK]
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:627 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
> ][interface2][-1, 7, 0] skypopen/interface2 CHANNEL got
> SWITCH_SIG_BREAK
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:451 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 451
> ][interface2][-1, 7, 0] interface2 CHANNEL INIT
> 03aeed34-cb25-11df-a2b6-3dee1bbd18ba
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_state_machine.c:338
> (skypopen/interface2) State INIT going to sleep
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_state_machine.c:314
> (skypopen/interface2) Running State Change CS_ROUTING
> 2010-09-28 17:22:48.061934 [DEBUG] switch_channel.c:1512
> (skypopen/interface2) Callstate Change DOWN -> RINGING
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_state_machine.c:341
> (skypopen/interface2) State ROUTING
> 2010-09-28 17:22:48.061934 [DEBUG] mod_skypopen.c:568 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 568
> ][interface2][-1, 7, 0] interface2 CHANNEL ROUTING
> 2010-09-28 17:22:48.061934 [DEBUG] switch_core_state_machine.c:77
> skypopen/interface2 Standard ROUTING
> 2010-09-28 17:22:48.061934 [INFO] mod_dialplan_xml.c:331 Processing
> Thomas Hazel <stratusware>->skype_inbound in context default
> Dialplan: skypopen/interface2 parsing [default->SkypeInbound] continue=false
> Dialplan: skypopen/interface2 Regex (PASS) [SkypeInbound]
> destination_number(skype_inbound) =~ /^skype_inbound$/ break=on-false
> Dialplan: skypopen/interface2 Action set(ignore_early_media=true)
> Dialplan: skypopen/interface2 Action
> set(toll_allow=domestic,international,local)
> Dialplan: skypopen/interface2 Action set(default_gateway=bandwidth.com)
> Dialplan: skypopen/interface2 Action
> set(effective_caller_id_name=${skype_user})
> Dialplan: skypopen/interface2 Action
> set(effective_caller_id_number=+18574883540)
> Dialplan: skypopen/interface2 Action
> bridge(sofia/gateway/${default_gateway}/+16037141687)
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:119
> (skypopen/interface2) State Change CS_ROUTING -> CS_EXECUTE
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_session.c:1039 Send
> signal skypopen/interface2 [BREAK]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:627 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
> ][interface2][-1, 7, 0] skypopen/interface2 CHANNEL got
> SWITCH_SIG_BREAK
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:341
> (skypopen/interface2) State ROUTING going to sleep
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:314
> (skypopen/interface2) Running State Change CS_EXECUTE
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:348
> (skypopen/interface2) State EXECUTE
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:585 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 585
> ][interface2][-1, 7, 0] interface2 CHANNEL EXECUTE
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:157
> skypopen/interface2 Standard EXECUTE
> EXECUTE skypopen/interface2 set(ignore_early_media=true)
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=26
> 2010-09-28 17:22:48.091944 [DEBUG] mod_dptools.c:854
> skypopen/interface2 SET [ignore_early_media]=[true]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=27
> EXECUTE skypopen/interface2 set(toll_allow=domestic,international,local)
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=26
> 2010-09-28 17:22:48.091944 [DEBUG] mod_dptools.c:854
> skypopen/interface2 SET [toll_allow]=[domestic,international,local]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=27
> EXECUTE skypopen/interface2 set(default_gateway=bandwidth.com)
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=26
> 2010-09-28 17:22:48.091944 [DEBUG] mod_dptools.c:854
> skypopen/interface2 SET [default_gateway]=[bandwidth.com]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=27
> EXECUTE skypopen/interface2 set(effective_caller_id_name=ct-user4)
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=26
> 2010-09-28 17:22:48.091944 [DEBUG] mod_dptools.c:854
> skypopen/interface2 SET [effective_caller_id_name]=[ct-user4]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=27
> EXECUTE skypopen/interface2 set(effective_caller_id_number=+18574883540)
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=26
> 2010-09-28 17:22:48.091944 [DEBUG] mod_dptools.c:854
> skypopen/interface2 SET [effective_caller_id_number]=[+18574883540]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=27
> EXECUTE skypopen/interface2 bridge(sofia/gateway/bandwidth.com/+16037141687)
> 2010-09-28 17:22:48.091944 [DEBUG] mod_skypopen.c:1061 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
> ][interface2][-1, 7, 0] MSG_ID=26
> 2010-09-28 17:22:48.091944 [NOTICE] switch_channel.c:779 New Channel
> sofia/external/+16037141687 [03b7082a-cb25-11df-a2b8-3dee1bbd18ba]
> 2010-09-28 17:22:48.091944 [DEBUG] mod_sofia.c:3899
> (sofia/external/+16037141687) State Change CS_NEW -> CS_INIT
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_session.c:1039 Send
> signal sofia/external/+16037141687 [BREAK]
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/+16037141687) Running State Change CS_INIT
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:338
> (sofia/external/+16037141687) State INIT
> 2010-09-28 17:22:48.091944 [DEBUG] mod_sofia.c:83
> sofia/external/+16037141687 SOFIA INIT
> 2010-09-28 17:22:48.091944 [DEBUG] mod_sofia.c:119
> (sofia/external/+16037141687) State Change CS_INIT -> CS_ROUTING
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_session.c:1039 Send
> signal sofia/external/+16037141687 [BREAK]
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:338
> (sofia/external/+16037141687) State INIT going to sleep
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/+16037141687) Running State Change CS_ROUTING
> 2010-09-28 17:22:48.091944 [DEBUG] switch_channel.c:1512
> (sofia/external/+16037141687) Callstate Change DOWN -> RINGING
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:341
> (sofia/external/+16037141687) State ROUTING
> 2010-09-28 17:22:48.091944 [DEBUG] mod_sofia.c:142
> sofia/external/+16037141687 SOFIA ROUTING
> 2010-09-28 17:22:48.091944 [DEBUG] switch_ivr_originate.c:66
> (sofia/external/+16037141687) State Change CS_ROUTING ->
> CS_CONSUME_MEDIA
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_session.c:1039 Send
> signal sofia/external/+16037141687 [BREAK]
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:341
> (sofia/external/+16037141687) State ROUTING going to sleep
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/+16037141687) Running State Change CS_CONSUME_MEDIA
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:360
> (sofia/external/+16037141687) State CONSUME_MEDIA
> 2010-09-28 17:22:48.091944 [DEBUG] switch_core_state_machine.c:360
> (sofia/external/+16037141687) State CONSUME_MEDIA going to sleep
> 2010-09-28 17:22:48.091944 [DEBUG] sofia.c:4399 Channel
> sofia/external/+16037141687 entering state [calling][0]
> 2010-09-28 17:22:49.701942 [INFO] sofia.c:703
> sofia/external/+16037141687 Update Callee ID to "+16037141687"
> <+16037141687>
> 2010-09-28 17:22:49.701942 [DEBUG] sofia.c:4399 Channel
> sofia/external/+16037141687 entering state [proceeding][183]
> 2010-09-28 17:22:49.701942 [DEBUG] sofia.c:4410 Remote SDP:
> v=0
> o=- 1285694568 1285694569 IN IP4 209.247.5.148
> s=-
> c=IN IP4 209.247.5.148
> t=0 0
> m=audio 63944 RTP/AVP 0 101
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
>
> 2010-09-28 17:22:49.701942 [DEBUG] sofia_glue.c:3851 Audio Codec
> Compare [PCMU:0:8000:20]/[L16:10:16000:20]
> 2010-09-28 17:22:49.701942 [DEBUG] sofia_glue.c:3851 Audio Codec
> Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
> 2010-09-28 17:22:49.701942 [DEBUG] sofia_glue.c:2446 Set Codec
> sofia/external/+16037141687 PCMU/8000 20 ms 160 samples
> 2010-09-28 17:22:49.701942 [DEBUG] sofia_glue.c:3941 Set 2833 dtmf
> send payload to 101
> 2010-09-28 17:22:49.701942 [DEBUG] sofia_glue.c:2686 AUDIO RTP
> [sofia/external/+16037141687] 173.203.197.16 port 16694 ->
> 209.247.5.148 port 63944 codec: 0 ms: 20
> 2010-09-28 17:22:49.701942 [DEBUG] switch_rtp.c:1413 Starting timer
> [soft] 160 bytes per 20ms
> 2010-09-28 17:22:49.711951 [DEBUG] sofia_glue.c:2896 Set 2833 dtmf
> send payload to 101
> 2010-09-28 17:22:49.711951 [DEBUG] sofia_glue.c:2901 Set 2833 dtmf
> receive payload to 101
> 2010-09-28 17:22:49.711951 [NOTICE] sofia_glue.c:3294 Pre-Answer
> sofia/external/+16037141687!
> 2010-09-28 17:22:49.711951 [DEBUG] switch_channel.c:2409
> (sofia/external/+16037141687) Callstate Change RINGING -> EARLY
> 2010-09-28 17:22:49.711951 [DEBUG] switch_channel.c:2449 Send signal
> skypopen/interface2 [BREAK]
> 2010-09-28 17:22:49.711951 [DEBUG] mod_skypopen.c:627 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
> ][interface2][-1, 7, 0] skypopen/interface2 CHANNEL got
> SWITCH_SIG_BREAK
> 2010-09-28 17:22:50.412029 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface3][-1, 0, 0] READING: |||USER cloud-tree-admin
> NROF_AUTHED_BUDDIES 8|||
> 2010-09-28 17:22:50.441981 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface3][-1, 0, 0] READING: |||USER cloud-tree-admin
> NROF_AUTHED_BUDDIES 7|||
> 2010-09-28 17:22:53.692056 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface3][-1, 0, 0] READING: |||USER ct-user4 TIMEZONE 72000|||
> 2010-09-28 17:22:55.741952 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1, 7, 0] READING: |||CALL 74 STATUS FINISHED|||
> 2010-09-28 17:22:55.741952 [DEBUG] skypopen_protocol.c:635 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 635
> ][interface2][-1, 7, 0] skype_call 74 is NOT MY call, ignoring
> 2010-09-28 17:23:15.982024 [DEBUG] sofia.c:4399 Channel
> sofia/external/+16037141687 entering state [completing][200]
> 2010-09-28 17:23:15.982024 [DEBUG] sofia.c:4407 Duplicate SDP
> v=0
> o=- 1285694568 1285694569 IN IP4 209.247.5.148
> s=-
> c=IN IP4 209.247.5.148
> t=0 0
> m=audio 63944 RTP/AVP 0 101
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
>
> 2010-09-28 17:23:15.992544 [DEBUG] sofia.c:4399 Channel
> sofia/external/+16037141687 entering state [ready][200]
> 2010-09-28 17:23:15.992544 [DEBUG] switch_channel.c:2555
> (sofia/external/+16037141687) Callstate Change EARLY -> ACTIVE
> 2010-09-28 17:23:15.992544 [DEBUG] switch_channel.c:2567 Send signal
> skypopen/interface2 [BREAK]
> 2010-09-28 17:23:15.992544 [DEBUG] mod_skypopen.c:627 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
> ][interface2][-1, 7, 0] skypopen/interface2 CHANNEL got
> SWITCH_SIG_BREAK
> 2010-09-28 17:23:15.992544 [NOTICE] sofia.c:4908 Channel
> [sofia/external/+16037141687] has been answered
> 2010-09-28 17:23:15.992544 [DEBUG] mod_skypopen.c:985 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 985
> ][interface2][-1, 7, 0] skypopen/interface2 CHANNEL got
> SWITCH_MESSAGE_INDICATE_ANSWER
> 2010-09-28 17:23:15.992544 [DEBUG] mod_skypopen.c:2546 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2546
> ][interface2][-1, 7, 0] NOT FOUND
> 2010-09-28 17:23:15.992544 [DEBUG] skypopen_protocol.c:1541 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
> ][interface2][-1,11, 0] SENDING: |||ALTER CALL 74 ANSWER||||
> 2010-09-28 17:23:16.011969 [DEBUG] mod_skypopen.c:2556 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2556
> ][interface2][-1,11, 0] We answered a Skype RING on skype_call 74
> 2010-09-28 17:23:16.011969 [DEBUG] mod_skypopen.c:2564 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2564
> ][interface2][-1,11, 0] NEW! name: interface2, state: 11,
> value=stratusware, tech_pvt->callid_number=stratusware,
> tech_pvt->skype_user=ct-user4
> 2010-09-28 17:23:16.042127 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1,11, 0] READING: |||ERROR 559 CALL: Action failed|||
> 2010-09-28 17:23:16.042127 [DEBUG] skypopen_protocol.c:236 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 236
> ][interface2][-1,11, 0] Skype got ERROR about a failed action
> (probably TRYING to ANSWER A CALL), let's go down: |||ERROR 559 CALL:
> Action failed|||
> 2010-09-28 17:23:16.042127 [DEBUG] skypopen_protocol.c:238 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 238
> ][interface2][-1,11,16] skype_call now is DOWN
> 2010-09-28 17:23:16.042127 [DEBUG] mod_skypopen.c:1271 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1271
> ][interface2][-1, 1,16] skype call ended
> 2010-09-28 17:23:16.042127 [DEBUG] switch_channel.c:2322
> (skypopen/interface2) Callstate Change RINGING -> HANGUP
> 2010-09-28 17:23:16.042127 [NOTICE] mod_skypopen.c:1282 Hangup
> skypopen/interface2 [CS_EXECUTE] [NORMAL_CLEARING]
> 2010-09-28 17:23:16.042127 [DEBUG] switch_channel.c:2338 Send signal
> skypopen/interface2 [KILL]
> 2010-09-28 17:23:16.042127 [DEBUG] mod_skypopen.c:606 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 606
> ][interface2][-1, 1,16] skypopen/interface2 CHANNEL got
> SWITCH_SIG_KILL
> 2010-09-28 17:23:16.042127 [DEBUG] skypopen_protocol.c:1541 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
> ][interface2][-1, 1,16] SENDING: |||ALTER CALL 74 END HANGUP||||
> 2010-09-28 17:23:16.061968 [DEBUG] switch_core_session.c:1039 Send
> signal skypopen/interface2 [BREAK]
> 2010-09-28 17:23:16.061968 [DEBUG] mod_skypopen.c:627 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
> ][interface2][-1, 1,16] skypopen/interface2 CHANNEL got
> SWITCH_SIG_BREAK
> 2010-09-28 17:23:16.371973 [DEBUG] skypopen_protocol.c:189 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
> ][interface2][-1, 0, 0] READING: |||ERROR 559 CALL: Action failed|||
> 2010-09-28 17:23:16.371973 [DEBUG] skypopen_protocol.c:245 rev
> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 245
> ][interface2][-1, 0, 0] Skype got ERROR about a failed action
> (probably TRYING to HANGUP A CALL), no problem: |||ERROR 559 CALL:
> Action failed|||
> 2010-09-28 17:23:29.121962 [DEBUG] switch_channel.c:2322
> (sofia/external/+16037141687) Callstate Change ACTIVE -> HANGUP
> 2010-09-28 17:23:29.121962 [NOTICE] sofia.c:522 Hangup
> sofia/external/+16037141687 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
> 2010-09-28 17:23:29.121962 [DEBUG] switch_channel.c:2338 Send signal
> sofia/external/+16037141687 [KILL]
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_session.c:1039 Send
> signal sofia/external/+16037141687 [BREAK]
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/+16037141687) Running State Change CS_HANGUP
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:535
> (sofia/external/+16037141687) State HANGUP
> 2010-09-28 17:23:29.121962 [DEBUG] mod_sofia.c:447
> sofia/external/+16037141687 Overriding SIP cause 480 with 200 from the
> other leg
> 2010-09-28 17:23:29.121962 [DEBUG] mod_sofia.c:453 Channel
> sofia/external/+16037141687 hanging up, cause: NORMAL_CLEARING
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:46
> sofia/external/+16037141687 Standard HANGUP, cause: NORMAL_CLEARING
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:535
> (sofia/external/+16037141687) State HANGUP going to sleep
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:333
> (sofia/external/+16037141687) State Change CS_HANGUP -> CS_REPORTING
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_session.c:1039 Send
> signal sofia/external/+16037141687 [BREAK]
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:314
> (sofia/external/+16037141687) Running State Change CS_REPORTING
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:595
> (sofia/external/+16037141687) State REPORTING
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:53
> sofia/external/+16037141687 Standard REPORTING, cause: NORMAL_CLEARING
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:595
> (sofia/external/+16037141687) State REPORTING going to sleep
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_state_machine.c:327
> (sofia/external/+16037141687) State Change CS_REPORTING -> CS_DESTROY
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_session.c:1039 Send
> signal sofia/external/+16037141687 [BREAK]
> 2010-09-28 17:23:29.121962 [DEBUG] switch_core_session.c:1202 Session
> 24 (sofia/external/+16037141687) Locked, Waiting on external entities
>
>
>
> On Tue, Sep 28, 2010 at 12:01 PM, Giovanni Maruzzelli <gmaruzz at gmail.com> wrote:
>> On Tue, Sep 28, 2010 at 5:26 PM, Jason Jeffords <jason at cloudtree.net> wrote:
>>> We did not realize this case is not supported, and it does indeed
>>> break mod_skypopen
>>> (specifically, it looks like mod_skypopen is ignoring the "answered"
>>> message from
>>> the Skype client indicating another client answered the call).
>>>
>>> Is there any way we could add this support?
>>
>> Only modifiying the mod_skypopen sources, and I'm not sure it's
>> feasible at all (ie: if the external skype clients notify the FS skype
>> clients they've answered), but maybe yes.
>>
>> -giovanni
>>
>>>
>>> Thanks in advance,
>>>
>>> Jason
>>>
>>> PS> Our use case is to have multiple instances with the same user ID on multiple
>>> servers and desktop clients. So this is a show stopper for us.
>>>
>>> On Tue, Sep 28, 2010 at 11:08 AM, Giovanni Maruzzelli <gmaruzz at gmail.com> wrote:
>>>> Hi Jason,
>>>>
>>>> Maybe I've not understood, so I ask explicitly: you have the same
>>>> skypeuserid running on the freeswitch server AND on the desktops?
>>>>
>>>> This is not supported, and will break the inner working of mod_skypopen.
>>>>
>>>> -giovanni
>>>>
>>>> On Tue, Sep 28, 2010 at 4:47 PM, Jason Jeffords <jason at cloudtree.net> wrote:
>>>>> 1) Call a Skype user on Freeswitch which then bridges to
>>>>> 1 or more SIP endpoints - this will simultaneous ring SIP
>>>>> and any desktop Skype instances you have open - it works
>>>>> every time as long as you answer the SIP endpoints
>>>>>
>>>>> 2) Answer the call with one of your desktop Skype instances
>>>>>
>>>>> 3) Call a Skype user again as in step 1 - this will now fail on both
>>>>> FreeSWITCH and your desktop clients
>>>>>
>>>>> mod_skypopen/FreeSWITCH is rejecting all subsequent calls,
>>>>> which forces a reject on the Skype network as well. It appears
>>>>> the call answering by the desktop Skype instance is not
>>>>> handled by mod_skypopen (it should probably cancel the
>>>>> outbound call request when it sees an external answer,
>>>>> perhaps by hangup?).
>>>>>
>>>>> The only way to fix the problem is a complete restart of the
>>>>> Skype instances on FreeSWITCH and FreeSWITCH itself.
>>>>>
>>>>> I have included a small portion of the failing log below (once
>>>>> mod_skypopen/FreeSWITCH system is wedged).
>>>>>
>>>>> Any help would be greatly appreciated.
>>>>>
>>>>> Thanks in advance,
>>>>>
>>>>> Jason
>>>>>
>>>>> 2010-09-28 14:38:14.797954 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1, 0, 0] READING: |||CALL 227 CONF_ID 0|||
>>>>> 2010-09-28 14:38:14.867970 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1, 0, 0] READING: |||CALL 227 STATUS RINGING|||
>>>>> 2010-09-28 14:38:14.867970 [DEBUG] skypopen_protocol.c:579 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 579
>>>>> ][interface4][-1, 0, 0] NO ACTIVE calls in this moment, skype_call 227
>>>>> is RINGING, to ask PARTNER_DISPNAME and PARTNER_HANDLE
>>>>> 2010-09-28 14:38:14.867970 [DEBUG] skypopen_protocol.c:1541 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
>>>>> ][interface4][-1, 0, 0] SENDING: |||GET CALL 227 PARTNER_DISPNAME||||
>>>>> 2010-09-28 14:38:14.917964 [DEBUG] skypopen_protocol.c:1541 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
>>>>> ][interface4][-1, 0, 0] SENDING: |||GET CALL 227 PARTNER_HANDLE||||
>>>>> 2010-09-28 14:38:15.247962 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1, 0, 0] READING: |||CALL 227 PARTNER_DISPNAME Thomas
>>>>> Hazel|||
>>>>> 2010-09-28 14:38:15.277958 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1, 0, 0] READING: |||CALL 227 PARTNER_HANDLE
>>>>> stratusware|||
>>>>> 2010-09-28 14:38:15.277958 [DEBUG] skypopen_protocol.c:496 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 496
>>>>> ][interface4][-1, 0, 0] Call 227 go to skypopen_partner_handle_ring
>>>>> 2010-09-28 14:38:15.707985 [DEBUG] mod_skypopen.c:2437 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2437
>>>>> ][interface4][-1, 0, 0] NOT FOUND
>>>>> 2010-09-28 14:38:15.838037 [DEBUG] mod_skypopen.c:2049 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2049
>>>>> ][interface4][-1, 7, 0] 2 SESSION_REQUEST
>>>>> 07602acc-cb0e-11df-ada1-018a94d3f22d
>>>>> 2010-09-28 14:38:15.898008 [DEBUG] mod_skypopen.c:272 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 272
>>>>> ][interface4][-1, 7, 0] skypopen_tech_init SUCCESS
>>>>> 2010-09-28 14:38:15.898008 [NOTICE] switch_channel.c:779 New Channel
>>>>> skypopen/interface4 [07602acc-cb0e-11df-ada1-018a94d3f22d]
>>>>> 2010-09-28 14:38:15.898008 [DEBUG] mod_skypopen.c:2073
>>>>> (skypopen/interface4) State Change CS_NEW -> CS_INIT
>>>>> 2010-09-28 14:38:15.898008 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:15.898008 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] mod_skypopen.c:2085 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2085
>>>>> ][interface4][-1, 7, 0] new_inbound_channel
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] switch_core_state_machine.c:314
>>>>> (skypopen/interface4) Running State Change CS_INIT
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] switch_core_state_machine.c:338
>>>>> (skypopen/interface4) State INIT
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] mod_skypopen.c:450
>>>>> (skypopen/interface4) State Change CS_INIT -> CS_ROUTING
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] mod_skypopen.c:451 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 451
>>>>> ][interface4][-1, 7, 0] interface4 CHANNEL INIT
>>>>> 07602acc-cb0e-11df-ada1-018a94d3f22d
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] switch_core_state_machine.c:338
>>>>> (skypopen/interface4) State INIT going to sleep
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] switch_core_state_machine.c:314
>>>>> (skypopen/interface4) Running State Change CS_ROUTING
>>>>> 2010-09-28 14:38:15.937986 [DEBUG] switch_channel.c:1512
>>>>> (skypopen/interface4) Callstate Change DOWN -> RINGING
>>>>> 2010-09-28 14:38:15.947959 [DEBUG] switch_core_state_machine.c:341
>>>>> (skypopen/interface4) State ROUTING
>>>>> 2010-09-28 14:38:15.967968 [DEBUG] mod_skypopen.c:568 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 568
>>>>> ][interface4][-1, 7, 0] interface4 CHANNEL ROUTING
>>>>> 2010-09-28 14:38:15.967968 [DEBUG] switch_core_state_machine.c:77
>>>>> skypopen/interface4 Standard ROUTING
>>>>> 2010-09-28 14:38:15.947959 [DEBUG] mod_skypopen.c:942 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 942
>>>>> ][interface4][-1, 7, 0] interface4 CHANNEL ANSWER
>>>>> bb88b0c2-cb0a-11df-ad99-018a94d3f22d
>>>>> 2010-09-28 14:38:15.977964 [DEBUG] mod_skypopen.c:947 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 947
>>>>> ][interface4][-1, 7, 0] ANSWERED!
>>>>> 2010-09-28 14:38:15.977964 [DEBUG] mod_skypopen.c:1008 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1008
>>>>> ][interface4][-1, 7, 0] Synching audio
>>>>> 2010-09-28 14:38:15.997965 [DEBUG] switch_core_session.c:658 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:15.997965 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:15.997965 [DEBUG] switch_channel.c:2555
>>>>> (skypopen/interface4) Callstate Change RINGING -> ACTIVE
>>>>> 2010-09-28 14:38:16.007958 [INFO] mod_dialplan_xml.c:331 Processing
>>>>> Thomas Hazel <stratusware>->skype_inbound in context default
>>>>> 2010-09-28 14:38:16.048001 [NOTICE] switch_ivr_originate.c:3315
>>>>> Channel [skypopen/interface4] has been answered
>>>>> 2010-09-28 14:38:16.048001 [DEBUG] mod_skypopen.c:1014 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1014
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_MESSAGE_INDICATE_AUDIO_SYNC
>>>>> 2010-09-28 14:38:16.048001 [DEBUG] mod_skypopen.c:1033 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1033
>>>>> ][interface4][-1, 7, 0] Synching audio
>>>>> 2010-09-28 14:38:16.097966 [DEBUG] switch_ivr_originate.c:3360
>>>>> Originate Resulted in Success: [sofia/external/+16037141687]
>>>>> 2010-09-28 14:38:16.179398 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface1][-1, 0, 0] READING: |||USER ct-user2 NROF_AUTHED_BUDDIES
>>>>> 3|||
>>>>> 2010-09-28 14:38:16.187965 [DEBUG] mod_skypopen.c:1014 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1014
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_MESSAGE_INDICATE_AUDIO_SYNC
>>>>> 2010-09-28 14:38:16.187965 [DEBUG] mod_skypopen.c:1033 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1033
>>>>> ][interface4][-1, 7, 0] Synching audio
>>>>> 2010-09-28 14:38:16.297970 [WARNING] switch_ivr_bridge.c:1241 Bridge
>>>>> Failed skypopen/interface4->sofia/external/+16037141687
>>>>> 2010-09-28 14:38:16.337946 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 7, 0] MSG_ID=5
>>>>> 2010-09-28 14:38:16.337946 [DEBUG] switch_core_session.c:658 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:16.337946 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:16.347942 [DEBUG] switch_channel.c:2322
>>>>> (skypopen/interface4) Callstate Change ACTIVE -> HANGUP
>>>>> 2010-09-28 14:38:16.358103 [NOTICE] switch_ivr_bridge.c:1280 Hangup
>>>>> skypopen/interface4 [CS_EXECUTE] [NORMAL_CLEARING]
>>>>> 2010-09-28 14:38:16.358103 [DEBUG] switch_channel.c:2338 Send signal
>>>>> skypopen/interface4 [KILL]
>>>>> 2010-09-28 14:38:16.358103 [DEBUG] mod_skypopen.c:606 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 606
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_KILL
>>>>> 2010-09-28 14:38:16.358103 [DEBUG] skypopen_protocol.c:1541 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
>>>>> ][interface4][-1, 7, 0] SENDING: |||ALTER CALL 227 END HANGUP||||
>>>>> 2010-09-28 14:38:16.377945 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:16.377945 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 7, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:16.377945 [NOTICE] switch_core_session.c:1220 Session
>>>>> 18 (sofia/external/+16037141687) Ended
>>>>> 2010-09-28 14:38:16.377945 [NOTICE] switch_core_session.c:1222 Close
>>>>> Channel sofia/external/+16037141687 [CS_DESTROY]
>>>>> 2010-09-28 14:38:16.387943 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1, 7, 0] READING: |||ALTER CALL 227 END HANGUP|||
>>>>> 2010-09-28 14:38:16.387943 [DEBUG] switch_core_session.c:1909
>>>>> skypopen/interface4 skip receive message [APPLICATION_EXEC_COMPLETE]
>>>>> (channel is hungup already)
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:427
>>>>> (sofia/external/+16037141687) Callstate Change HANGUP -> DOWN
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:348
>>>>> (skypopen/interface4) State EXECUTE going to sleep
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:314
>>>>> (skypopen/interface4) Running State Change CS_HANGUP
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:535
>>>>> (skypopen/interface4) State HANGUP
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] mod_skypopen.c:541 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 541
>>>>> ][interface4][-1,10, 0] interface4 CHANNEL HANGUP
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:46
>>>>> skypopen/interface4 Standard HANGUP, cause: NORMAL_CLEARING
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:535
>>>>> (skypopen/interface4) State HANGUP going to sleep
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:333
>>>>> (skypopen/interface4) State Change CS_HANGUP -> CS_REPORTING
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:314
>>>>> (skypopen/interface4) Running State Change CS_REPORTING
>>>>> 2010-09-28 14:38:16.428193 [DEBUG] switch_core_state_machine.c:595
>>>>> (skypopen/interface4) State REPORTING
>>>>> 2010-09-28 14:38:16.507974 [DEBUG] switch_core_state_machine.c:53
>>>>> skypopen/interface4 Standard REPORTING, cause: NORMAL_CLEARING
>>>>> 2010-09-28 14:38:16.507974 [DEBUG] switch_core_state_machine.c:595
>>>>> (skypopen/interface4) State REPORTING going to sleep
>>>>> 2010-09-28 14:38:16.507974 [DEBUG] switch_core_state_machine.c:327
>>>>> (skypopen/interface4) State Change CS_REPORTING -> CS_DESTROY
>>>>> 2010-09-28 14:38:16.507974 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:16.507974 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:16.517965 [DEBUG] switch_core_session.c:1202 Session
>>>>> 17 (skypopen/interface4) Locked, Waiting on external entities
>>>>> 2010-09-28 14:38:16.517965 [NOTICE] switch_core_session.c:1220 Session
>>>>> 17 (skypopen/interface4) Ended
>>>>> 2010-09-28 14:38:16.517965 [NOTICE] switch_core_session.c:1222 Close
>>>>> Channel skypopen/interface4 [CS_DESTROY]
>>>>> 2010-09-28 14:38:16.517965 [DEBUG] switch_core_state_machine.c:427
>>>>> (skypopen/interface4) Callstate Change HANGUP -> DOWN
>>>>> 2010-09-28 14:38:16.517965 [DEBUG] switch_core_state_machine.c:430
>>>>> (skypopen/interface4) Running State Change CS_DESTROY
>>>>> 2010-09-28 14:38:16.517965 [DEBUG] switch_core_state_machine.c:440
>>>>> (skypopen/interface4) State DESTROY
>>>>> 2010-09-28 14:38:16.517965 [DEBUG] mod_skypopen.c:464 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 464
>>>>> ][interface4][-1, 0, 0] interface4 CHANNEL DESTROY
>>>>> bb88b0c2-cb0a-11df-ad99-018a94d3f22d
>>>>> 2010-09-28 14:38:16.547962 [DEBUG] switch_core_state_machine.c:60
>>>>> skypopen/interface4 Standard DESTROY
>>>>> 2010-09-28 14:38:16.547962 [DEBUG] switch_core_state_machine.c:440
>>>>> (skypopen/interface4) State DESTROY going to sleep
>>>>> 2010-09-28 14:38:16.577977 [DEBUG] switch_core_state_machine.c:430
>>>>> (sofia/external/+16037141687) Running State Change CS_DESTROY
>>>>> 2010-09-28 14:38:16.597962 [DEBUG] switch_core_state_machine.c:440
>>>>> (sofia/external/+16037141687) State DESTROY
>>>>> 2010-09-28 14:38:16.597962 [DEBUG] mod_sofia.c:358
>>>>> sofia/external/+16037141687 SOFIA DESTROY
>>>>> 2010-09-28 14:38:16.637965 [DEBUG] switch_core_state_machine.c:60
>>>>> sofia/external/+16037141687 Standard DESTROY
>>>>> 2010-09-28 14:38:16.637965 [DEBUG] switch_core_state_machine.c:440
>>>>> (sofia/external/+16037141687) State DESTROY going to sleep
>>>>> 2010-09-28 14:38:17.381259 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1, 0, 0] READING: |||CALL 227 STATUS REFUSED|||
>>>>> 2010-09-28 14:38:17.390474 [DEBUG] skypopen_protocol.c:666 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 666
>>>>> ][interface4][-1, 0, 0] we REFUSED skype_call 227
>>>>> Dialplan: skypopen/interface4 parsing [default->SkypeInbound] continue=false
>>>>> Dialplan: skypopen/interface4 Regex (PASS) [SkypeInbound]
>>>>> destination_number(skype_inbound) =~ /^skype_inbound$/ break=on-false
>>>>> Dialplan: skypopen/interface4 Action set(ignore_early_media=true)
>>>>> Dialplan: skypopen/interface4 Action
>>>>> set(toll_allow=domestic,international,local)
>>>>> Dialplan: skypopen/interface4 Action set(default_gateway=bandwidth.com)
>>>>> Dialplan: skypopen/interface4 Action set(effective_caller_id_name=Thomas Hazel)
>>>>> Dialplan: skypopen/interface4 Action
>>>>> set(effective_caller_id_number=+16174190921)
>>>>> Dialplan: skypopen/interface4 Action ring_ready()
>>>>> Dialplan: skypopen/interface4 Action set(hangup_after_bridge=true)
>>>>> Dialplan: skypopen/interface4 Action
>>>>> bridge(sofia/gateway/${default_gateway}/+16037141687)
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] switch_core_state_machine.c:119
>>>>> (skypopen/interface4) State Change CS_ROUTING -> CS_EXECUTE
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] switch_core_state_machine.c:341
>>>>> (skypopen/interface4) State ROUTING going to sleep
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] switch_core_state_machine.c:314
>>>>> (skypopen/interface4) Running State Change CS_EXECUTE
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] switch_core_state_machine.c:348
>>>>> (skypopen/interface4) State EXECUTE
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:585 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 585
>>>>> ][interface4][-1, 0, 0] interface4 CHANNEL EXECUTE
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] switch_core_state_machine.c:157
>>>>> skypopen/interface4 Standard EXECUTE
>>>>> EXECUTE skypopen/interface4 set(ignore_early_media=true)
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_dptools.c:854
>>>>> skypopen/interface4 SET [ignore_early_media]=[true]
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 set(toll_allow=domestic,international,local)
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_dptools.c:854
>>>>> skypopen/interface4 SET [toll_allow]=[domestic,international,local]
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 set(default_gateway=bandwidth.com)
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_dptools.c:854
>>>>> skypopen/interface4 SET [default_gateway]=[bandwidth.com]
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 set(effective_caller_id_name=Thomas Hazel)
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_dptools.c:854
>>>>> skypopen/interface4 SET [effective_caller_id_name]=[Thomas Hazel]
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 set(effective_caller_id_number=+16174190921)
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_dptools.c:854
>>>>> skypopen/interface4 SET [effective_caller_id_number]=[+16174190921]
>>>>> 2010-09-28 14:38:17.967960 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 ring_ready()
>>>>> 2010-09-28 14:38:18.007957 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:18.007957 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=7
>>>>> 2010-09-28 14:38:18.007957 [DEBUG] switch_core_session.c:658 Send
>>>>> signal skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:18.007957 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:18.007957 [NOTICE] mod_dptools.c:514 Ring Ready
>>>>> skypopen/interface4!
>>>>> 2010-09-28 14:38:18.007957 [NOTICE] mod_dptools.c:514 Ring-Ready
>>>>> skypopen/interface4!
>>>>> 2010-09-28 14:38:18.037964 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 set(hangup_after_bridge=true)
>>>>> 2010-09-28 14:38:18.047977 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:18.047977 [DEBUG] mod_dptools.c:854
>>>>> skypopen/interface4 SET [hangup_after_bridge]=[true]
>>>>> 2010-09-28 14:38:18.069062 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=27
>>>>> EXECUTE skypopen/interface4 bridge(sofia/gateway/bandwidth.com/+16037141687)
>>>>> 2010-09-28 14:38:18.069062 [DEBUG] mod_skypopen.c:1061 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1061
>>>>> ][interface4][-1, 0, 0] MSG_ID=26
>>>>> 2010-09-28 14:38:18.117977 [NOTICE] switch_channel.c:779 New Channel
>>>>> sofia/external/+16037141687 [08bcfb02-cb0e-11df-ada3-018a94d3f22d]
>>>>> 2010-09-28 14:38:18.137885 [DEBUG] mod_sofia.c:3899
>>>>> (sofia/external/+16037141687) State Change CS_NEW -> CS_INIT
>>>>> 2010-09-28 14:38:18.137885 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal sofia/external/+16037141687 [BREAK]
>>>>> 2010-09-28 14:38:18.147956 [DEBUG] switch_core_state_machine.c:314
>>>>> (sofia/external/+16037141687) Running State Change CS_INIT
>>>>> 2010-09-28 14:38:18.147956 [DEBUG] switch_core_state_machine.c:338
>>>>> (sofia/external/+16037141687) State INIT
>>>>> 2010-09-28 14:38:18.147956 [DEBUG] mod_sofia.c:83
>>>>> sofia/external/+16037141687 SOFIA INIT
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] mod_sofia.c:119
>>>>> (sofia/external/+16037141687) State Change CS_INIT -> CS_ROUTING
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal sofia/external/+16037141687 [BREAK]
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:338
>>>>> (sofia/external/+16037141687) State INIT going to sleep
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:314
>>>>> (sofia/external/+16037141687) Running State Change CS_ROUTING
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_channel.c:1512
>>>>> (sofia/external/+16037141687) Callstate Change DOWN -> RINGING
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:341
>>>>> (sofia/external/+16037141687) State ROUTING
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] mod_sofia.c:142
>>>>> sofia/external/+16037141687 SOFIA ROUTING
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_ivr_originate.c:66
>>>>> (sofia/external/+16037141687) State Change CS_ROUTING ->
>>>>> CS_CONSUME_MEDIA
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal sofia/external/+16037141687 [BREAK]
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:341
>>>>> (sofia/external/+16037141687) State ROUTING going to sleep
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:314
>>>>> (sofia/external/+16037141687) Running State Change CS_CONSUME_MEDIA
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:360
>>>>> (sofia/external/+16037141687) State CONSUME_MEDIA
>>>>> 2010-09-28 14:38:18.267973 [DEBUG] switch_core_state_machine.c:360
>>>>> (sofia/external/+16037141687) State CONSUME_MEDIA going to sleep
>>>>> 2010-09-28 14:38:18.347964 [DEBUG] sofia.c:4399 Channel
>>>>> sofia/external/+16037141687 entering state [calling][0]
>>>>> 2010-09-28 14:38:20.068043 [INFO] sofia.c:703
>>>>> sofia/external/+16037141687 Update Callee ID to "+16037141687"
>>>>> <+16037141687>
>>>>> 2010-09-28 14:38:20.068043 [DEBUG] sofia.c:4399 Channel
>>>>> sofia/external/+16037141687 entering state [proceeding][183]
>>>>> 2010-09-28 14:38:20.068043 [DEBUG] sofia.c:4410 Remote SDP:
>>>>> v=0
>>>>> o=- 1285684698 1285684699 IN IP4 63.215.27.71
>>>>> s=-
>>>>> c=IN IP4 63.215.27.71
>>>>> t=0 0
>>>>> m=audio 64508 RTP/AVP 0 101
>>>>> a=rtpmap:101 telephone-event/8000
>>>>> a=fmtp:101 0-16
>>>>> a=ptime:20
>>>>>
>>>>> 2010-09-28 14:38:20.068043 [DEBUG] sofia_glue.c:3851 Audio Codec
>>>>> Compare [PCMU:0:8000:20]/[PCMU:0:8000:20]
>>>>> 2010-09-28 14:38:20.068043 [DEBUG] sofia_glue.c:2446 Set Codec
>>>>> sofia/external/+16037141687 PCMU/8000 20 ms 160 samples
>>>>> 2010-09-28 14:38:20.068043 [DEBUG] sofia_glue.c:3941 Set 2833 dtmf
>>>>> send payload to 101
>>>>> 2010-09-28 14:38:20.068043 [DEBUG] sofia_glue.c:2686 AUDIO RTP
>>>>> [sofia/external/+16037141687] 173.203.197.16 port 29798 ->
>>>>> 63.215.27.71 port 64508 codec: 0 ms: 20
>>>>> 2010-09-28 14:38:20.147938 [DEBUG] switch_rtp.c:1413 Starting timer
>>>>> [soft] 160 bytes per 20ms
>>>>> 2010-09-28 14:38:20.147938 [DEBUG] sofia_glue.c:2896 Set 2833 dtmf
>>>>> send payload to 101
>>>>> 2010-09-28 14:38:20.147938 [DEBUG] sofia_glue.c:2901 Set 2833 dtmf
>>>>> receive payload to 101
>>>>> 2010-09-28 14:38:20.147938 [NOTICE] sofia_glue.c:3294 Pre-Answer
>>>>> sofia/external/+16037141687!
>>>>> 2010-09-28 14:38:20.147938 [DEBUG] switch_channel.c:2409
>>>>> (sofia/external/+16037141687) Callstate Change RINGING -> EARLY
>>>>> 2010-09-28 14:38:20.147938 [DEBUG] switch_channel.c:2449 Send signal
>>>>> skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:20.147938 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:40.417986 [DEBUG] sofia.c:4399 Channel
>>>>> sofia/external/+16037141687 entering state [completing][200]
>>>>> 2010-09-28 14:38:40.417986 [DEBUG] sofia.c:4407 Duplicate SDP
>>>>> v=0
>>>>> o=- 1285684698 1285684699 IN IP4 63.215.27.71
>>>>> s=-
>>>>> c=IN IP4 63.215.27.71
>>>>> t=0 0
>>>>> m=audio 64508 RTP/AVP 0 101
>>>>> a=rtpmap:101 telephone-event/8000
>>>>> a=fmtp:101 0-16
>>>>> a=ptime:20
>>>>>
>>>>> 2010-09-28 14:38:40.417986 [DEBUG] sofia.c:4399 Channel
>>>>> sofia/external/+16037141687 entering state [ready][200]
>>>>> 2010-09-28 14:38:40.417986 [DEBUG] switch_channel.c:2555
>>>>> (sofia/external/+16037141687) Callstate Change EARLY -> ACTIVE
>>>>> 2010-09-28 14:38:40.417986 [DEBUG] switch_channel.c:2567 Send signal
>>>>> skypopen/interface4 [BREAK]
>>>>> 2010-09-28 14:38:40.437977 [DEBUG] mod_skypopen.c:627 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 627
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_SIG_BREAK
>>>>> 2010-09-28 14:38:40.437977 [NOTICE] sofia.c:4908 Channel
>>>>> [sofia/external/+16037141687] has been answered
>>>>> 2010-09-28 14:38:40.437977 [DEBUG] mod_skypopen.c:985 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 985
>>>>> ][interface4][-1, 0, 0] skypopen/interface4 CHANNEL got
>>>>> SWITCH_MESSAGE_INDICATE_ANSWER
>>>>> 2010-09-28 14:38:40.458166 [DEBUG] mod_skypopen.c:2546 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2546
>>>>> ][interface4][-1, 0, 0] NOT FOUND
>>>>> 2010-09-28 14:38:40.458166 [DEBUG] skypopen_protocol.c:1541 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1541
>>>>> ][interface4][-1,11, 0] SENDING: |||ALTER CALL 227 ANSWER||||
>>>>> 2010-09-28 14:38:40.467976 [DEBUG] mod_skypopen.c:2556 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2556
>>>>> ][interface4][-1,11, 0] We answered a Skype RING on skype_call 227
>>>>> 2010-09-28 14:38:40.467976 [DEBUG] mod_skypopen.c:2564 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 2564
>>>>> ][interface4][-1,11, 0] NEW! name: interface4, state: 11,
>>>>> value=stratusware, tech_pvt->callid_number=stratusware,
>>>>> tech_pvt->skype_user=jjeffords.com
>>>>> 2010-09-28 14:38:40.487975 [DEBUG] skypopen_protocol.c:189 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 189
>>>>> ][interface4][-1,11, 0] READING: |||ERROR 559 CALL: Action failed|||
>>>>> 2010-09-28 14:38:40.487975 [DEBUG] skypopen_protocol.c:236 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 236
>>>>> ][interface4][-1,11, 0] Skype got ERROR about a failed action
>>>>> (probably TRYING to ANSWER A CALL), let's go down: |||ERROR 559 CALL:
>>>>> Action failed|||
>>>>> 2010-09-28 14:38:40.487975 [DEBUG] skypopen_protocol.c:238 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 238
>>>>> ][interface4][-1,11,16] skype_call now is DOWN
>>>>> 2010-09-28 14:38:40.487975 [DEBUG] mod_skypopen.c:1271 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1271
>>>>> ][interface4][-1, 1,16] skype call ended
>>>>> 2010-09-28 14:38:40.487975 [DEBUG] mod_skypopen.c:1288 rev
>>>>> git2svn-syncpoint-master-372-gce352bc[(nil)|37 ][DEBUG_SKYPE 1288
>>>>> ][interface4][-1, 1,16] no session
>>>>> 2010-09-28 14:38:47.227969 [DEBUG] switch_channel.c:2322
>>>>> (sofia/external/+16037141687) Callstate Change ACTIVE -> HANGUP
>>>>> 2010-09-28 14:38:47.227969 [NOTICE] sofia.c:522 Hangup
>>>>> sofia/external/+16037141687 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
>>>>> 2010-09-28 14:38:47.227969 [DEBUG] switch_channel.c:2338 Send signal
>>>>> sofia/external/+16037141687 [KILL]
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal sofia/external/+16037141687 [BREAK]
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:314
>>>>> (sofia/external/+16037141687) Running State Change CS_HANGUP
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:535
>>>>> (sofia/external/+16037141687) State HANGUP
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] mod_sofia.c:447
>>>>> sofia/external/+16037141687 Overriding SIP cause 480 with 200 from the
>>>>> other leg
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] mod_sofia.c:453 Channel
>>>>> sofia/external/+16037141687 hanging up, cause: NORMAL_CLEARING
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:46
>>>>> sofia/external/+16037141687 Standard HANGUP, cause: NORMAL_CLEARING
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:535
>>>>> (sofia/external/+16037141687) State HANGUP going to sleep
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:333
>>>>> (sofia/external/+16037141687) State Change CS_HANGUP -> CS_REPORTING
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal sofia/external/+16037141687 [BREAK]
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:314
>>>>> (sofia/external/+16037141687) Running State Change CS_REPORTING
>>>>> 2010-09-28 14:38:47.238185 [DEBUG] switch_core_state_machine.c:595
>>>>> (sofia/external/+16037141687) State REPORTING
>>>>> 2010-09-28 14:38:47.258201 [DEBUG] switch_core_state_machine.c:53
>>>>> sofia/external/+16037141687 Standard REPORTING, cause: NORMAL_CLEARING
>>>>> 2010-09-28 14:38:47.258201 [DEBUG] switch_core_state_machine.c:595
>>>>> (sofia/external/+16037141687) State REPORTING going to sleep
>>>>> 2010-09-28 14:38:47.258201 [DEBUG] switch_core_state_machine.c:327
>>>>> (sofia/external/+16037141687) State Change CS_REPORTING -> CS_DESTROY
>>>>> 2010-09-28 14:38:47.258201 [DEBUG] switch_core_session.c:1039 Send
>>>>> signal sofia/external/+16037141687 [BREAK]
>>>>> 2010-09-28 14:38:47.258201 [DEBUG] switch_core_session.c:1202 Session
>>>>> 20 (sofia/external/+16037141687) Locked, Waiting on external entities
>>>>>
>>>>> _______________________________________________
>>>>> FreeSWITCH-users mailing list
>>>>> FreeSWITCH-users at lists.freeswitch.org
>>>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>>>> http://www.freeswitch.org
>>>>>
>>>>
>>>>
>>>>
>>>> --
>>>> Sincerely,
>>>>
>>>> Giovanni Maruzzelli
>>>> Cell : +39-347-2665618
>>>>
>>>> _______________________________________________
>>>> FreeSWITCH-users mailing list
>>>> FreeSWITCH-users at lists.freeswitch.org
>>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>>> http://www.freeswitch.org
>>>>
>>>
>>>
>>>
>>> --
>>> jason jeffords | founder & cto cloudtree
>>> c | +1 617 299 6242
>>> 850 winter street I waltham ma 02451
>>> jason at cloudtree.net
>>>
>>> _______________________________________________
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>
>>
>>
>> --
>> Sincerely,
>>
>> Giovanni Maruzzelli
>> Cell : +39-347-2665618
>>
>> _______________________________________________
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>
>
>
> --
> jason jeffords | founder & cto cloudtree
> c | +1 617 299 6242
> 850 winter street I waltham ma 02451
> jason at cloudtree.net
>
--
jason jeffords | founder & cto cloudtree
c | +1 617 299 6242
850 winter street I waltham ma 02451
jason at cloudtree.net
More information about the FreeSWITCH-users
mailing list