<html><head><style type="text/css"><!-- DIV {margin:0px;} --></style></head><body><div style="font-family:courier,monaco,monospace,sans-serif;font-size:12pt"><span>whenever you post a trace you should put it on <a target="_blank" href="http://pastebin.freeswitch.org">http://pastebin.freeswitch.org</a> and tag it with your name and just put the link in the email.</span><br><br>Also make sure you run freeswitch like this when reproducing:<br><br>NUA_DEBUG=9 TPORT_LOG=1 /usr/local/freeswitch/bin/freeswitch<br><br><br><div> </div><div>Anthony Minessale II<br><br><span>FreeSWITCH <a target="_blank" href="http://www.freeswitch.org/">http://www.freeswitch.org/</a></span><br><span>ClueCon <a target="_blank" href="http://www.cluecon.com/">http://www.cluecon.com/</a></span><br><br>AIM: anthm<br>MSN:anthony_minessale@hotmail.com<br>JABBER:anthony.minessale@gmail.com<br>IRC: irc.freenode.net #freeswitch</div><div><br>FreeSWITCH Developer
Conference<br>sip:888@conference.freeswitch.org<br>iax:guest@conference.freeswitch.org/888<br>googletalk:conf+888@conference.freeswitch.org<br>pstn:213-799-1400</div><div style="font-family: courier,monaco,monospace,sans-serif; font-size: 12pt;"><br><br><div style="font-family: times new roman,new york,times,serif; font-size: 12pt;">----- Original Message ----<br>From: Ivan C Myrvold <ivan@myrvold.org><br>To: freeswitch-dev@lists.freeswitch.org<br>Sent: Friday, May 11, 2007 1:24:11 AM<br>Subject: Re: [Freeswitch-dev] Unintended call termination<br><br><div>I am also experiencing this, on a SIPURA SPA-2000. The call is <br>terminated unintended:<br><br>2007-05-10 13:14:09 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:10 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:10 [NOTICE] sofia_reg.c:69
sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:12 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:12 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:802 do_2833() Send start <br>packet for [9] ts=4367360 sofar=0 dur=0 seq=26759<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:802 do_2833() Send start <br>packet for [9] ts=4367360 sofar=0 dur=0 seq=26759<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:802 do_2833() Send start <br>packet for [9] ts=4367360 sofar=0 dur=0 seq=26759<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle <br>packet for [9] ts=4367360 sofar=160 dur=160 seq=26760<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle <br>packet for [9] ts=4367360 sofar=320 dur=320
seq=26761<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle <br>packet for [9] ts=4367360 sofar=480 dur=480 seq=26762<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send middle <br>packet for [9] ts=4367360 sofar=640 dur=640 seq=26763<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send end <br>packet for [9] ts=4367360 sofar=800 dur=800 seq=26764<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send end <br>packet for [9] ts=4367360 sofar=800 dur=800 seq=26765<br>2007-05-10 13:14:16 [DEBUG] switch_rtp.c:758 do_2833() Send end <br>packet for [9] ts=4367360 sofar=800 dur=800 seq=26766<br>2007-05-10 13:14:17 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:18 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:24 [NOTICE] sofia_reg.c:69
sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:25 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:25 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:26 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:28 [NOTICE] sofia_reg.c:69 sofia_reg_check_gateway() <br>registered 213.160.242.135<br>2007-05-10 13:14:29 [DEBUG] sofia.c:987 sofia_handle_sip_i_state() <br>Channel sofia/imyrvold.dyndns.org/38791437@213.160.242.135:5060 <br>entering state [terminated]<br>2007-05-10 13:14:29 [NOTICE] sofia.c:1277 sofia_handle_sip_i_state() <br>Hangup sofia/imyrvold.dyndns.org/38791437@213.160.242.135:5060 <br>[CS_EXECUTE] [NORMAL_CLEARING]<br>2007-05-10 13:14:29 [INFO]
switch_channel.c:1055 <br>switch_channel_perform_hangup() Kill sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060 [KILL]<br>2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:168 <br>audio_bridge_thread() write: sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060 Bad Frame....[160] Bubye!<br>2007-05-10 13:14:29 [DEBUG] mod_sofia.c:779 sofia_receive_message() <br>Re-activate timed RTP!<br>2007-05-10 13:14:29 [INFO] switch_core_session.c:345 <br>switch_core_session_receive_message() Kill sofia/imyrvold.dyndns.org/ <br>100 [BREAK]<br>2007-05-10 13:14:29 [INFO] switch_ivr_bridge.c:183 audio_bridge_thread <br>() Kill sofia/imyrvold.dyndns.org/38791437@213.160.242.135:5060 [BREAK]<br>2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:186 <br>audio_bridge_thread() BRIDGE THREAD DONE [sofia/imyrvold.dyndns.org/100]<br>2007-05-10 13:14:29 [NOTICE] switch_ivr_bridge.c:214 <br>audio_bridge_on_loopback()
Hangup sofia/imyrvold.dyndns.org/100 <br>[CS_LOOPBACK] [NORMAL_CLEARING]<br>2007-05-10 13:14:29 [INFO] switch_channel.c:1055 <br>switch_channel_perform_hangup() Kill sofia/imyrvold.dyndns.org/100 <br>[KILL]<br>2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:342 <br>switch_core_session_run() (sofia/imyrvold.dyndns.org/100) State HANGUP<br>2007-05-10 13:14:29 [DEBUG] mod_sofia.c:214 sofia_on_hangup() Channel <br>sofia/imyrvold.dyndns.org/100 hanging up, cause: NORMAL_CLEARING<br>2007-05-10 13:14:29 [DEBUG] mod_sofia.c:230 sofia_on_hangup() Sending <br>BYE to sofia/imyrvold.dyndns.org/100<br>2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:45 <br>switch_core_standard_on_hangup() Standard HANGUP sofia/ <br>imyrvold.dyndns.org/100, cause: NORMAL_CLEARING<br>2007-05-10 13:14:29 [DEBUG] switch_core_session.c:696 <br>switch_core_session_thread() Session 6
(sofia/imyrvold.dyndns.org/ <br>100) Locked, Waiting on external entities<br>2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:174 <br>audio_bridge_thread() read: sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060 Bad Frame.... Bubye!<br>2007-05-10 13:14:29 [DEBUG] mod_sofia.c:779 sofia_receive_message() <br>Re-activate timed RTP!<br>2007-05-10 13:14:29 [INFO] switch_core_session.c:345 <br>switch_core_session_receive_message() Kill sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060 [BREAK]<br>2007-05-10 13:14:29 [INFO] switch_ivr_bridge.c:183 audio_bridge_thread <br>() Kill sofia/imyrvold.dyndns.org/100 [BREAK]<br>2007-05-10 13:14:29 [DEBUG] switch_ivr_bridge.c:186 <br>audio_bridge_thread() BRIDGE THREAD DONE [sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060]<br>2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:342 <br>switch_core_session_run() (sofia/imyrvold.dyndns.org/
<br>38791437@213.160.242.135:5060) State HANGUP<br>2007-05-10 13:14:29 [INFO] switch_core_session.c:702 <br>switch_core_session_thread() Session 6 (sofia/imyrvold.dyndns.org/ <br>100) Ended<br>2007-05-10 13:14:29 [NOTICE] switch_core_session.c:654 <br>switch_core_session_destroy() Close Channel sofia/imyrvold.dyndns.org/ <br>100<br>2007-05-10 13:14:29 [DEBUG] mod_sofia.c:214 sofia_on_hangup() Channel <br>sofia/imyrvold.dyndns.org/38791437@213.160.242.135:5060 hanging up, <br>cause: NORMAL_CLEARING<br>2007-05-10 13:14:29 [DEBUG] switch_core_state_machine.c:45 <br>switch_core_standard_on_hangup() Standard HANGUP sofia/ <br>imyrvold.dyndns.org/38791437@213.160.242.135:5060, cause: <br>NORMAL_CLEARING<br>2007-05-10 13:14:29 [DEBUG] switch_core_session.c:696 <br>switch_core_session_thread() Session 5 (sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060) Locked, Waiting on external
entities<br>2007-05-10 13:14:29 [INFO] switch_core_session.c:702 <br>switch_core_session_thread() Session 5 (sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060) Ended<br>2007-05-10 13:14:29 [NOTICE] switch_core_session.c:654 <br>switch_core_session_destroy() Close Channel sofia/imyrvold.dyndns.org/ <br>38791437@213.160.242.135:5060<br><br>Ivan<br><br>Den 23. jan. 2007 kl. 08:34 skrev Per Møller:<br><br>> I am testing FS with a range of phones.<br>><br>> My first problem is that when I make a call from a Snom 3xx phone <br>> (<a target="_blank" href="http://www.snom.com">www.snom.com</a>), the moment the call is answered - the call is <br>> terminated.<br>><br>> If I instead make the call from one of my Linksys phones, the call <br>> works fine.<br>><br>> Below is the output from the console from the moment the call is <br>> answered until the call was terminated. I
call from locally <br>> attached phone 12 to locally attached phone 11 (in this case 2 Snom <br>> 360 phones).<br>><br>> Maybe there is some indication to the problem here:<br>><br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:4447 event_callback() event <br>> [nua_i_error] status [500][Responding to a Non-Existing Request] <br>> session: sofia/standard/12@192.168.11.222<br>> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1961 audio_bridge_thread() <br>> read: sofia/standard/12@192.168.11.222 Bad Frame.... Bubye!<br>><br>> Somebody have any idea how to fix this, or perhaps some hints on <br>> how to debug this further?<br>><br>> // Per<br>><br>> ------------------------------------------------------------<br>><br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2562 sip_i_state() Channel <br>> sofia/standard/11 entering state [ready]<br>> 2007-01-23
07:19:12 [DEBUG] mod_sofia.c:2567 sip_i_state() Remote SDP:<br>> v=0<br>> o=root 217248721 217248722 IN IP4 192.168.11.187<br>> s=call<br>> c=IN IP4 192.168.11.187<br>> t=0 0<br>> m=audio 29442 RTP/AVP 8 101<br>> a=rtpmap:8 pcma/8000<br>> a=rtpmap:101 telephone-event/8000<br>> a=fmtp:101 0-16<br>> a=ptime:20<br>><br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2201 negotiate_sdp() Codec <br>> Compare [pcma:8]/[PCMA:8]<br>> 2007-01-23 07:19:12 [INFO] mod_sofia.c:1379 tech_set_codec() Set <br>> Codec sofia/standard/11 pcma/8000 20 ms<br>> 2007-01-23 07:19:12 [INFO] mod_sofia.c:1427 activate_rtp() RTP <br>> [sofia/standard/11] 192.168.11.222:16408->192.168.11.187:29442 <br>> codec: 8 ms: 20<br>> 2007-01-23 07:19:12 [DEBUG] switch_rtp.c:500 switch_rtp_create() <br>> Starting timer [soft] 160 bytes per 20000ms<br>> 2007-01-23 07:19:12 [NOTICE] mod_sofia.c:2806
sip_i_state() Channel <br>> [sofia/standard/11] has been answered<br>> 2007-01-23 07:19:12 [INFO] mod_sofia.c:1427 activate_rtp() RTP <br>> [sofia/standard/12@192.168.11.222] 192.168.11.222:16410- <br>> >192.168.11.144:25064 codec: 8 ms: 20<br>> 2007-01-23 07:19:12 [DEBUG] switch_rtp.c:500 switch_rtp_create() <br>> Starting timer [soft] 160 bytes per 20000ms<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1528 sofia_answer_channel() <br>> Local SDP sofia/standard/12@192.168.11.222:<br>> v=0<br>> o=FreeSWITCH 164101169533152819133 164101169533152819133 IN IP4 <br>> 192.168.11.222<br>> s=FreeSWITCH<br>> c=IN IP4 192.168.11.222<br>> t=0 0<br>> a=sendrecv<br>> m=audio 16410 RTP/AVP 8 101<br>> a=rtpmap:8 pcma/8000<br>> a=ptime:20<br>> a=rtpmap:101 telephone-event/8000<br>> a=fmtp:101 0-16<br>><br>> 2007-01-23 07:19:12 [NOTICE] switch_ivr.c:2870
switch_ivr_originate <br>> () Channel [sofia/standard/12@192.168.11.222] has been answered<br>> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:2894 switch_ivr_originate <br>> () Originate Resulted in Success: [sofia/standard/11]<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1890 sofia_receive_message <br>> () De-activate timed RTP!<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2562 sip_i_state() Channel <br>> sofia/standard/12@192.168.11.222 entering state [completed]<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1890 sofia_receive_message <br>> () De-activate timed RTP!<br>> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:3389 <br>> switch_ivr_multi_threaded_bridge() sofia/standard/11 State Change <br>> CS_HOLD -> CS_LOOPBACK<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:3115 <br>> switch_core_session_run() (sofia/standard/11) State LOOPBACK<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1302
sofia_on_loopback() <br>> SOFIA LOOPBACK<br>> 2007-01-23 07:19:12 [NOTICE] mod_sofia.c:4467 event_callback() <br>> Hangup sofia/standard/12@192.168.11.222 [CS_EXECUTE] <br>> [DESTINATION_OUT_OF_ORDER]<br>> 2007-01-23 07:19:12 [INFO] switch_channel.c:969 <br>> switch_channel_perform_hangup() Kill sofia/standard/ <br>> 12@192.168.11.222 [1]<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:2562 sip_i_state() Channel <br>> sofia/standard/12@192.168.11.222 entering state [ready]<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:4447 event_callback() event <br>> [nua_i_error] status [500][Responding to a Non-Existing Request] <br>> session: sofia/standard/12@192.168.11.222<br>> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1961 audio_bridge_thread() <br>> read: sofia/standard/12@192.168.11.222 Bad Frame.... Bubye!<br>> 2007-01-23 07:19:12 [INFO]
switch_ivr.c:1968 audio_bridge_thread() <br>> Kill sofia/standard/11 [3]<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1896 sofia_receive_message <br>> () Re-activate timed RTP!<br>> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1975 audio_bridge_thread() <br>> BRIDGE THREAD DONE [sofia/standard/12@192.168.11.222]<br>> 2007-01-23 07:19:12 [NOTICE] switch_ivr.c:2001 <br>> audio_bridge_on_loopback() Hangup sofia/standard/11 [CS_LOOPBACK] <br>> [NORMAL_CLEARING]<br>> 2007-01-23 07:19:12 [INFO] switch_channel.c:969 <br>> switch_channel_perform_hangup() Kill sofia/standard/11 [1]<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2970 <br>> switch_core_session_run() (sofia/standard/11) State HANGUP<br>> 2007-01-23 07:19:12 [INFO] switch_ivr.c:1968 audio_bridge_thread() <br>> Kill sofia/standard/12@192.168.11.222 [3]<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1896
sofia_receive_message <br>> () Re-activate timed RTP!<br>> 2007-01-23 07:19:12 [DEBUG] switch_ivr.c:1975 audio_bridge_thread() <br>> BRIDGE THREAD DONE [sofia/standard/11]<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2970 <br>> switch_core_session_run() (sofia/standard/12@192.168.11.222) State <br>> HANGUP<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1251 sofia_on_hangup() <br>> Channel sofia/standard/11 hanging up, cause: NORMAL_CLEARING<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1267 sofia_on_hangup() <br>> Sending BYE to sofia/standard/11<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2674 <br>> switch_core_standard_on_hangup() Standard HANGUP sofia/standard/11, <br>> cause: NORMAL_CLEARING<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:3413 <br>> switch_core_session_thread() Session 14 (sofia/standard/11) Locked, <br>>
Waiting on external entities<br>> 2007-01-23 07:19:12 [INFO] switch_core.c:3418 <br>> switch_core_session_thread() Session 14 (sofia/standard/11) Ended<br>> 2007-01-23 07:19:12 [NOTICE] switch_core.c:3294 <br>> switch_core_session_destroy() Close Channel sofia/standard/11<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1251 sofia_on_hangup() <br>> Channel sofia/standard/12@192.168.11.222 hanging up, cause: <br>> DESTINATION_OUT_OF_ORDER<br>> 2007-01-23 07:19:12 [DEBUG] mod_sofia.c:1267 sofia_on_hangup() <br>> Sending BYE to sofia/standard/12@192.168.11.222<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:2674 <br>> switch_core_standard_on_hangup() Standard HANGUP sofia/standard/ <br>> 12@192.168.11.222,cause: DESTINATION_OUT_OF_ORDER<br>> 2007-01-23 07:19:12 [DEBUG] switch_core.c:3413 <br>> switch_core_session_thread() Session 13 (sofia/standard/ <br>>
12@192.168.11.222) Locked,Waiting on external entities<br>> 2007-01-23 07:19:12 [INFO] switch_core.c:3418 <br>> switch_core_session_thread() Session 13 (sofia/standard/ <br>> 12@192.168.11.222) Ended<br>> 2007-01-23 07:19:12 [NOTICE] switch_core.c:3294 <br>> switch_core_session_destroy() Close Channel sofia/standard/ <br>> 12@192.168.11.222<br>><br>><br>> _______________________________________________<br>> Freeswitch-dev mailing list<br>> Freeswitch-dev@lists.freeswitch.org<br>> <a target="_blank" href="http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev">http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev</a><br>> UNSUBSCRIBE:<a target="_blank" href="http://lists.freeswitch.org/mailman/options/freeswitch-dev">http://lists.freeswitch.org/mailman/options/freeswitch-dev</a><br>> <a target="_blank"
href="http://www.freeswitch.org">http://www.freeswitch.org</a><br>><br><br><br>_______________________________________________<br>Freeswitch-dev mailing list<br>Freeswitch-dev@lists.freeswitch.org<br><a target="_blank" href="http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev">http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev</a><br>UNSUBSCRIBE:<a target="_blank" href="http://lists.freeswitch.org/mailman/options/freeswitch-dev">http://lists.freeswitch.org/mailman/options/freeswitch-dev</a><br><a target="_blank" href="http://www.freeswitch.org">http://www.freeswitch.org</a><br></div></div><br></div></div><br>
<hr size=1>Sick sense of humor? Visit Yahoo! TV's
<a href="http://us.rd.yahoo.com/evt=47093/*http://tv.yahoo.com/collections/222">Comedy with an Edge </a>to see what's on, when.
</body></html>