[Freeswitch-dev] Unintended call termination

M Matijas mladen at podiumvision.co.uk
Fri May 11 10:03:28 EDT 2007 

Hi Guys,

I get these lists & thought I might interfere.

I biz dev Epygi (www.epygi.com) IP PBXes. We test heaps of IP phones. So I
tend to see a lot of crap as all the handset & ATA manufactures seem to use
us to fix their SIP implementation.

Regarding SNOM, nice company but they are a real pain in the a... with their
SIP stack. I can tell you that finally after more the 18 months are we
getting them to implement the SIP stack correctly. I suggest you make sure
that you have the last Linux OS on the phone THEN upgrade to 6.5.8. They do
all sorts of dumb things like forget to send BYE messages so you get all
these damn phantom calls.

My personal favourite for high end IP phones is the new Aastra 5i series.
They are cool.

As for entry level phones, what out. You WILL get burnt.

Just my 2 cents.

Regards,
Mladen

-----Original Message-----
From: freeswitch-dev-bounces at lists.freeswitch.org
[mailto:freeswitch-dev-bounces at lists.freeswitch.org] On Behalf Of Ivan C
Myrvold
Sent: vendredi 11 mai 2007 08:24
To: freeswitch-dev at lists.freeswitch.org
Subject: Re: [Freeswitch-dev] Unintended call termination

I am also experiencing this, on a SIPURA SPA-2000. The call is  
terminated unintended:

2007-05-10 13:14:09 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:10 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:10 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:12 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:12 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:802 do_2833() Send start  
packet for [9] ts=4367360 sofar=0 dur=0 seq=26759
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:802 do_2833() Send start  
packet for [9] ts=4367360 sofar=0 dur=0 seq=26759
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:802 do_2833() Send start  
packet for [9] ts=4367360 sofar=0 dur=0 seq=26759
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle  
packet for [9] ts=4367360 sofar=160 dur=160 seq=26760
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle  
packet for [9] ts=4367360 sofar=320 dur=320 seq=26761
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle  
packet for [9] ts=4367360 sofar=480 dur=480 seq=26762
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle  
packet for [9] ts=4367360 sofar=640 dur=640 seq=26763
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send end  
packet for [9] ts=4367360 sofar=800 dur=800 seq=26764
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send end  
packet for [9] ts=4367360 sofar=800 dur=800 seq=26765
2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send end  
packet for [9] ts=4367360 sofar=800 dur=800 seq=26766
2007-05-10 13:14:17 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:18 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:24 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:25 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:25 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:26 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:28 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway()  
registered 213.160.242.135
2007-05-10 13:14:29 [DEBUG] sofia.c:987 sofia_handle_sip_i_state()  
Channel sofia/imyrvold.dyndns.org/38791437 at 213.160.242.135:5060  
entering state [terminated]
2007-05-10 13:14:29 [NOTICE] sofia.c:1277 sofia_handle_sip_i_state()  
Hangup sofia/imyrvold.dyndns.org/38791437 at 213.160.242.135:5060  
[CS_EXECUTE] [NORMAL_CLEARING]
2007-05-10 13:14:29 [INFO] switch_channel.c:1055  
switch_channel_perform_hangup() Kill sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060 [KILL]
2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:168  
audio_bridge_thread() write: sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060 Bad Frame....[160] Bubye!
2007-05-10 13:14:29 [DEBUG] mod_sofia.c:779 sofia_receive_message()  
Re-activate timed RTP!
2007-05-10 13:14:29 [INFO] switch_core_session.c:345  
switch_core_session_receive_message() Kill sofia/imyrvold.dyndns.org/ 
100 [BREAK]
2007-05-10 13:14:29 [INFO] switch_ivr_bridge.c:183 audio_bridge_thread 
() Kill sofia/imyrvold.dyndns.org/38791437 at 213.160.242.135:5060 [BREAK]
2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:186  
audio_bridge_thread() BRIDGE THREAD DONE [sofia/imyrvold.dyndns.org/100]
2007-05-10 13:14:29 [NOTICE] switch_ivr_bridge.c:214  
audio_bridge_on_loopback() Hangup sofia/imyrvold.dyndns.org/100  
[CS_LOOPBACK] [NORMAL_CLEARING]
2007-05-10 13:14:29 [INFO] switch_channel.c:1055  
switch_channel_perform_hangup() Kill sofia/imyrvold.dyndns.org/100  
[KILL]
2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:342  
switch_core_session_run() (sofia/imyrvold.dyndns.org/100) State HANGUP
2007-05-10 13:14:29 [DEBUG] mod_sofia.c:214 sofia_on_hangup() Channel  
sofia/imyrvold.dyndns.org/100 hanging up, cause: NORMAL_CLEARING
2007-05-10 13:14:29 [DEBUG] mod_sofia.c:230 sofia_on_hangup() Sending  
BYE to sofia/imyrvold.dyndns.org/100
2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:45  
switch_core_standard_on_hangup() Standard HANGUP sofia/ 
imyrvold.dyndns.org/100, cause: NORMAL_CLEARING
2007-05-10 13:14:29 [DEBUG] switch_core_session.c:696  
switch_core_session_thread() Session 6 (sofia/imyrvold.dyndns.org/ 
100) Locked, Waiting on external entities
2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:174  
audio_bridge_thread() read: sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060 Bad Frame.... Bubye!
2007-05-10 13:14:29 [DEBUG] mod_sofia.c:779 sofia_receive_message()  
Re-activate timed RTP!
2007-05-10 13:14:29 [INFO] switch_core_session.c:345  
switch_core_session_receive_message() Kill sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060 [BREAK]
2007-05-10 13:14:29 [INFO] switch_ivr_bridge.c:183 audio_bridge_thread 
() Kill sofia/imyrvold.dyndns.org/100 [BREAK]
2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:186  
audio_bridge_thread() BRIDGE THREAD DONE [sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060]
2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:342  
switch_core_session_run() (sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060) State HANGUP
2007-05-10 13:14:29 [INFO] switch_core_session.c:702  
switch_core_session_thread() Session 6 (sofia/imyrvold.dyndns.org/ 
100) Ended
2007-05-10 13:14:29 [NOTICE] switch_core_session.c:654  
switch_core_session_destroy() Close Channel sofia/imyrvold.dyndns.org/ 
100
2007-05-10 13:14:29 [DEBUG] mod_sofia.c:214 sofia_on_hangup() Channel  
sofia/imyrvold.dyndns.org/38791437 at 213.160.242.135:5060 hanging up,  
cause: NORMAL_CLEARING
2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:45  
switch_core_standard_on_hangup() Standard HANGUP sofia/ 
imyrvold.dyndns.org/38791437 at 213.160.242.135:5060, cause:  
NORMAL_CLEARING
2007-05-10 13:14:29 [DEBUG] switch_core_session.c:696  
switch_core_session_thread() Session 5 (sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060) Locked, Waiting on external entities
2007-05-10 13:14:29 [INFO] switch_core_session.c:702  
switch_core_session_thread() Session 5 (sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060) Ended
2007-05-10 13:14:29 [NOTICE] switch_core_session.c:654  
switch_core_session_destroy() Close Channel sofia/imyrvold.dyndns.org/ 
38791437 at 213.160.242.135:5060

Ivan

Den 23. jan. 2007 kl. 08:34 skrev Per Møller:

