[Freeswitch-users] registration fails after several hours - FS problem?

Mon Nov 1 15:51:17 PDT 2010

Just a quick note. Mario mentions he only sees the problems on osX. I see the
exactly same errors and warning in my logs on a Linux box (Fedora 12 64-bit).
Sometimes it happens every couple of minutes, sometimes it goes away for 2-3
hours.

The excerpt attached is from a log of a freshly compiled git checkout. What I see
is that if it happens, usually multiple external registrations go down, not just
one or just the registrations with one server/provider.

Cheers,

Kurt

On Sun, Oct 31, 2010 at 12:24:35PM -0700, Mario G wrote:
> 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!
> 
> LINUX
> 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.
> 2. Final testing was on git 2010-10-13. Ran fine for 5 days on very old 32 bit system.
> 
> OSX
> 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.
> 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.
> 5. Updated to git 10-29 but made no difference.
> 
> LINUX
> 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!
> 7. Copied and updated Linux to git 10-29 to be the same as Mac box. Again, no problems for 12 hours!
> 
> OSX
> 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:
> 
> 2010-10-31 11:35:00.593970 [WARNING] sofia_reg.c:387 idone Failed Registration, setting retry to 15 seconds.
> 2010-10-31 11:35:13.118634 [NOTICE] sofia_reg.c:342 Registering idtwo
> 2010-10-31 11:35:16.432236 [NOTICE] sofia_reg.c:342 Registering idone
> 2010-10-31 11:35:19.898319 [CRIT] switch_time.c:760 Forward Clock Skew Detected!
> 2010-10-31 11:35:25.440207 [WARNING] switch_scheduler.c:114 Task was executed late by 2 seconds 1 heartbeat (core)
> 2010-10-31 11:35:29.946329 [WARNING] sofia_reg.c:387 idtwo Failed Registration, setting retry to 15 seconds.
> 2010-10-31 11:35:32.147466 [WARNING] sofia_reg.c:387 idone Failed Registration, setting retry to 15 seconds.
> 
> I found the instruction for PCAP and TCPDUMP here in case you need them:
> http://support.apple.com/kb/HT3994
> http://www.osxbook.com/book/bonus/chapter8/core/
> 
> 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.
> 
> 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. 
> 
-------------- next part --------------
The excerpt below is from a log of a freshly compiled git checkout. What I see
is that if it happens, usually multiple external registrations go down, not just
one or just the registrations with one server/provider.

[cut]
[ here the initial registrations happens ]

2010-10-31 22:46:07.173810 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-10-31 22:46:07.176417 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-10-31 22:46:07.176924 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-10-31 22:46:07.178535 [NOTICE] sofia_reg.c:342 Registering s.......info
2010-10-31 22:46:07.178794 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-10-31 22:46:07.178895 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-10-31 22:46:07.179085 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-10-31 22:46:07.179184 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-10-31 22:46:07.179348 [NOTICE] sofia_reg.c:342 Registering i.............com

