Excuse me, I can not enforce FS to write into logfile all debug info. I trued to run according http://wiki.freeswitch.org/wiki/Reporting_Bugs: TPORT_LOG=1 /usr/local/freeswitch/bin/freeswitch but anyway, siptrace does not writing to log, only to fs_cli terminal output. Anyway, I caught SIPtrace messages for Nortel, this is piece of terminal output. I see, FS sends signal BYE, because ACK timeout: 2011-11-02 18:32:07.929071 [DEBUG] switch_ivr_play_say.c:1672 done playing file /usr/local/freeswitch/sounds/ru/RU/elena/digits/1.wav recv 330 bytes from udp/[192.168.1.17]:5061 at 22:32:07.995778: ------------------------------------------------------------------------ NOTIFY sip:192.168.1.5 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.17:5061;branch=z9hG4bK-c51ee6c4 From: 1004<sip:1004@192.168.1.5>;tag=12dc6681765b973do1 To:<sip:192.168.1.5> Call-ID: af69bdb1-3c02a9cd@192.168.1.17 CSeq: 274133 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/PAP2-3.1.22(LS) Content-Length: 0 ------------------------------------------------------------------------ send 669 bytes to udp/[192.168.1.17]:5061 at 22:32:08.001770: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.17:5061;branch=z9hG4bK-c51ee6c4 From: 1004<sip:1004@192.168.1.5>;tag=12dc6681765b973do1 To:<sip:192.168.1.5>;tag=c0N5gH4XH8DQm Call-ID: af69bdb1-3c02a9cd@192.168.1.17 CSeq: 274133 NOTIFY Contact:<sip:173.79.237.112> User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-f847059 2011-10-28 15-58-17 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Length: 0 ------------------------------------------------------------------------ 2011-11-02 18:32:08.195841 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (ru:ru) 2011-11-02 18:32:08.195841 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms send 1154 bytes to udp/[192.168.1.158]:5060 at 22:32:09.084079: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.158:5060;branch=z9hG4bK-6e-1ae15-7e234642 From: "1000"<sip:1000@olegh.ath.cx>;tag=2f5c50-9e01a8c0-13c4-45026-6d-ad711f2-6d To:<sip:5000@olegh.ath.cx>;tag=1vZmX7aQH6r9m Call-ID: 3039a8-9e01a8c0-13c4-45026-6d-1a07e714-6d CSeq: 2 INVITE Contact:<sip:5000@173.79.237.112:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-f847059 2011-10-28 15-58-17 -0500 Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 242 Remote-Party-ID: "5000"<sip:5000@olegh.ath.cx>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1320248473 1320248474 IN IP4 192.168.1.5 s=FreeSWITCH c=IN IP4 192.168.1.5 t=0 0 m=audio 24624 RTP/AVP 0 99 a=rtpmap:0 PCMU/8000 a=rtpmap:99 telephone-event/8000 a=fmtp:99 0-16 a=silenceSupp:off - - - - a=ptime:20 ------------------------------------------------------------------------ 2011-11-02 18:32:09.554915 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx [BREAK] send 685 bytes to udp/[192.168.1.158]:5060 at 22:32:09.573772: ------------------------------------------------------------------------ BYE sip:1000@192.168.1.158:5060 SIP/2.0 Via: SIP/2.0/UDP 173.79.237.112;rport;branch=z9hG4bKmBgZ4SN8yDSag Max-Forwards: 70 From:<sip:5000@olegh.ath.cx>;tag=1vZmX7aQH6r9m To: "1000"<sip:1000@olegh.ath.cx>;tag=2f5c50-9e01a8c0-13c4-45026-6d-ad711f2-6d Call-ID: 3039a8-9e01a8c0-13c4-45026-6d-1a07e714-6d CSeq: 19800500 BYE Contact:<sip:5000@173.79.237.112:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-f847059 2011-10-28 15-58-17 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Reason: SIP;cause=408;text="ACK Timeout" Content-Length: 0 ------------------------------------------------------------------------ 2011-11-02 18:32:09.554915 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx [BREAK] recv 479 bytes from udp/[192.168.1.158]:5060 at 22:32:09.586581: ------------------------------------------------------------------------ SIP/2.0 200 OK From:<sip:5000@olegh.ath.cx>;tag=1vZmX7aQH6r9m To: "1000"<sip:1000@olegh.ath.cx>;tag=2f5c50-9e01a8c0-13c4-45026-6d-ad711f2-6d Call-ID: 3039a8-9e01a8c0-13c4-45026-6d-1a07e714-6d CSeq: 19800500 BYE Via: SIP/2.0/UDP 173.79.237.112;received=192.168.1.5;rport=5060;branch=z9hG4bKmBgZ4SN8yDSag Supported: replaces Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER User-Agent: Nortel IP Phone 1535 (0.2.50.0905) Content-Length: 0 ------------------------------------------------------------------------ 2011-11-02 18:32:09.582519 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx [BREAK] 2011-11-02 18:32:09.582519 [DEBUG] sofia.c:5283 Channel sofia/internal/1000@olegh.ath.cx entering state [terminating][0] 2011-11-02 18:32:09.582519 [DEBUG] switch_channel.c:2804 (sofia/internal/1000@olegh.ath.cx) Callstate Change ACTIVE -> HANGUP 2011-11-02 18:32:09.582519 [NOTICE] sofia.c:6039 Hangup sofia/internal/1000@olegh.ath.cx [CS_EXECUTE] [NORMAL_UNSPECIFIED] Anthony Minessale wrote:
snippets of logs rarely are helpful, try complete debug logs including sip trace
On Wed, Nov 2, 2011 at 4:16 PM, Oleg Khovayko <khovayko@gmail.com <mailto:khovayko@gmail.com>> wrote:
Hi,
I am using FS for couple years, it was works OK. And, approx 1 year ago, I tested with FreeSWITCH phone Nortel 1535. It worked perfect.
Thereafter, I couple times upgraded FS, and right now, I run version from GIT, dated 11-10-29. OS: FreeBSD 7.2, 32 bits.
I again connected Nortel 1535, and this time see, connection suddenly broken during call to any "robot": FS #5000, FS #4000, CallCentric #17771234567
Every time, before disconnect, I see chain of log messages like:
[DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] and HANGUP thereafter. See following samples from the log:
Another phones, like VM1188T or PAP2, still works OK. About Nortel: I tested 3 phones, with two firmwares (2.50 & 2.76) -- problem same on both.
Can you suggest me, how to fix this issue?
Thanks,
Oleg
CallCentric: 7771234567
2011-11-02 16:39:20.901219 [DEBUG] sofia_reg.c:1984 Changing expire time to 103 by request of proxy sip:callcentric.com <http://callcentric.com> 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:39:31.130669 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:39:31.130669 [DEBUG] sofia.c:5283 Channel sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> entering state [terminating][0] 2011-11-02 16:39:31.130669 [DEBUG] switch_channel.c:2804 (sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx>) Callstate Change ACTIVE -> HANGUP 2011-11-02 16:39:31.130669 [NOTICE] sofia.c:6039 Hangup sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [CS_EXECUTE] [NORMAL_UNSPECIFIED] 2011-11-02 16:39:31.130669 [DEBUG] switch_channel.c:2820 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [KILL] 2011-11-02 16:39:31.130669 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK]
FS: 5000
2011-11-02 17:03:08.207852 [DEBUG] switch_ivr_play_say.c:1672 done playing file /usr/local/freeswitch/sounds/ru/RU/elena/ivr/ivr-to_do_a_freeswitch_echo_test.wav 2011-11-02 17:03:08.459809 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[ivr/ivr-please.wav] (ru:ru) 2011-11-02 17:03:08.459809 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 2011-11-02 17:03:09.257683 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 17:03:09.257683 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 17:03:09.257683 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 17:03:09.280490 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 17:03:09.280490 [DEBUG] sofia.c:5283 Channel sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> entering state [terminating][0] 2011-11-02 17:03:09.280490 [DEBUG] switch_channel.c:2804 (sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx>) Callstate Change ACTIVE -> HANGUP 2011-11-02 17:03:09.280490 [NOTICE] sofia.c:6039 Hangup sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [CS_EXECUTE] [NORMAL_UNSPECIFIED] 2011-11-02 17:03:09.280490 [DEBUG] switch_channel.c:2820 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [KILL] 2011-11-02 17:03:09.280490 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 17:03:09.280490 [DEBUG] switch_ivr_play_say.c:1672 done playing file /usr/local/freeswitch/sounds/ru/RU/elena/ivr/ivr-please.wav 2011-11-02 17:03:09.532638 [DEBUG] switch_ivr_menu.c:348 waiting for 4/4 digits t/o 2000 2011-11-02 17:03:09.532638 [DEBUG] switch_ivr_menu.c:395 digits '' 2011-11-02 17:03:09.532638 [DEBUG] switch_ivr_menu.c:585 IVR menu 'demo_ivr' no input detected 2011-11-02 17:03:10.587476 [DEBUG] switch_ivr_menu.c:599 exit-sound 'voicemail/vm-goodbye.wav' 2011-11-02 17:03:10.587476 [DEBUG] switch_core_session.c:2269 sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
FS: voicemail
2011-11-02 16:51:50.217856 [DEBUG] switch_ivr_play_say.c:67 No language specified - Using [ru] 2011-11-02 16:51:50.307721 [DEBUG] switch_ivr_play_say.c:244 Handle say:[1290554584] (ru:ru) 2011-11-02 16:51:50.307721 [INFO] mod_say_ru.c:721 ru_say!!! 1290554584! say_opt.gender=0 say_opt.cases=0 2011-11-02 16:51:50.307721 [DEBUG] switch_ivr_play_say.c:1302 Codec Activated L16@8000hz 1 channels 20ms 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK] 2011-11-02 16:51:50.990445 [DEBUG] sofia.c:5283 Channel sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> entering state [terminating][0] 2011-11-02 16:51:50.990445 [DEBUG] switch_channel.c:2804 (sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx>) Callstate Change ACTIVE -> HANGUP 2011-11-02 16:51:50.990445 [NOTICE] sofia.c:6039 Hangup sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [CS_EXECUTE] [NORMAL_UNSPECIFIED] 2011-11-02 16:51:50.990445 [DEBUG] switch_channel.c:2820 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [KILL] 2011-11-02 16:51:50.990445 [DEBUG] switch_core_session.c:1177 Send signal sofia/internal/1000@olegh.ath.cx <mailto:1000@olegh.ath.cx> [BREAK]
_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE
FreeSWITCH-dev mailing list FreeSWITCH-dev@lists.freeswitch.org <mailto:FreeSWITCH-dev@lists.freeswitch.org> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire
AIM: anthm MSN:anthony_minessale@hotmail.com <mailto:MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com <mailto:PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net <http://irc.freenode.net> #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <mailto:sip%3A888@conference.freeswitch.org> googletalk:conf+888@conference.freeswitch.org <mailto:googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:+19193869900
_______________________________________________ Join us at ClueCon 2011, Aug 9-11, Chicago http://www.cluecon.com 877-7-4ACLUE
FreeSWITCH-dev mailing list FreeSWITCH-dev@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev http://www.freeswitch.org