Koozali.org: home of the SME Server

sip_reg_timeout

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
sip_reg_timeout
« on: January 27, 2008, 12:28:50 AM »
Hi,
  I have had an issue pop up sometime in the last week or so.
I keep getting 'sip_reg_timeout' on all my trunks and extensions, every now and then.

This has caused an active call to just go silent.
These timeouts last from a couple of minutes to around an hour,
and then everything connects again and all is OK.

Here is the asterisk console log of my most recent hit which only lasted a couple of minutes :-
Code: [Select]
[root@l1nuxsvr ~]# asterisk -rvvvvvvv
Asterisk 1.4.17, Copyright (C) 1999 - 2007 Digium, Inc. and others.
Created by Mark Spencer <markster@digium.com>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'core show license' for details.
=========================================================================
  == Parsing '/etc/asterisk/asterisk.conf': Found
  == Parsing '/etc/asterisk/extconfig.conf': Found
Connected to Asterisk 1.4.17 currently running on l1nuxsvr (pid = 4563)
Verbosity is at least 7
l1nuxsvr*CLI> sip show peers
Name/username              Host            Dyn Nat ACL Port     Status
97951738/97951738          192.168.37.250   D          5061     OK (14 ms)
ft2609/87952609            202.86.50.100               5060     OK (28 ms)
ftel1901/87951901          202.86.50.100               5060     OK (27 ms)
ft1738/87951738            202.86.50.100               5060     OK (29 ms)
ft1708/87951708            202.86.50.100               5060     OK (30 ms)
ft0112/87950112            202.86.50.100               5060     OK (28 ms)
pt5551/61386835551         203.166.6.160               5060     OK (31 ms)
09109431/09109431          125.213.160.81              5060     OK (23 ms)
5010/Study                 192.168.37.71    D          5060     OK (96 ms)
5009/Glen                  192.168.37.252   D   N      11065    OK (121 ms)
5008/HomePC                (Unspecified)    D          0        UNKNOWN
5007/Jo                    192.168.37.252   D   N      1088     OK (109 ms)
5005/Dani                  (Unspecified)    D          0        UNKNOWN
5004/Matt                  (Unspecified)    D          0        UNKNOWN
5000/homephone             192.168.37.250   D          5060     OK (6 ms)
15 sip peers [Monitored: 12 online, 3 offline Unmonitored: 0 online, 0 offline]
[Jan 27 09:33:13] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5007' is now UNREACHABLE!  Last qualify: 107
 Extension Changed 5007 new state Unavailable for Notify User Glen
[Jan 27 09:58:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 27 09:58:44] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 27 09:58:59] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 27 09:59:14] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 27 09:59:44] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951738@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '97951738' is now UNREACHABLE!  Last qualify: 7
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5000' is now UNREACHABLE!  Last qualify: 7
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '09109431' is now UNREACHABLE!  Last qualify: 25
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'ft2609' is now UNREACHABLE!  Last qualify: 27
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'ftel1901' is now UNREACHABLE!  Last qualify: 29
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'ft1738' is now UNREACHABLE!  Last qualify: 26
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'ft1708' is now UNREACHABLE!  Last qualify: 29
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'ft0112' is now UNREACHABLE!  Last qualify: 27
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'pt5551' is now UNREACHABLE!  Last qualify: 27
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5010' is now UNREACHABLE!  Last qualify: 95
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5009' is now UNREACHABLE!  Last qualify: 104
 Extension Changed 5000 new state Unavailable for Notify User Glen
 Extension Changed 5010 new state Unavailable for Notify User Glen