[NO cut]
[ the following caught my eye but I think it's unrelated ]

2010-10-31 22:46:07.195608 [CRIT] switch_loadable_module.c:928 Error Loading module /usr/local/freeswitch/mod/mod_spidermonkey.so
**/usr/lib64/libnssutil3.so: undefined symbol: PR_GetDirectorySeparator**

[cut]
[ the following is the first thing after the freshly installed instance comes up ]

2010-10-31 22:46:07.240416 [DEBUG] mod_event_socket.c:2688 Socket up listening on 127.0.0.1:8021
2010-10-31 22:46:22.757575 [WARNING] sofia.c:3925 Ping succeeded w.....ch.55 with code 404 - count -1/1/1, state UP
2010-10-31 22:46:23.760832 [WARNING] sofia.c:3925 Ping succeeded w.....ch.54 with code 404 - count -1/1/1, state UP
2010-10-31 22:46:24.777652 [WARNING] sofia.c:3925 Ping succeeded w.....ch.53 with code 404 - count -1/1/1, state UP
2010-10-31 22:46:25.768651 [WARNING] sofia.c:3925 Ping succeeded p..........ch.line3 with code 200 - count -1/1/1, state UP
2010-10-31 22:46:26.774292 [WARNING] sofia.c:3925 Ping succeeded p..........ch.line2 with code 200 - count -1/1/1, state UP
2010-10-31 22:46:27.765993 [WARNING] sofia.c:3925 Ping succeeded p..........ch.line1 with code 200 - count -1/1/1, state UP
2010-10-31 22:46:28.980981 [WARNING] sofia.c:3925 Ping succeeded m.........net with code 200 - count -1/1/1, state UP
2010-10-31 22:46:30.018576 [WARNING] sofia.c:3925 Ping succeeded i.............com with code 200 - count -1/1/1, state UP
2010-10-31 22:46:34.043063 [WARNING] sofia.c:3925 Ping succeeded s.......info with code 200 - count -1/1/1, state UP

[cut]
[ there are some of these from time to time, but not too frequently,
  seems unrelated ]

2010-10-31 23:20:42.935675 [CRIT] switch_time.c:755 Virtual Migration Detected! Syncing Clock
2010-10-31 23:35:13.100848 [CRIT] switch_time.c:755 Virtual Migration Detected! Syncing Clock

[NO cut]
[ I know, this is long, it contains all the messages from going down to
  being up again. Here it happens for the first time after startup, all
  but one registrations are affected and from here this just goes on and
  on, sometimes quiet for 10-40 minutes, but the same thing keeps
  happening over and over and over ]

2010-11-01 00:07:21.730130 [WARNING] sofia.c:3931 Unregister w.....ch.53
2010-11-01 00:07:21.730130 [WARNING] sofia.c:3944 Ping failed w.....ch.53 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:21.835637 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:24.836888 [WARNING] sofia.c:3931 Unregister w.....ch.55
2010-11-01 00:07:24.836888 [WARNING] sofia.c:3944 Ping failed w.....ch.55 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:24.906811 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:27.908720 [WARNING] sofia.c:3931 Unregister m.........net
2010-11-01 00:07:27.908720 [WARNING] sofia.c:3944 Ping failed m.........net with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:28.135215 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:31.136489 [WARNING] sofia.c:3931 Unregister w.....ch.54
2010-11-01 00:07:31.136489 [WARNING] sofia.c:3944 Ping failed w.....ch.54 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:31.289773 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:34.190773 [WARNING] sofia.c:3931 Unregister p..........ch.line3
2010-11-01 00:07:34.190773 [WARNING] sofia.c:3944 Ping failed p..........ch.line3 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:34.190773 [WARNING] sofia.c:3931 Unregister p..........ch.line1
2010-11-01 00:07:34.190773 [WARNING] sofia.c:3944 Ping failed p..........ch.line1 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:34.190773 [WARNING] sofia.c:3931 Unregister p..........ch.line2
2010-11-01 00:07:34.190773 [WARNING] sofia.c:3944 Ping failed p..........ch.line2 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:34.357844 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:34.357844 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:34.357844 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:47.339805 [WARNING] sofia.c:3931 Unregister i.............com
2010-11-01 00:07:47.339805 [WARNING] sofia.c:3944 Ping failed i.............com with code 503 - count -1/0/1, state DOWN
2010-11-01 00:07:47.843793 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:52.965318 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:07:55.042876 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:07:55.966349 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:07:55.966349 [ERR] sofia_reg.c:1653 w.....ch.53 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:07:56.060837 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:56.060837 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:07:59.079583 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:08:02.217283 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:08:05.191866 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:08:05.464553 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:05.464553 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:08:05.464553 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-11-01 00:08:05.464553 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:08:08.192202 [ERR] sofia_reg.c:1653 p..........ch.line1 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:08:08.192202 [ERR] sofia_reg.c:1653 p..........ch.line2 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:08:08.192202 [ERR] sofia_reg.c:1653 p..........ch.line3 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:08:08.706145 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:08.706145 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:08.706145 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:11.190673 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:08:11.835130 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:18.106140 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:08:21.108046 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:08:21.217122 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:27.370918 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:08:27.370918 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:08:27.390525 [ERR] sofia_reg.c:1653 w.....ch.53 Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:27.390525 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:28.410317 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:28.410317 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:36.825828 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:08:38.974290 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:39.975162 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:39.975162 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:08:39.975162 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-11-01 00:08:39.975162 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:08:41.990018 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:08:42.383920 [ERR] sofia_reg.c:1653 p..........ch.line1 Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:42.383920 [ERR] sofia_reg.c:1653 p..........ch.line2 Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:42.383920 [ERR] sofia_reg.c:1653 p..........ch.line3 Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:42.383920 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:08:43.023247 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:43.023247 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:43.023247 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:43.023247 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:08:52.408002 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:08:59.705427 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:08:59.705427 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:09:00.888850 [ERR] sofia_reg.c:1653 w.....ch.53 Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:00.888850 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:01.769563 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:01.769563 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:03.889770 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:09:04.929254 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:10.206481 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:09:10.386155 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:11.228110 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:14.322411 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:09:14.322411 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-11-01 00:09:14.322411 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:09:14.322411 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:09:17.323125 [ERR] sofia_reg.c:1653 p..........ch.line3 Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:17.323125 [ERR] sofia_reg.c:1653 p..........ch.line2 Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:17.323125 [ERR] sofia_reg.c:1653 p..........ch.line1 Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:17.323125 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:17.433443 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:17.433443 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:17.433443 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:17.433443 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:33.027611 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:09:33.027611 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:09:33.988744 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:33.988744 [ERR] sofia_reg.c:1653 w.....ch.53 Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:34.087990 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:34.087990 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:35.160342 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:09:40.386681 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:09:40.421093 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:42.517762 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:09:45.519692 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:45.810237 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:48.998642 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:09:48.998642 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-11-01 00:09:48.998642 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:09:48.998642 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:09:50.392989 [ERR] sofia_reg.c:1653 p..........ch.line1 Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:50.392989 [ERR] sofia_reg.c:1653 p..........ch.line2 Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:50.392989 [ERR] sofia_reg.c:1653 p..........ch.line3 Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:50.392989 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:09:51.047491 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:51.047491 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:51.047491 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:09:51.047491 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:05.982381 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:10:05.982381 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:10:06.960963 [ERR] sofia_reg.c:1653 w.....ch.53 Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:06.960963 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:07.061182 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:07.061182 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:11.447381 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:10:14.448627 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:10:14.532168 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:16.613012 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:10:17.449514 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:17.670659 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:22.822819 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:10:22.822819 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-11-01 00:10:22.822819 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:10:22.822819 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:10:25.231306 [ERR] sofia_reg.c:1653 p..........ch.line3 Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:25.231306 [ERR] sofia_reg.c:1653 p..........ch.line1 Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:25.231306 [ERR] sofia_reg.c:1653 p..........ch.line2 Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:25.231306 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:25.919680 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:25.919680 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:25.919680 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:25.919680 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:38.644573 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:10:38.644573 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:10:41.650658 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #6
2010-11-01 00:10:41.650658 [ERR] sofia_reg.c:1653 w.....ch.53 Registration Failed with status Service Unavailable [503]. failure #6
2010-11-01 00:10:41.656672 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:41.656672 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:45.649294 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:10:46.406928 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:10:46.684822 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:48.723613 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:10:49.407751 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #6
2010-11-01 00:10:49.730897 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:10:56.704864 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:10:56.704864 [NOTICE] sofia_reg.c:342 Registering p..........ch.line2
2010-11-01 00:10:56.704864 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:10:56.704864 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:10:58.719009 [WARNING] sofia.c:3925 Ping succeeded p..........ch.line3 with code 200 - count -1/1/1, state UP
2010-11-01 00:10:58.720180 [WARNING] sofia.c:3925 Ping succeeded p..........ch.line2 with code 200 - count -1/1/1, state UP
2010-11-01 00:10:58.720180 [WARNING] sofia.c:3925 Ping succeeded p..........ch.line1 with code 200 - count -1/1/1, state UP
2010-11-01 00:10:58.815254 [WARNING] sofia.c:3925 Ping succeeded m.........net with code 200 - count -1/1/1, state UP
2010-11-01 00:11:12.608903 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:11:12.608903 [NOTICE] sofia_reg.c:342 Registering w.....ch.53
2010-11-01 00:11:14.616263 [WARNING] sofia.c:3925 Ping succeeded w.....ch.55 with code 404 - count -1/1/1, state UP
2010-11-01 00:11:14.620132 [WARNING] sofia.c:3925 Ping succeeded w.....ch.53 with code 404 - count -1/1/1, state UP
2010-11-01 00:11:17.577143 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:11:19.709772 [WARNING] sofia.c:3925 Ping succeeded i.............com with code 200 - count -1/1/1, state UP
2010-11-01 00:11:20.609130 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:11:22.641562 [WARNING] sofia.c:3925 Ping succeeded w.....ch.54 with code 404 - count -1/1/1, state UP

[NO cut]
[ looks like things have caught up now again, but soon they start again,
  this time only two registrations involved ]

2010-11-01 00:14:38.629434 [WARNING] sofia.c:3931 Unregister m.........net
2010-11-01 00:14:38.629434 [WARNING] sofia.c:3944 Ping failed m.........net with code 503 - count -1/0/1, state DOWN
2010-11-01 00:14:38.759196 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:14:45.858107 [WARNING] sofia.c:3931 Unregister i.............com
2010-11-01 00:14:45.858107 [WARNING] sofia.c:3944 Ping failed i.............com with code 503 - count -1/0/1, state DOWN
2010-11-01 00:14:45.956805 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:15:09.734263 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:15:12.735381 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:15:12.960229 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:15:16.223643 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:15:19.225555 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:15:19.417014 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:15:43.506994 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:15:46.517716 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:15:46.576793 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:15:50.775998 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:15:53.777834 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #2
2010-11-01 00:15:53.841982 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:16:17.978237 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:16:20.979241 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:16:21.020251 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:16:24.083098 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:16:27.084694 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #3
2010-11-01 00:16:27.098816 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:16:52.297707 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:16:55.309436 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:16:55.562035 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:16:58.746040 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:17:01.758269 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #4
2010-11-01 00:17:02.054230 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:17:26.593556 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:17:28.557665 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:17:28.716171 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:17:34.084268 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:17:37.086523 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #5
2010-11-01 00:17:37.285595 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:17:59.763068 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:18:02.764248 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #6
2010-11-01 00:18:02.973280 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:18:08.235127 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:18:11.240533 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #6
2010-11-01 00:18:11.389928 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:18:33.342623 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:18:36.343342 [ERR] sofia_reg.c:1653 m.........net Registration Failed with status Service Unavailable [503]. failure #7
2010-11-01 00:18:36.455978 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:18:42.739771 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:18:45.740268 [ERR] sofia_reg.c:1653 i.............com Registration Failed with status Service Unavailable [503]. failure #7
2010-11-01 00:18:45.828133 [WARNING] sofia_reg.c:387 i.............com Failed Registration, setting retry to 30 seconds.
2010-11-01 00:19:07.761143 [NOTICE] sofia_reg.c:342 Registering m.........net
2010-11-01 00:19:09.907923 [WARNING] sofia.c:3925 Ping succeeded m.........net with code 200 - count -1/1/1, state UP
2010-11-01 00:19:16.055707 [NOTICE] sofia_reg.c:342 Registering i.............com
2010-11-01 00:19:18.261944 [WARNING] sofia.c:3925 Ping succeeded i.............com with code 200 - count -1/1/1, state UP

[NO cut]
[ lines up again and on it goes after a short time, now with all but two
  registrations involved ]

2010-11-01 00:21:22.309002 [WARNING] sofia.c:3931 Unregister p..........ch.line1
2010-11-01 00:21:22.309002 [WARNING] sofia.c:3944 Ping failed p..........ch.line1 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:22.409677 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:30.986146 [WARNING] sofia.c:3931 Unregister w.....ch.54
2010-11-01 00:21:30.986146 [WARNING] sofia.c:3944 Ping failed w.....ch.54 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:30.986146 [WARNING] sofia.c:3931 Unregister w.....ch.55
2010-11-01 00:21:30.986146 [WARNING] sofia.c:3944 Ping failed w.....ch.55 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:31.566020 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:31.566020 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:34.002905 [WARNING] sofia.c:3931 Unregister p..........ch.line3
2010-11-01 00:21:34.002905 [WARNING] sofia.c:3944 Ping failed p..........ch.line3 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:34.728287 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:37.010362 [WARNING] sofia.c:3931 Unregister w.....ch.53
2010-11-01 00:21:37.010362 [WARNING] sofia.c:3944 Ping failed w.....ch.53 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:37.010362 [WARNING] sofia.c:3931 Unregister m.........net
2010-11-01 00:21:37.010362 [WARNING] sofia.c:3944 Ping failed m.........net with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:37.987610 [WARNING] sofia_reg.c:387 w.....ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:37.987610 [WARNING] sofia_reg.c:387 m.........net Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:40.126997 [WARNING] sofia.c:3931 Unregister p..........ch.line2
2010-11-01 00:21:40.126997 [WARNING] sofia.c:3944 Ping failed p..........ch.line2 with code 503 - count -1/0/1, state DOWN
2010-11-01 00:21:41.107835 [WARNING] sofia_reg.c:387 p..........ch.line2 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:21:53.670368 [NOTICE] sofia_reg.c:342 Registering p..........ch.line1
2010-11-01 00:22:02.235855 [NOTICE] sofia_reg.c:342 Registering w.....ch.55
2010-11-01 00:22:02.235855 [NOTICE] sofia_reg.c:342 Registering w.....ch.54
2010-11-01 00:22:03.116142 [ERR] sofia_reg.c:1653 w.....ch.55 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:22:03.116142 [ERR] sofia_reg.c:1653 w.....ch.54 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:22:03.287988 [WARNING] sofia_reg.c:387 w.....ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:22:03.287988 [WARNING] sofia_reg.c:387 w.....ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:22:05.402543 [NOTICE] sofia_reg.c:342 Registering p..........ch.line3
2010-11-01 00:22:06.117219 [ERR] sofia_reg.c:1653 p..........ch.line1 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:22:06.117219 [ERR] sofia_reg.c:1653 p..........ch.line3 Registration Failed with status Service Unavailable [503]. failure #1
2010-11-01 00:22:06.518641 [WARNING] sofia_reg.c:387 p..........ch.line3 Failed Registration, setting retry to 30 seconds.
2010-11-01 00:22:06.518641 [WARNING] sofia_reg.c:387 p..........ch.line1 Failed Registration, setting retry to 30 seconds.

[cut]
[ interestingly, it can also happen seconds after startup; this is
  after a fresh reboot of the machine, mod_spidermonkey no longer autoloaded
  to get rid of the error and the three external registrations I can live
  without are now disabled; FreeSwitch was started and running for around
  10 minutes, during which I saw a constant decrease in memory, so I stopped
  it once, the decrease stopped, then I started FreeSwitch again; this is
  from the second start ]

2010-11-01 11:28:37.866600 [NOTICE] sofia_reg.c:2652 Added gateway 'peoplefone.ch.line1' to profile 'external'
2010-11-01 11:28:37.866732 [NOTICE] sofia_reg.c:2652 Added gateway 'peoplefone.ch.line2' to profile 'external'
2010-11-01 11:28:37.866903 [NOTICE] sofia_reg.c:2652 Added gateway 'peoplefone.ch.line3' to profile 'external'
2010-11-01 11:28:37.866998 [NOTICE] sofia_reg.c:2652 Added gateway 'winet.ch.53' to profile 'external'
2010-11-01 11:28:37.867132 [NOTICE] sofia_reg.c:2652 Added gateway 'winet.ch.54' to profile 'external'
2010-11-01 11:28:37.867242 [NOTICE] sofia_reg.c:2652 Added gateway 'winet.ch.55' to profile 'external'
2010-11-01 11:28:37.867378 [NOTICE] sofia_reg.c:2652 Added gateway 'app1.peoplefone.ch' to profile 'external'
2010-11-01 11:28:37.867499 [WARNING] sofia.c:1853 Ignoring duplicate gateway 'app1.peoplefone.ch'
2010-11-01 11:28:37.867728 [NOTICE] sofia.c:3859 Started Profile external [sofia_reg_external]

[cut]

2010-11-01 11:28:38.890356 [NOTICE] sofia_reg.c:342 Registering winet.ch.55
2010-11-01 11:28:38.891323 [NOTICE] sofia_reg.c:342 Registering winet.ch.54
2010-11-01 11:28:38.891714 [NOTICE] sofia_reg.c:342 Registering winet.ch.53
2010-11-01 11:28:38.892061 [NOTICE] sofia_reg.c:342 Registering peoplefone.ch.line3
2010-11-01 11:28:38.892398 [NOTICE] sofia_reg.c:342 Registering peoplefone.ch.line2
2010-11-01 11:28:38.892665 [NOTICE] sofia_reg.c:342 Registering peoplefone.ch.line1
2010-11-01 11:28:38.993090 [DEBUG] sofia_reg.c:1641 Changing expire time to 3600 by request of proxy sip:app1.peoplefone.ch
2010-11-01 11:28:38.994048 [DEBUG] sofia_reg.c:1641 Changing expire time to 3600 by request of proxy sip:app1.peoplefone.ch
2010-11-01 11:28:39.386825 [NOTICE] switch_loadable_module.c:145 Adding Endpoint 'sofia'

[cut]

2010-11-01 11:28:55.324768 [WARNING] sofia.c:3925 Ping succeeded winet.ch.55 with code 404 - count -1/1/1, state UP
2010-11-01 11:28:56.355487 [WARNING] sofia.c:3925 Ping succeeded winet.ch.54 with code 404 - count -1/1/1, state UP
2010-11-01 11:28:57.377200 [WARNING] sofia.c:3925 Ping succeeded winet.ch.53 with code 404 - count -1/1/1, state UP
2010-11-01 11:28:58.379232 [WARNING] sofia.c:3925 Ping succeeded peoplefone.ch.line3 with code 200 - count -1/1/1, state UP
2010-11-01 11:28:59.406081 [WARNING] sofia.c:3925 Ping succeeded peoplefone.ch.line2 with code 200 - count -1/1/1, state UP
2010-11-01 11:29:00.418566 [WARNING] sofia.c:3925 Ping succeeded peoplefone.ch.line1 with code 200 - count -1/1/1, state UP
2010-11-01 11:29:16.841659 [WARNING] sofia.c:3931 Unregister winet.ch.55
2010-11-01 11:29:16.841659 [WARNING] sofia.c:3944 Ping failed winet.ch.55 with code 503 - count -1/0/1, state DOWN
2010-11-01 11:29:16.841659 [WARNING] sofia.c:3931 Unregister winet.ch.54
2010-11-01 11:29:16.841659 [WARNING] sofia.c:3944 Ping failed winet.ch.54 with code 503 - count -1/0/1, state DOWN
2010-11-01 11:29:16.937681 [WARNING] sofia_reg.c:387 winet.ch.55 Failed Registration, setting retry to 30 seconds.
2010-11-01 11:29:16.937681 [WARNING] sofia_reg.c:387 winet.ch.54 Failed Registration, setting retry to 30 seconds.
2010-11-01 11:29:20.972512 [WARNING] sofia.c:3931 Unregister winet.ch.53
2010-11-01 11:29:20.972512 [WARNING] sofia.c:3944 Ping failed winet.ch.53 with code 503 - count -1/0/1, state DOWN
2010-11-01 11:29:20.972512 [WARNING] sofia.c:3931 Unregister peoplefone.ch.line3
2010-11-01 11:29:20.972512 [WARNING] sofia.c:3944 Ping failed peoplefone.ch.line3 with code 503 - count -1/0/1, state DOWN
2010-11-01 11:29:21.013448 [WARNING] sofia_reg.c:387 winet.ch.53 Failed Registration, setting retry to 30 seconds.
2010-11-01 11:29:21.013448 [WARNING] sofia_reg.c:387 peoplefone.ch.line3 Failed Registration, setting retry to 30 seconds.

[cut]