Yes, that is exactly my case. 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? 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@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@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@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@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@cloudtree.net