[Jan 27 09:59:59] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 27 10:00:14] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 27 10:00:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 27 10:00:44] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 27 10:00:59] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '09109431@sip00.mynetfone.com.au' timed out, trying again (Attempt #1)
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
[Jan 27 10:01:14] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951738@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 27 10:01:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #3)
[Jan 27 10:01:44] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #3)
[Jan 27 10:01:59] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #3)
[Jan 27 10:02:14] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #3)
[Jan 27 10:02:25] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '09109431@sip00.mynetfone.com.au' timed out, trying again (Attempt #2)
[Jan 27 10:02:25] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951738@sip.freshtel.net' timed out, trying again (Attempt #3)
[Jan 27 10:02:25] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #4)
[Jan 27 10:02:25] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #4)
    -- Registered SIP '5000' at 192.168.37.250 port 5060 expires 180
 Extension Changed 5000 new state Idle for Notify User Glen
[Jan 27 10:02:25] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5000' is now Reachable. (10ms / 3000ms)
    -- Registered SIP '97951738' at 192.168.37.250 port 5061 expires 180
[Jan 27 10:02:26] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '97951738' is now Reachable. (10ms / 3000ms)
    -- Registered SIP '5009' at 192.168.37.252 port 11069 expires 180
[Jan 27 10:02:26] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5009' is now Reachable. (50ms / 3000ms)
    -- Unregistered SIP '5009'
    -- Registered SIP '5009' at 192.168.37.252 port 11069 expires 180
    -- Saved useragent "X-Lite release 1011s stamp 41150" for peer 5009
[Jan 27 10:02:26] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5009' is now Reachable. (4ms / 3000ms)
    -- Registered SIP '5010' at 192.168.37.71 port 5060 expires 180
 Extension Changed 5010 new state Idle for Notify User Glen
 Extension Changed 5010 new state Idle for Notify User Glen
[Jan 27 10:02:27] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5010' is now Reachable. (264ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '09109431' is now Reachable. (25ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'ft2609' is now Reachable. (30ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'ftel1901' is now Reachable. (35ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'ft1738' is now Reachable. (35ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'ft1708' is now Reachable. (40ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'pt5551' is now Reachable. (43ms / 3000ms)
[Jan 27 10:02:35] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'ft0112' is now Reachable. (47ms / 3000ms)
    -- Registered SIP '5007' at 192.168.37.252 port 15730 expires 180
 Extension Changed 5007 new state Idle for Notify User Glen
[Jan 27 10:14:46] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5007' is now Reachable. (51ms / 3000ms)
    -- Unregistered SIP '5007'
 Extension Changed 5007 new state Unavailable for Notify User Glen
    -- Registered SIP '5007' at 192.168.37.252 port 15730 expires 180
    -- Saved useragent "X-Lite release 1011s stamp 41150" for peer 5007
 Extension Changed 5007 new state Idle for Notify User Glen
[Jan 27 10:14:46] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5007' is now Reachable. (6ms / 3000ms)

I do not lose internet connectivity at this time,  So I cannot blame the ISP (also my extensions would not be hit if it was ISP)
This was happening while running sail 2.2.1-582,  und I have upgraded to -587 last night without change.
asterisk-1.4.17-55.el4  and have been for a number of weeks, I only noticed this timeout issue in the last week or so.

Given the timing, it may be related to the recent sme 7.3 updates.

But I am at a loss to what is the cause or how to resolve,
any help would be great ;-)
(fortunately wife has not noticed yet)  :-?


Offline SARK devs

  • ****
  • 2,806
  • +1/-0
    • http://sarkpbx.com
Re: sip_reg_timeout
« Reply #1 on: January 27, 2008, 02:00:41 AM »
Very odd.  I have never seen asterisk lose coms with local devices like this.  As an aside, why does...

5009/Glen                  192.168.37.252   D   N      11065    OK (121 ms)

and...

5007/Jo                    192.168.37.252   D   N      1088     OK (109 ms)

have the same IP address?  Is this a 2102 or something similar?

Anyhoo, could this be a network switch error?  I have seen IAX peers on carrier sites go off like this but NEVER a local device.

I'll have a google on the asterisk BB's

Best



Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #2 on: January 27, 2008, 02:53:34 AM »
Hi Selintra,
  I looked at that and wondered if it would get picked on ;-)
they both have the same IP due to that IP being my wireless router address.
Both those Xtn's are X-Lite on laptops, and are set for NAT (N). so are same gateway address with different ports.

