[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 10:36:24 PDT 2010


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



More information about the FreeSWITCH-users mailing list