[Freeswitch-dev] Nortel 1535 drops connection to FS
Oleg Khovayko
khovayko at gmail.com
Fri Nov 4 06:23:20 MSK 2011
Anthony,
I found problem source. I think, it will be valuable information for our
community. Also, maybe will need to fix FS according this info.
1. About "FS does not receive ACK" - you was right. Really, FS was not
received ACKs, and breaks connection.
2. Currently, FS runs behind NAT router, with option "-nonat" and static
routing.
Also, there is firewall on the FS server, which allows connection to
port 5060 only from some selected networks.
Server has static IP=192.168.1.5, WAN IP=173.79.237.11, Phone connected
to LAN, IP=192.168.1.158 (DHCP).
3. When I (and Stan G.) investigated this problem, we run tcpdump
_inside_ the phone, and found -- phone sends
ACKs to WAN ROUTERs port (173.79.237.11), when must send to FS server,
192.168.1.5
{{{
tcpdump -A -vvv port 5060
Via: SIP/2
20:36:27.790809 IP (tos 0xa0, ttl 64, id 28499, offset 0, flags [none],
length: 699) lgvp.5060 > Wireless_Broadband_Router.5060: UDP, length: 671
E...oS.. at ..8.....O.p......%GACK sip:5000 at 173.79.237.11
20:36:27.809815 IP (tos 0xa0, ttl 64, id 28500, offset 0, flags [none],
length: 699) lgvp.5060 > Wireless_Broadband_Router.5060: UDP, length: 671
E...oT.. at ..7.....O.p......%GACK sip:5000 at 173.79.237.11
20:36:27.815188 IP (tos 0xa0, ttl 64, id 28501, offset 0, flags [none],
length: 699) lgvp.5060 > Wireless_Broadband_Router.5060: UDP, length: 671
E...oU.. at ..6.....O.p......%GACK sip:5000 at 173.79.237.11
20:36:29.179099 IP (tos 0x0, ttl 64, id 43922, offset 0, flags [none],
length: 1174) 192.168.1.5.5060 > lgvp.5060: UDP, length: 1146
E....... at .F.................SIP/2.0 200 OK
}}
When router sends UDP packets to FS box, they receiving from Router's
address 173.79.237.11, and rejected by IP firewall.
I allowed my own WAN subnet 173.79.0.0/16 with firewall, and thereafter
phone works OK.
Following - sample of the FS log, when connection works OK, with ACKs.
http://olegh.ath.cx/freeswitch.log-1535-2
<http://olegh.ath.cx/freeswitch.log-1535-1>
But, question: How can I enforce phone works directly with FS, without
loopback in the router?
I assume, phone sends request to WAN address instead of direct FS,
because FS sends to LAN client
contact field, contains WAN address in the SIP 200 message:
Contact: <sip:5000 at 173.79.237.112:5060;transport=udp>
Of course, client sends replies back to this WAN address...
How to fix this issue, for FS send to local clients only something like
Contact: <sip:5000 at 192.168.1.5:5060;transport=udp>
Thanks,
Oleg
Anthony Minessale wrote:
> you are not getting an ACK back from the phone after the 200OK
> investigate the sip traffic and look for something like SIP ALG or
> other things that may cause the ACK to not make it back to FS.
>
>
> 2011/11/3 Oleg Khovayko <khovayko at gmail.com <mailto:khovayko at gmail.com>>
>
> Anthony,
>
>
> Thank you very much for assistance. I produced log-file, contains
> siptrace, you can get it:
>
> http://olegh.ath.cx/freeswitch.log-1535-1
>
> In thins test, I called from numbed 1000 to number 5000.
>
>
> Oleg
>
>
>
>
>
>
>
>
> 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 at gmail.com
>> <mailto:khovayko at 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 at olegh.ath.cx <mailto:1000 at 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 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:39:31.108503 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:39:31.130669 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:39:31.130669 [DEBUG] sofia.c:5283 Channel
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> entering state [terminating][0]
>> 2011-11-02 16:39:31.130669 [DEBUG] switch_channel.c:2804
>> (sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>)
>> Callstate Change ACTIVE -> HANGUP
>> 2011-11-02 16:39:31.130669 [NOTICE] sofia.c:6039 Hangup
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [CS_EXECUTE] [NORMAL_UNSPECIFIED]
>> 2011-11-02 16:39:31.130669 [DEBUG] switch_channel.c:2820 Send
>> signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [KILL]
>> 2011-11-02 16:39:31.130669 [DEBUG] switch_core_session.c:1177
>> Send
>> signal sofia/internal/1000 at olegh.ath.cx
>> <mailto:1000 at 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 at 8000hz 1 channels 20ms
>> 2011-11-02 17:03:09.257683 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 17:03:09.257683 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 17:03:09.257683 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 17:03:09.280490 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 17:03:09.280490 [DEBUG] sofia.c:5283 Channel
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> entering state [terminating][0]
>> 2011-11-02 17:03:09.280490 [DEBUG] switch_channel.c:2804
>> (sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>)
>> Callstate Change ACTIVE -> HANGUP
>> 2011-11-02 17:03:09.280490 [NOTICE] sofia.c:6039 Hangup
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [CS_EXECUTE] [NORMAL_UNSPECIFIED]
>> 2011-11-02 17:03:09.280490 [DEBUG] switch_channel.c:2820 Send
>> signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [KILL]
>> 2011-11-02 17:03:09.280490 [DEBUG] switch_core_session.c:1177
>> Send
>> signal sofia/internal/1000 at olegh.ath.cx
>> <mailto:1000 at 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 at olegh.ath.cx <mailto:1000 at 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 at 8000hz 1 channels 20ms
>> 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:51:50.969016 [DEBUG] switch_core_session.c:872
>> Send signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [BREAK]
>> 2011-11-02 16:51:50.990445 [DEBUG] sofia.c:5283 Channel
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> entering state [terminating][0]
>> 2011-11-02 16:51:50.990445 [DEBUG] switch_channel.c:2804
>> (sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>)
>> Callstate Change ACTIVE -> HANGUP
>> 2011-11-02 16:51:50.990445 [NOTICE] sofia.c:6039 Hangup
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [CS_EXECUTE] [NORMAL_UNSPECIFIED]
>> 2011-11-02 16:51:50.990445 [DEBUG] switch_channel.c:2820 Send
>> signal
>> sofia/internal/1000 at olegh.ath.cx <mailto:1000 at olegh.ath.cx>
>> [KILL]
>> 2011-11-02 16:51:50.990445 [DEBUG] switch_core_session.c:1177
>> Send
>> signal sofia/internal/1000 at olegh.ath.cx
>> <mailto:1000 at 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 at lists.freeswitch.org
>> <mailto: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
>>
>>
>>
>>
>> --
>> Anthony Minessale II
>>
>> FreeSWITCH http://www.freeswitch.org/
>> ClueCon http://www.cluecon.com/
>> Twitter: http://twitter.com/FreeSWITCH_wire
>>
>> AIM: anthm
>> MSN:anthony_minessale at hotmail.com
>> <mailto:MSN%3Aanthony_minessale at hotmail.com>
>> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
>> <mailto:PAYPAL%3Aanthony.minessale at gmail.com>
>> IRC: irc.freenode.net <http://irc.freenode.net> #freeswitch
>>
>> FreeSWITCH Developer Conference
>> sip:888 at conference.freeswitch.org
>> <mailto:sip%3A888 at conference.freeswitch.org>
>> googletalk:conf+888 at conference.freeswitch.org
>> <mailto:googletalk%3Aconf%2B888 at conference.freeswitch.org>
>> pstn:+19193869900 <tel:%2B19193869900>
>>
>>
>> _______________________________________________
>> Join us at ClueCon 2011, Aug 9-11, Chicago
>> http://www.cluecon.com 877-7-4ACLUE
>>
>> FreeSWITCH-dev mailing list
>> FreeSWITCH-dev at lists.freeswitch.org <mailto: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
>
>
>
>
> --
> Anthony Minessale II
>
> FreeSWITCH http://www.freeswitch.org/
> ClueCon http://www.cluecon.com/
> Twitter: http://twitter.com/FreeSWITCH_wire
>
> AIM: anthm
> MSN:anthony_minessale at hotmail.com
> <mailto:MSN%3Aanthony_minessale at hotmail.com>
> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
> <mailto:PAYPAL%3Aanthony.minessale at gmail.com>
> IRC: irc.freenode.net <http://irc.freenode.net> #freeswitch
>
> FreeSWITCH Developer Conference
> sip:888 at conference.freeswitch.org
> <mailto:sip%3A888 at conference.freeswitch.org>
> googletalk:conf+888 at conference.freeswitch.org
> <mailto:googletalk%3Aconf%2B888 at conference.freeswitch.org>
> pstn:+19193869900
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-dev/attachments/20111103/54db8cab/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-dev
mailing list