My Network switch is just an unitelligent SMC switch, and like I said, I get no other issues with web browsing etc.
Also the Trunks are direct out the 2nd interface of sme-server to the cable modem, not via the network switch at all.

Something in the IP stack in sme ?
yet I have nothing in the /var/log/messages to indicate an issue at all.

Any ideas of what to look at / trace etc  to get an idea of what is going on ?

cheers  G


Offline SARK devs

  • ****
  • 2,806
  • +1/-0
    • http://sarkpbx.com
Re: sip_reg_timeout
« Reply #3 on: January 27, 2008, 03:12:25 AM »
Have a look at this  thread...

http://forums.digium.com/viewtopic.php?=&p=44574


Best

S

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #4 on: January 27, 2008, 03:38:22 AM »
Curious,
  so if I set qualify off  it should sort out the issue ?

in my sip.conf I find
Code: [Select]
[5009]
type=friend
username=Glen
secret=763029
host=dynamic
[b]qualify=3000[/b]
context=internal
callerid="Glen" <5009>
canreinvite=no
mailbox=5009
pickupgroup=1
callgroup=1
disallow=all
allow=gsm
allow=ulaw
allow=alaw

nat=yes

So how do I disable this and for the trunks in sail ?

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #5 on: January 27, 2008, 03:56:23 AM »
I edit qualify to =no on my main trunks and extensions,
I now get
Code: [Select]
l1nuxsvr*CLI> sip show peers
Name/username              Host            Dyn Nat ACL Port     Status
97951738/97951738          192.168.37.250   D          5061     Unmonitored
ft2609/87952609            202.86.50.100               5060     OK (28 ms)
ftel1901/87951901          202.86.50.100               5060     OK (32 ms)
ft1738/87951738            202.86.50.100               5060     Unmonitored
ft1708/87951708            202.86.50.100               5060     OK (30 ms)
ft0112/87950112            202.86.50.100               5060     OK (28 ms)
pt5551/61386835551         203.166.6.160               5060     Unmonitored
09109431/09109431          125.213.160.81              5060     Unmonitored
5010/Study                 192.168.37.71    D          5060     Unmonitored
5009/Glen                  192.168.37.252   D   N      11069    Unmonitored
5008/HomePC                (Unspecified)    D          0        UNKNOWN
5007/Jo                    192.168.37.252   D   N      9544     Unmonitored
5005/Dani                  (Unspecified)    D          0        UNKNOWN
5004/Matt                  (Unspecified)    D          0        UNKNOWN
5000/homephone             192.168.37.250   D          5060     Unmonitored
15 sip peers [Monitored: 4 online, 3 offline Unmonitored: 8 online, 0 offline]
l1nuxsvr*CLI>
So qualify is a monitoring setting ?

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #6 on: January 27, 2008, 07:26:35 AM »
Have a look at this  thread...

http://forums.digium.com/viewtopic.php?=&p=44574

So far with qualify=no set on all my trunks and extensions, it appears all good.
But the above thread is 12 months old, and no mention of a fix to the qualify bug ?

While only a minor issue now, the 'State'  column in the Trunks and extensions display an X or a !

Offline SARK devs

  • ****
  • 2,806
  • +1/-0
    • http://sarkpbx.com
Re: sip_reg_timeout
« Reply #7 on: January 27, 2008, 09:42:07 AM »
It isn't clear to me that there is a bug in qualify.  Also SAIL is not presenting unmonitored trunks and extensions properly.  However, first things first; let's see if this cures your problem.  Suggest you keep an eye on this and re-post yhour results in a week or so,

Best

S

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #8 on: January 27, 2008, 09:59:47 AM »
No problem, will do..
  Thanks Sel.

G

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #9 on: January 28, 2008, 12:28:04 AM »
OK,
  that didn't help,  seems it just stops the reporting of 'some' of the messages....

