[Freeswitch-users] Skypiax false DTMF event
Dmitry Bely
dmitry.bely at gmail.com
Wed Sep 9 13:04:39 PDT 2009
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:
(...)
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 at 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 at 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 at 192.168.121.66 [BREAK]
2009-09-09 22:20:12.458666 [DEBUG] switch_ivr_bridge.c:452 BRIDGE
THREAD DONE [sofia/internal/1002 at 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 at 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 at 192.168.121.66 [KILL]
2009-09-09 22:20:12.458666 [DEBUG] switch_core_session.c:932 Send
signal sofia/internal/1002 at 192.168.121.66 [BREAK]
2009-09-09 22:20:12.458666 [DEBUG] switch_core_state_machine.c:494
(sofia/internal/1002 at 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 at 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 at 192.168.121.66) State HANGUP
2009-09-09 22:20:12.459723 [DEBUG] mod_sofia.c:338 Channel
sofia/internal/1002 at 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 at 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
More information about the FreeSWITCH-users
mailing list