On Wed, Sep 9, 2009 at 10:04 PM, Dmitry Bely <dmitry.bely@gmail.com> wrote:
I have a problem. After 10-20 minutes of Skype talk via cordless phone connected to ATA the latter erroneously generated DTMF 'D' event. Then skypiax looses connection while the call remain active in Skype client. The only way to terminate it is to ask another party to hang up:
Ciao Dmitry, could you please fill a Jira with the same infos? http://wiki.freeswitch.org/wiki/Skypiax#How_To_Report_BUGS_and_Feature_Reque... That is the standard and correct procedure for bugs, so the devs can follow up on it. -giovanni
(...)
2009-09-09 22:20:07.474051 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 5,21] READING: |||CALL 307 DURATION 500||| 2009-09-09 22:20:08.473755 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 5,21] READING: |||CALL 307 DURATION 501||| 2009-09-09 22:20:09.474247 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 5,21] READING: |||CALL 307 DURATION 502||| 2009-09-09 22:20:10.474611 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 5,21] READING: |||CALL 307 DURATION 503||| 2009-09-09 22:20:11.474456 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 5,21] READING: |||CALL 307 DURATION 504||| 2009-09-09 22:20:12.411664 [DEBUG] switch_rtp.c:2239 RTP RECV DTMF D:2000 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:633 rev 14771[(nil)|37 ][DEBUG_SKYPE 633 ][interface1][-1, 5,21] interface1 CHANNEL SEND_DTMF 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:634 rev 14771[(nil)|37 ][DEBUG_SKYPE 634 ][interface1][-1, 5,21] DTMF: D 2009-09-09 22:20:12.411664 [DEBUG] skypiax_protocol.c:882 rev 14707[(nil)|37 ][DEBUG_SKYPE 882 ][interface1][-1, 5,21] DIGIT received: D 2009-09-09 22:20:12.411664 [DEBUG] skypiax_protocol.c:1352 rev 14707[(nil)|37 ][DEBUG_SKYPE 1352 ][interface1][-1, 5,21] SENDING: |||SET CALL 307 DTMF D|||| 2009-09-09 22:20:12.411664 [DEBUG] skypiax_protocol.c:1530 rev 14707[(nil)|37 ][DEBUG_SKYPE 1530 ][interface1][-1, 5,21] Got a 'continue' XAtom without a previous 'begin'. It's value (between vertical bars) is=|||allowed call prop||| 2009-09-09 22:20:12.411664 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 5,21] READING: |||ERROR 21 Unknown/dis||| 2009-09-09 22:20:12.411664 [ERR] skypiax_protocol.c:144 rev 14707[(nil)|37 ][ERRORA 144 ][interface1][-1, 5,21] Skype got ERROR: |||ERROR 21 Unknown/dis||| 2009-09-09 22:20:12.411664 [ERR] skypiax_protocol.c:146 rev 14707[(nil)|37 ][ERRORA 146 ][interface1][-1, 5,16] skype_call now is DOWN 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:1011 rev 14771[(nil)|37 ][DEBUG_SKYPE 1011 ][interface1][-1, 1,16] skype call ended 2009-09-09 22:20:12.411664 [NOTICE] mod_skypiax.c:1022 Hangup skypiax/interface1/user2 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2009-09-09 22:20:12.411664 [DEBUG] switch_channel.c:1715 Send signal skypiax/interface1/user2 [KILL] 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:566 rev 14771[(nil)|37 ][DEBUG_SKYPE 566 ][interface1][-1, 1,16] interface1 CHANNEL KILL_CHANNEL 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:569 rev 14771[(nil)|37 ][DEBUG_SKYPE 569 ][interface1][-1, 1,16] skypiax/interface1/user2 CHANNEL got SWITCH_SIG_KILL 2009-09-09 22:20:12.411664 [DEBUG] switch_core_session.c:932 Send signal skypiax/interface1/user2 [BREAK] 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:566 rev 14771[(nil)|37 ][DEBUG_SKYPE 566 ][interface1][-1, 1,16] interface1 CHANNEL KILL_CHANNEL 2009-09-09 22:20:12.411664 [DEBUG] mod_skypiax.c:589 rev 14771[(nil)|37 ][DEBUG_SKYPE 589 ][interface1][-1, 1,16] skypiax/interface1/user2 CHANNEL got SWITCH_SIG_BREAK 2009-09-09 22:20:12.428590 [DEBUG] skypiax_protocol.c:670 rev 14707[(nil)|37 ][DEBUG_SKYPE 670 ][interface1][-1, 1,16] Skype incoming audio GONE 2009-09-09 22:20:12.428590 [DEBUG] mod_skypiax.c:702 rev 14771[(nil)|37 ][DEBUG_SKYPE 702 ][interface1][-1, 1,16] CHANNEL READ FALSE 2009-09-09 22:20:12.428590 [DEBUG] switch_ivr_bridge.c:377 skypiax/interface1/user2 ending bridge by request from read function 2009-09-09 22:20:12.428590 [DEBUG] switch_ivr_bridge.c:452 BRIDGE THREAD DONE [skypiax/interface1/user2] 2009-09-09 22:20:12.428590 [DEBUG] switch_ivr_bridge.c:454 Send signal sofia/internal/1002@192.168.121.66 [BREAK] 2009-09-09 22:20:12.428590 [DEBUG] switch_core_state_machine.c:497 (skypiax/interface1/user2) State EXCHANGE_MEDIA going to sleep 2009-09-09 22:20:12.428590 [DEBUG] switch_core_state_machine.c:398 (skypiax/interface1/user2) Running State Change CS_HANGUP 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:434 (skypiax/interface1/user2) State HANGUP 2009-09-09 22:20:12.429654 [DEBUG] mod_skypiax.c:506 rev 14771[(nil)|37 ][DEBUG_SKYPE 506 ][interface1][-1, 1,16] interface1 CHANNEL HANGUP 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:46 skypiax/interface1/user2 Standard HANGUP, cause: NORMAL_CLEARING 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:434 (skypiax/interface1/user2) State HANGUP going to sleep 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:479 (skypiax/interface1/user2) State Change CS_HANGUP -> CS_REPORTING 2009-09-09 22:20:12.429654 [DEBUG] switch_core_session.c:932 Send signal skypiax/interface1/user2 [BREAK] 2009-09-09 22:20:12.429654 [DEBUG] mod_skypiax.c:566 rev 14771[(nil)|37 ][DEBUG_SKYPE 566 ][interface1][-1, 0, 0] interface1 CHANNEL KILL_CHANNEL 2009-09-09 22:20:12.429654 [DEBUG] mod_skypiax.c:589 rev 14771[(nil)|37 ][DEBUG_SKYPE 589 ][interface1][-1, 0, 0] skypiax/interface1/user2 CHANNEL got SWITCH_SIG_BREAK 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:398 (skypiax/interface1/user2) Running State Change CS_REPORTING 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:616 (skypiax/interface1/user2) State REPORTING 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:53 skypiax/interface1/user2 Standard REPORTING, cause: NORMAL_CLEARING 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:616 (skypiax/interface1/user2) State REPORTING going to sleep 2009-09-09 22:20:12.429654 [DEBUG] switch_core_state_machine.c:411 (skypiax/interface1/user2) State Change CS_REPORTING -> CS_DESTROY 2009-09-09 22:20:12.429654 [DEBUG] switch_core_session.c:932 Send signal skypiax/interface1/user2 [BREAK] 2009-09-09 22:20:12.429654 [DEBUG] mod_skypiax.c:566 rev 14771[(nil)|37 ][DEBUG_SKYPE 566 ][interface1][-1, 0, 0] interface1 CHANNEL KILL_CHANNEL 2009-09-09 22:20:12.429654 [DEBUG] mod_skypiax.c:589 rev 14771[(nil)|37 ][DEBUG_SKYPE 589 ][interface1][-1, 0, 0] skypiax/interface1/user2 CHANNEL got SWITCH_SIG_BREAK 2009-09-09 22:20:12.429654 [DEBUG] switch_core_session.c:1068 Session 8 (skypiax/interface1/user2) Locked, Waiting on external entities 2009-09-09 22:20:12.439620 [DEBUG] skypiax_protocol.c:849 rev 14707[(nil)|37 ][DEBUG_SKYPE 849 ][interface1][-1, 0, 0] Skype outbound audio GONE 2009-09-09 22:20:12.458666 [DEBUG] switch_ivr_bridge.c:426 sofia/internal/1002@192.168.121.66 receive message [UNBRIDGE] 2009-09-09 22:20:12.458666 [DEBUG] switch_core_session.c:630 Send signal sofia/internal/1002@192.168.121.66 [BREAK] 2009-09-09 22:20:12.458666 [DEBUG] switch_ivr_bridge.c:452 BRIDGE THREAD DONE [sofia/internal/1002@192.168.121.66 ] 2009-09-09 22:20:12.458666 [DEBUG] switch_ivr_bridge.c:454 Send signal skypiax/interface1/user2 [BREAK] 2009-09-09 22:20:12.458666 [DEBUG] mod_skypiax.c:566 rev 14771[(nil)|37 ][DEBUG_SKYPE 566 ][interface1][-1, 0, 0] interface1 CHANNEL KILL_CHANNEL 2009-09-09 22:20:12.458666 [DEBUG] mod_skypiax.c:589 rev 14771[(nil)|37 ][DEBUG_SKYPE 589 ][interface1][-1, 0, 0] skypiax/interface1/user2 CHANNEL got SWITCH_SIG_BREAK 2009-09-09 22:20:12.458666 [NOTICE] switch_core_state_machine.c:179 Hangup sofia/internal/1002@192.168.121.66 [CS_EXECUTE] [NORMAL_CLEARING] 2009-09-09 22:20:12.458666 [DEBUG] switch_channel.c:1715 Send signal sofia/internal/1002@192.168.121.66 [KILL] 2009-09-09 22:20:12.458666 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/1002@192.168.121.66 [BREAK] 2009-09-09 22:20:12.458666 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/1002@192.168.121.66) State EXECUTE going to sleep 2009-09-09 22:20:12.458666 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1002@192.168.121.66) Running State Change CS_HANGUP 2009-09-09 22:20:12.459723 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/1002@192.168.121.66) State HANGUP 2009-09-09 22:20:12.459723 [DEBUG] mod_sofia.c:338 Channel sofia/internal/1002@192.168.121.66 hanging up, cause: NORMAL_CLEARING 2009-09-09 22:20:12.459723 [DEBUG] mod_sofia.c:376 Sending BYE to sofia/internal/1002@192.168.121.66
(...)
2009-09-09 22:20:12.712461 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CALL 307 DURATION 505||| 2009-09-09 22:20:12.712461 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CALL 307 VAA_INPUT_STATUS FALSE||| 2009-09-09 22:20:13.473652 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CALL 307 DURATION 506||| 2009-09-09 22:20:14.473723 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CALL 307 DURATION 507|||
(...)
2009-09-09 22:26:47.775793 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CALL 307 STATUS FINISHED||| 2009-09-09 22:26:47.775793 [DEBUG] skypiax_protocol.c:361 rev 14707[(nil)|37 ][DEBUG_SKYPE 361 ][interface1][-1, 0, 0] skype_call 307 is NOT MY call, ignoring 2009-09-09 22:48:08.274202 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||USER user1 ONLINESTATUS OFFLINE||| 2009-09-09 22:48:08.274202 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||USERSTATUS OFFLINE||| 2009-09-09 22:48:08.274202 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CONNSTATUS CONNECTING||| 2009-09-09 22:48:31.374348 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||USER user1 ONLINESTATUS ONLINE||| 2009-09-09 22:48:31.374348 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||USERSTATUS ONLINE||| 2009-09-09 22:48:31.375500 [DEBUG] skypiax_protocol.c:104 rev 14707[(nil)|37 ][DEBUG_SKYPE 104 ][interface1][-1, 0, 0] READING: |||CONNSTATUS ONLINE|||
Is this expected behavior? Of course, the main problem is probably in hardware but does skypiax do its job right?
- Dmitry Bely
_______________________________________________ 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