Code: [Select]
[Jan 28 09:44:47] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '61386835551@sip.pennytel.com' timed out, trying again (Attempt #1)
[Jan 28 09:45:18] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #1)
 Extension Changed 5000 new state Unavailable for Notify User Glen
 Extension Changed 5000 new state Unavailable for Notify User Jo
[Jan 28 09:45:33] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 28 09:45:48] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 28 09:46:03] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 28 09:46:18] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951738@sip.freshtel.net' timed out, trying again (Attempt #1)
 Extension Changed 5010 new state Unavailable for Notify User Glen
 Extension Changed 5010 new state Unavailable for Notify User Jo
[Jan 28 09:46:33] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '61386835551@sip.pennytel.com' timed out, trying again (Attempt #2)
[Jan 28 09:46:48] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '09109431@sip00.mynetfone.com.au' timed out, trying again (Attempt #1)
[Jan 28 09:47:03] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 28 09:47:18] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #2)
 Extension Changed 5007 new state Unavailable for Notify User Glen
[Jan 28 09:47:33] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #2)

Note there is no reg_timeout reported for xtn 5000 or 5010  yet they have reported a new state !
I will set my qualify back to 3000, at so I get vaild reporting

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #10 on: January 28, 2008, 12:45:10 AM »
Also just noticed something intriguing..
I had disabled..  i.e  unchecked 'ACT' for the following trunks....
Code: [Select]
[Jan 28 09:45:18] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 28 09:45:33] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 28 09:45:48] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 28 09:46:03] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #1)

Yet they still report the timeouts ??
If they are not 'ACTIVE' according to the Check box in SAIL,  why would they be attempting to register ?

Offline hervep

  • **
  • 70
  • +0/-0
Re: sip_reg_timeout
« Reply #11 on: January 28, 2008, 06:21:03 AM »
Hi G,

Not sure at this stage, but I had something more or less similar using IAX trunks between dynamic ip DSL connections. The issue was the 'nat session timing' ( session was dead before qualify check ).

Don't know if it can help, but I would suggest to try using a low qualify value to make the test ( I.E. 45 secs ) and see the result. Idea is to keep the 'NAT session' active by sending data before the router kills the nat cross table relation.

Best,

Herve


Offline SARK devs

  • ****
  • 2,806
  • +1/-0
    • http://sarkpbx.com
Re: sip_reg_timeout
« Reply #12 on: January 28, 2008, 01:46:30 PM »
Hi Guys,

Yeah, I though that would happen.  The removal of the qualfy is just ignoring the problem.  Re ACT ticked/unticked.  There is a little bug.  Even if you untick the trunk, we still generate the registration (if there is one).  I've been meaning to fix it for yonks but never gotten 'round to it.

Best

J

Offline groutley

  • ****
  • 213
  • +0/-0
    • http://www.routley.homeip.net
Re: sip_reg_timeout
« Reply #13 on: January 29, 2008, 12:25:35 PM »
Don't know if it can help, but I would suggest to try using a low qualify value to make the test ( I.E. 45 secs ) and see the result. Idea is to keep the 'NAT session' active by sending data before the router kills the nat cross table relation.

I tried setting qualify=45  and continually go LAGGED messages, setting to 30 produced even more LAGGED messages.
I set to 60 which appears to be enough time to allow for the LAG,  but I still got...
Code: [Select]
Extension Changed 5004 new state Unavailable for Notify User Glen
[Jan 29 21:29:09] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #1)
 Extension Changed 5010 new state Unavailable for Notify User Glen
