[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 13:38:08 PDT 2010
Hi Giovanni
I have created Issue FS-2743 to track the single instance early hangup issues.
http://jira.freeswitch.org/browse/FS-2743
Thanks for all your help,
Jason
On Tue, Sep 28, 2010 at 3:12 PM, Jason Jeffords <jason at cloudtree.net> wrote:
> Thanks Giovanni,
>
> We will do that ASAP.
>
> Jason
>
> On Tue, Sep 28, 2010 at 2:48 PM, Giovanni Maruzzelli <gmaruzz at gmail.com> wrote:
>> Please open a Jira on this one, and attach a complete debug session to
>> it (as a text file attachment).
>>
>> -giovanni
>>
>> On Tue, Sep 28, 2010 at 8:14 PM, Jason Jeffords <jason at cloudtree.net> wrote:
>>> 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
>>>
>>> _______________________________________________
>>> 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