[Freeswitch-users] mod_skypopen Refusing Skype Calls Once a Call is Answered Via a Desktop Skype Client

Giovanni Maruzzelli gmaruzz at gmail.com
Tue Sep 28 08:08:53 PDT 2010


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



More information about the FreeSWITCH-users mailing list