[Jan 29 21:29:24] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 29 21:29:54] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 29 21:30:09] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '09109431' is now UNREACHABLE!  Last qualify: 29
[Jan 29 21:30:09] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'pt5551' is now UNREACHABLE!  Last qualify: 33
[Jan 29 21:30:09] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951738@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 29 21:30:24] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '97951738' is now UNREACHABLE!  Last qualify: 6
[Jan 29 21:30:24] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer 'ft1738' is now UNREACHABLE!  Last qualify: 27
[Jan 29 21:30:24] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87950112@sip.freshtel.net' timed out, trying again (Attempt #1)
[Jan 29 21:30:29] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5000' is now UNREACHABLE!  Last qualify: 7
[Jan 29 21:30:29] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5010' is now UNREACHABLE!  Last qualify: 95
[Jan 29 21:30:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '61386835551@sip.pennytel.com' timed out, trying again (Attempt #1)
 Extension Changed 5000 new state Unavailable for Notify User Glen
[Jan 29 21:30:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951901@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 29 21:30:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87952609@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 29 21:30:29] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '09109431@sip00.mynetfone.com.au' timed out, trying again (Attempt #1)
[Jan 29 21:30:30] NOTICE[4671]: chan_sip.c:7422 sip_reg_timeout:    -- Registration for '87951708@sip.freshtel.net' timed out, trying again (Attempt #2)
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 336, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5008@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 337, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5004@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 338, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5005@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 339, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5007@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 336, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5008@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 337, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5004@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 338, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5005@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 339, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5007@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 336, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5008@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 337, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5004@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 338, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5005@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 339, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5007@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 336, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5008@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 337, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5004@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 338, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5005@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 339, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5007@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 336, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5008@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 337, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5004@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 338, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5005@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 339, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5007@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 336, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5008@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 337, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5004@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 338, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5005@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 339, laststate: 0, dialogver: 0, subscribecont: '', subscribeuri: '5007@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 334, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5010@internal'
[Jan 29 21:30:30] WARNING[4671]: chan_sip.c:14870 handle_request_subscribe: SUBSCRIBE failure: no Accept header: pvt: stateid: 335, laststate: 4, dialogver: 0, subscribecont: '', subscribeuri: '5000@internal'
    -- Registered SIP '5000' at 192.168.37.250 port 5060 expires 180
    -- Registered SIP '97951738' at 192.168.37.250 port 5061 expires 180
[Jan 29 21:30:31] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5000' is now Reachable. (9ms / 3000ms)
 Extension Changed 5000 new state Idle for Notify User Glen
[Jan 29 21:30:31] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '97951738' is now Reachable. (58ms / 3000ms)
    -- Registered SIP '5010' at 192.168.37.71 port 5060 expires 180
[Jan 29 21:30:34] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5010' is now Reachable. (189ms / 3000ms)
 Extension Changed 5010 new state Idle for Notify User Glen
[Jan 29 21:30:34] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'ft1738' is now Reachable. (28ms / 60ms)
    -- Registered SIP '5009' at 192.168.37.252 port 15614 expires 180
[Jan 29 21:30:38] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5009' is now Reachable. (25ms / 45ms)
    -- Unregistered SIP '5009'
    -- Registered SIP '5009' at 192.168.37.252 port 15614 expires 180
    -- Saved useragent "X-Lite release 1011s stamp 41150" for peer 5009
[Jan 29 21:30:38] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5009' is now Reachable. (5ms / 45ms)
[Jan 29 21:30:40] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '09109431' is now Reachable. (25ms / 60ms)
[Jan 29 21:30:40] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer 'pt5551' is now Reachable. (28ms / 60ms)
[Jan 29 21:32:38] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5009' is now UNREACHABLE!  Last qualify: 38
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
[Jan 29 22:11:10] NOTICE[4671]: chan_sip.c:12517 handle_response_peerpoke: Peer '5009' is now Reachable. (3ms / 45ms)
[Jan 29 22:12:11] NOTICE[4671]: chan_sip.c:15655 sip_poke_noanswer: Peer '5009' is now UNREACHABLE!  Last qualify: 3
l1nuxsvr*CLI>


I have no idea what most of that means, but I do not understand why this has all of a sudden started.
My setup had been working without issue for months.
But since approx Mid January I have got this constantly,  and it does affect the Trunks.
I have had calls just stop,  mid call,  and my wife has now tried to make a call and got dead silence.

The people complaining of the Qualify setting have said they are not affected,  but just want to clean up the messages.
Mine is more serious.
And I have to put it down to one of the recent updates I applied to sme, but which one ?

How do I get to the bottom of this ?

Offline SARK devs

  • ****
  • 2,806
  • +1/-0
    • http://sarkpbx.com
Re: sip_reg_timeout
« Reply #14 on: January 29, 2008, 03:52:27 PM »
Have you changed your router or router settings lately?

Best

S