> I am testing FS with a range of phones.
>
> My first problem is that when I make a call from a Snom 3xx phone  
> (www.snom.com), the moment the call is answered - the call is  
> terminated.
>
> If I instead make the call from one of my Linksys phones, the call  
> works fine.
>
> Below is the output from the console from the moment the call is  
> answered until the call was terminated. I call from locally  
> attached phone 12 to locally attached phone 11 (in this case 2 Snom  
> 360 phones).
>
> Maybe there is some indication to the problem here:
>
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:4447 event_callback() event  
> [nua_i_error] status [500][Responding to a Non-Existing Request]  
> session: sofia/standard/12 at 192.168.11.222
> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1961 audio_bridge_thread()  
> read: sofia/standard/12 at 192.168.11.222 Bad Frame.... Bubye!
>
> Somebody have any idea how to fix this, or perhaps some hints on  
> how to debug this further?
>
> // Per
>
> ------------------------------------------------------------
>
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2562 sip_i_state() Channel  
> sofia/standard/11 entering state [ready]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2567 sip_i_state() Remote SDP:
> v=0
> o=root 217248721 217248722 IN IP4 192.168.11.187
> s=call
> c=IN IP4 192.168.11.187
> t=0 0
> m=audio 29442 RTP/AVP 8 101
> a=rtpmap:8 pcma/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
>
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2201 negotiate_sdp() Codec  
> Compare [pcma:8]/[PCMA:8]
> 2007-01-23 07:19:12 [INFO] mod_sofia.c:1379 tech_set_codec() Set  
> Codec sofia/standard/11 pcma/8000 20 ms
> 2007-01-23 07:19:12 [INFO] mod_sofia.c:1427 activate_rtp() RTP  
> [sofia/standard/11] 192.168.11.222:16408->192.168.11.187:29442  
> codec: 8 ms: 20
> 2007-01-23 07:19:12 [DEBUG] switch_rtp.c:500 switch_rtp_create()  
> Starting timer [soft] 160 bytes per 20000ms
> 2007-01-23 07:19:12 [NOTICE] mod_sofia.c:2806 sip_i_state() Channel  
> [sofia/standard/11] has been answered
> 2007-01-23 07:19:12 [INFO] mod_sofia.c:1427 activate_rtp() RTP  
> [sofia/standard/12 at 192.168.11.222] 192.168.11.222:16410- 
> >192.168.11.144:25064 codec: 8 ms: 20
> 2007-01-23 07:19:12 [DEBUG] switch_rtp.c:500 switch_rtp_create()  
> Starting timer [soft] 160 bytes per 20000ms
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1528 sofia_answer_channel()  
> Local SDP sofia/standard/12 at 192.168.11.222:
> v=0
> o=FreeSWITCH 164101169533152819133 164101169533152819133 IN IP4  
> 192.168.11.222
> s=FreeSWITCH
> c=IN IP4 192.168.11.222
> t=0 0
> a=sendrecv
> m=audio 16410 RTP/AVP 8 101
> a=rtpmap:8 pcma/8000
> a=ptime:20
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
>
> 2007-01-23 07:19:12 [NOTICE] switch_ivr.c:2870 switch_ivr_originate 
> () Channel [sofia/standard/12 at 192.168.11.222] has been answered
> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:2894 switch_ivr_originate 
> () Originate Resulted in Success: [sofia/standard/11]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1890 sofia_receive_message 
> () De-activate timed RTP!
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2562 sip_i_state() Channel  
> sofia/standard/12 at 192.168.11.222 entering state [completed]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1890 sofia_receive_message 
> () De-activate timed RTP!
> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:3389  
> switch_ivr_multi_threaded_bridge() sofia/standard/11 State Change  
> CS_HOLD -> CS_LOOPBACK
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:3115  
> switch_core_session_run() (sofia/standard/11) State LOOPBACK
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1302 sofia_on_loopback()  
> SOFIA LOOPBACK
> 2007-01-23 07:19:12 [NOTICE] mod_sofia.c:4467 event_callback()  
> Hangup sofia/standard/12 at 192.168.11.222 [CS_EXECUTE]  
> [DESTINATION_OUT_OF_ORDER]
> 2007-01-23 07:19:12 [INFO] switch_channel.c:969  
> switch_channel_perform_hangup() Kill sofia/standard/ 
> 12 at 192.168.11.222 [1]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2562 sip_i_state() Channel  
> sofia/standard/12 at 192.168.11.222 entering state [ready]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:4447 event_callback() event  
> [nua_i_error] status [500][Responding to a Non-Existing Request]  
> session: sofia/standard/12 at 192.168.11.222
> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1961 audio_bridge_thread()  
> read: sofia/standard/12 at 192.168.11.222 Bad Frame.... Bubye!
> 2007-01-23 07:19:12 [INFO] switch_ivr.c:1968 audio_bridge_thread()  
> Kill sofia/standard/11 [3]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1896 sofia_receive_message 
> () Re-activate timed RTP!
> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1975 audio_bridge_thread()  
> BRIDGE THREAD DONE [sofia/standard/12 at 192.168.11.222]
> 2007-01-23 07:19:12 [NOTICE] switch_ivr.c:2001  
> audio_bridge_on_loopback() Hangup sofia/standard/11 [CS_LOOPBACK]  
> [NORMAL_CLEARING]
> 2007-01-23 07:19:12 [INFO] switch_channel.c:969  
> switch_channel_perform_hangup() Kill sofia/standard/11 [1]
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2970  
> switch_core_session_run() (sofia/standard/11) State HANGUP
> 2007-01-23 07:19:12 [INFO] switch_ivr.c:1968 audio_bridge_thread()  
> Kill sofia/standard/12 at 192.168.11.222 [3]
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1896 sofia_receive_message 
> () Re-activate timed RTP!
> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1975 audio_bridge_thread()  
> BRIDGE THREAD DONE [sofia/standard/11]
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2970  
> switch_core_session_run() (sofia/standard/12 at 192.168.11.222) State  
> HANGUP
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1251 sofia_on_hangup()  
> Channel sofia/standard/11 hanging up, cause: NORMAL_CLEARING
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1267 sofia_on_hangup()  
> Sending BYE to sofia/standard/11
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2674  
> switch_core_standard_on_hangup() Standard HANGUP sofia/standard/11,  
> cause: NORMAL_CLEARING
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:3413  
> switch_core_session_thread() Session 14 (sofia/standard/11) Locked,  
> Waiting on external entities
> 2007-01-23 07:19:12 [INFO] switch_core.c:3418  
> switch_core_session_thread() Session 14 (sofia/standard/11) Ended
> 2007-01-23 07:19:12 [NOTICE] switch_core.c:3294  
> switch_core_session_destroy() Close Channel sofia/standard/11
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1251 sofia_on_hangup()  
> Channel sofia/standard/12 at 192.168.11.222 hanging up, cause:  
> DESTINATION_OUT_OF_ORDER
> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1267 sofia_on_hangup()  
> Sending BYE to sofia/standard/12 at 192.168.11.222
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2674  
> switch_core_standard_on_hangup() Standard HANGUP sofia/standard/ 
> 12 at 192.168.11.222,cause: DESTINATION_OUT_OF_ORDER
> 2007-01-23 07:19:12 [DEBUG] switch_core.c:3413  
> switch_core_session_thread() Session 13 (sofia/standard/ 
> 12 at 192.168.11.222) Locked,Waiting on external entities
> 2007-01-23 07:19:12 [INFO] switch_core.c:3418  
> switch_core_session_thread() Session 13 (sofia/standard/ 
> 12 at 192.168.11.222) Ended
> 2007-01-23 07:19:12 [NOTICE] switch_core.c:3294  
> switch_core_session_destroy() Close Channel sofia/standard/ 
> 12 at 192.168.11.222
>
>
> _______________________________________________
> Freeswitch-dev mailing list
> Freeswitch-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>


_______________________________________________
Freeswitch-dev mailing list
Freeswitch-dev at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
http://www.freeswitch.org

More information about the Freeswitch-dev mailing list