<html><head></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; ">A final update for those interested. Anthony worked many hours last Mon-Wed (11/2-3) and solved this issue. I leave it up to him if he wants to explain/add comments. I thoroughly tested FS for 48 hours twice and shorter two other times. Not once did it fail to register, even after an isp upgrade knocked the line out 7 times one night. FS is recovering from lost connections and reregistering perfectly every time as far as I can tell. The fix was applied to the git on 11/3.<div>MANY THANKS TO ANTHONY!</div><div>Mario G<br><div><br><div><div>On Nov 2, 2010, at 5:01 PM, <a href="mailto:pbdlists@pinboard.com">pbdlists@pinboard.com</a> wrote:</div><br class="Apple-interchange-newline"><blockquote type="cite"><div>Hello Anthony,<br><br>Indeed, even though I can't understand most of what is going on in this<br>debug output, it is helpful. Here what I found (I still have the traces,<br>but can't put them anywhere public):<br><br>- just before the registrations go away, freeswitch says it got an ICMP<br> &nbsp;type 3 code 1 (no route to host):<br> &nbsp;&nbsp;&nbsp;&nbsp;ESC[mESC[mtport_wakeup_pri(0x7f9030004520): events ERR<br> &nbsp;&nbsp;&nbsp;&nbsp;ESC[mESC[mtport_udp_error: No route to host (113) [icmp type=3 code=1]<br> &nbsp;&nbsp;&nbsp;&nbsp;ESC[mESC[m &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;reported by [188..........9]:0<br> &nbsp;&nbsp;&nbsp;&nbsp;ESC[mESC[mnta_agent: tport: 88........1:1024: No route to host<br>- a tcpdump, however, shows no such ICMP packet<br>- routes are static and a dump of the routing table every 5 seconds<br> &nbsp;shows that the default route (used for these destinations) is there<br>- some more testing, capturing and searching shows a very interesting<br>behaviour:<br> &nbsp;- none of the network interfaces used to communicate to anywhere<br> &nbsp;&nbsp;&nbsp;outside of the box do show the ICMP reported by freeswitch, neither<br> &nbsp;&nbsp;&nbsp;the external facing interface, nor the internal facing interface<br> &nbsp;- BUT:<br> &nbsp;&nbsp;&nbsp;- on the loopback interface I do get ICMP type 3 code 1 (host<br> &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;unreachable) messages<br> &nbsp;&nbsp;&nbsp;- the ICMP messages I see there are only for systems which which<br> &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;freeswitch is communicating<br> &nbsp;&nbsp;&nbsp;- the ICMP messages I see there are exactly for the remote systems<br> &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;which were reported down, plus for one internal registrations)<br> &nbsp;&nbsp;&nbsp;- the timestamps of the ICMP messages starting and the registrations<br> &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;going down match, as well as the timestamps of the ICMP messages<br> &nbsp;&nbsp;&nbsp;&nbsp;&nbsp;stopping and the registrations coming up again<br><br>I didn't change much on the default config and as far as I know nothing<br>network related. Is it possible that I nevertheless messed up my config<br>somewhere, causing freeswitch to chose the loopback interface for<br>communicating from time to time?<br><br>Cheers,<br><br>Kurt<br><br>On Mon, Nov 01, 2010 at 06:59:27PM -0500, Anthony Minessale wrote:<br><blockquote type="cite">what would help is if you can get a similar log with the siptrace on<br></blockquote><blockquote type="cite">the profile and sofia global loglevel 9<br></blockquote><blockquote type="cite">The key is the catch the very first time it goes wrong, possibly a<br></blockquote><blockquote type="cite">full pcap of any network activity as well to look for more clues.<br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite">This appears to be some sort of strange environmental condition or<br></blockquote><blockquote type="cite">particular edge case that breaks the sip lib internally.<br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite">On Mon, Nov 1, 2010 at 5:51 PM, &nbsp;&lt;<a href="mailto:pbdlists@pinboard.com">pbdlists@pinboard.com</a>&gt; wrote:<br></blockquote><blockquote type="cite"><blockquote type="cite">Just a quick note. Mario mentions he only sees the problems on osX. I see the<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">exactly same errors and warning in my logs on a Linux box (Fedora 12 64-bit).<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">Sometimes it happens every couple of minutes, sometimes it goes away for 2-3<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">hours.<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">The excerpt attached is from a log of a freshly compiled git checkout. What I see<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">is that if it happens, usually multiple external registrations go down, not just<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">one or just the registrations with one server/provider.<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">Cheers,<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">Kurt<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite">On Sun, Oct 31, 2010 at 12:24:35PM -0700, Mario G wrote:<br></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">I have the pcap and dump to email to you and lot's of new info on this serious bug (yes it's a bug on FS for osX). The pcap is 1.1M and dump is 350M, please tell me where to send them. I don't want to put then in public areas since they contain security info. Please review my steps below. I don't know FS or Linux internals but it seems a lot like a timing issue where two processes are not communicating with each other since retry messages occur but there is no SIP tracing going on. THANKS SO MUCH!<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">LINUX<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">1. Setup FS on OpenSuse starting Sep 15. After basic initial problems there was a serious nat/upnp problems that lasted 3 weeks. Fixed with help, but still used nat.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2. Final testing was on git 2010-10-13. Ran fine for 5 days on very old 32 bit system.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">OSX<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">3. Purchased Mac Mini and installed FS git 2010-10-23. Lasted only 3 to 17 hours. Problems looked same as nat so switched to full static.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">4. With all static (-nonat) and only one DSL static connection active ITSPs go down in 5-60 minutes one by one. Still thought it was network related. Sent you traces.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">5. Updated to git 10-29 but made no difference.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">LINUX<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">6. Went back to the Linux box with git 10-13 using copy of config from mac. Pure static as osX. No problems for 6 hours!<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">7. Copied and updated Linux to git 10-29 to be the same as Mac box. Again, no problems for 12 hours!<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">OSX<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">8. Went back to the mac to provide you with pcap and dump. In about 15 minutes FS lost 2 ITSPs. Here are messages issues during pcap/dump, NOTE clock message which is first I have seen of it:<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:00.593970 [WARNING] sofia_reg.c:387 idone Failed Registration, setting retry to 15 seconds.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:13.118634 [NOTICE] sofia_reg.c:342 Registering idtwo<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:16.432236 [NOTICE] sofia_reg.c:342 Registering idone<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:19.898319 [CRIT] switch_time.c:760 Forward Clock Skew Detected!<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:25.440207 [WARNING] switch_scheduler.c:114 Task was executed late by 2 seconds 1 heartbeat (core)<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:29.946329 [WARNING] sofia_reg.c:387 idtwo Failed Registration, setting retry to 15 seconds.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">2010-10-31 11:35:32.147466 [WARNING] sofia_reg.c:387 idone Failed Registration, setting retry to 15 seconds.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">I found the instruction for PCAP and TCPDUMP here in case you need them:<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><a href="http://support.apple.com/kb/HT3994">http://support.apple.com/kb/HT3994</a><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><a href="http://www.osxbook.com/book/bonus/chapter8/core/">http://www.osxbook.com/book/bonus/chapter8/core/</a><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">Note: I had the Mini set to no sleep even though it worked with Linux sleep. I found a couple others on the web who had the same problem and one had written a script to restart FS every 4 hours. Fried (tired) right now and cant find the URL but it was from Jan 2010.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite">One last thing to mention is that on osX using auto-nat:1.2.3.4 and some expiry parms, etc that may have triggered activity, FS worked much longer than on static. This is why I think it's timer or sync related and only on osX.<br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote></blockquote><blockquote type="cite"><blockquote type="cite"><br></blockquote></blockquote><blockquote type="cite"><font class="Apple-style-span" color="#540000"><br></font></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite">-- <br></blockquote><blockquote type="cite">Anthony Minessale II<br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite">FreeSWITCH <a href="http://www.freeswitch.org/">http://www.freeswitch.org/</a><br></blockquote><blockquote type="cite">ClueCon <a href="http://www.cluecon.com/">http://www.cluecon.com/</a><br></blockquote><blockquote type="cite">Twitter: <a href="http://twitter.com/FreeSWITCH_wire">http://twitter.com/FreeSWITCH_wire</a><br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite">AIM: anthm<br></blockquote><blockquote type="cite">MSN:anthony_minessale@hotmail.com<br></blockquote><blockquote type="cite">GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<br></blockquote><blockquote type="cite">IRC: <a href="http://irc.freenode.net">irc.freenode.net</a> #freeswitch<br></blockquote><blockquote type="cite"><br></blockquote><blockquote type="cite">FreeSWITCH Developer Conference<br></blockquote><blockquote type="cite"><a href="sip:888@conference.freeswitch.org">sip:888@conference.freeswitch.org</a><br></blockquote><blockquote type="cite">googletalk:conf+888@conference.freeswitch.org<br></blockquote><blockquote type="cite">pstn:+19193869900<br></blockquote><blockquote type="cite"><br></blockquote><br>-- <br></div></blockquote></div><br></div></div></body></html>