thr3ads.net - asterisk users - [asterisk-users] What are my logs telling me here? [Aug 2006]

If this information is useful, please help other people find it:
Share via:

Ferguson, Michael

2006-Aug-25 12:54 UTC

[asterisk-users] What are my logs telling me here?

G'Day All,
 
I am trying to figure out and correct some of the issues showing up in the
messages log but, I am still a newbie and thus, somewhat at a loss, so here
goes:
 
NUMBER 1 -- This appears continuously in the log REACHABLE and the UNREACHABLE:
Aug 25 15:24:18 NOTICE[1867]: Peer '5103' is now REACHABLE! (418ms /
1000ms)
Aug 25 15:24:21 NOTICE[1867]: Peer '5107' is now REACHABLE! (448ms /
1000ms)
Aug 25 15:24:23 NOTICE[1867]: Peer '5108' is now REACHABLE! (445ms /
1000ms)
Aug 25 15:25:22 NOTICE[1867]: Peer '5103' is now UNREACHABLE!  Last
qualify: 418
Aug 25 15:25:25 NOTICE[1867]: Peer '5107' is now UNREACHABLE!  Last
qualify: 448
Aug 25 15:25:27 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify: 445
Aug 25 15:26:14 NOTICE[1867]: Peer '5103' is now REACHABLE! (448ms /
1000ms)
Aug 25 15:26:17 NOTICE[1867]: Peer '5107' is now REACHABLE! (449ms /
1000ms)
Aug 25 15:26:19 NOTICE[1867]: Peer '5108' is now REACHABLE! (472ms /
1000ms)
Aug 25 15:27:18 NOTICE[1867]: Peer '5103' is now UNREACHABLE!  Last
qualify: 448
Aug 25 15:27:21 NOTICE[1867]: Peer '5107' is now UNREACHABLE!  Last
qualify: 449
Aug 25 15:27:23 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify: 472


NUMBER 2 -- Why "cause 3" and "Still have a call"
Aug 25 11:08:47 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify: 460
Aug 25 11:08:51 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)
Aug 25 11:08:55 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)
Aug 25 11:09:20 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)
Aug 25 11:09:28 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)
Aug 25 11:09:34 NOTICE[1867]: Peer '5103' is now REACHABLE! (457ms /
1000ms)
Aug 25 11:09:39 NOTICE[1867]: Peer '5108' is now REACHABLE! (551ms /
1000ms)
Aug 25 11:09:56 NOTICE[1867]: Still have a call...
Aug 25 11:09:56 NOTICE[1867]: Peer '5001' is now REACHABLE! (83ms /
1000ms)
Aug 25 11:40:29 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)
Aug 25 11:40:30 NOTICE[1867]: Peer '5107' is now REACHABLE! (350ms /
1000ms)
Aug 25 11:40:31 NOTICE[1867]: Peer '5108' is now REACHABLE! (355ms /
1000ms)
Aug 25 11:49:18 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify: 449
Aug 25 11:49:42 NOTICE[1867]: Still have a call...
Aug 25 11:49:42 NOTICE[1867]: Peer '5003' is now REACHABLE! (26ms /
1000ms)
Aug 25 11:57:04 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)
Aug 25 11:58:14 NOTICE[1867]: Unable to create channel of type 'SIP'
(cause 3)


NUMBER 3 -- This is also repeated quite a bit.
Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
36ef767b19f952fc6ea9f8b03b56126f@6.19.15.11 for seqno 102 (Non-critical Request)
Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
33eeb59a68abfc922b2f47b853f45ddc@6.19.15.11 for seqno 102 (Non-critical Request)
Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
5babbfc421a847f60ef5190514b89a91@6.90.15.11 for seqno 102 (Non-critical Request)


Any pointers, documents, help criticisms
welcome..................Thanks...................Mike
 
 
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
http://lists.digium.com/pipermail/asterisk-users/attachments/20060825/57420487/attachment.htm

BJ Weschke

2006-Aug-25 12:59 UTC

head link

[asterisk-users] What are my logs telling me here?

On 8/25/06, Ferguson, Michael <ferguson@brvmlaw.com>
wrote:>
>
> G'Day All,
>
> I am trying to figure out and correct some of the issues showing up in the
> messages log but, I am still a newbie and thus, somewhat at a loss, so here
> goes:
>
> NUMBER 1 -- This appears continuously in the log REACHABLE and the
> UNREACHABLE:
>
>
> Aug 25 15:24:18 NOTICE[1867]: Peer '5103' is now REACHABLE! (418ms
/ 1000ms)
> Aug 25 15:24:21 NOTICE[1867]: Peer '5107' is now REACHABLE! (448ms
/ 1000ms)
> Aug 25 15:24:23 NOTICE[1867]: Peer '5108' is now REACHABLE! (445ms
/ 1000ms)
> Aug 25 15:25:22 NOTICE[1867]: Peer '5103' is now UNREACHABLE!  Last
qualify:
> 418
> Aug 25 15:25:25 NOTICE[1867]: Peer '5107' is now UNREACHABLE!  Last
qualify:
> 448
> Aug 25 15:25:27 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 445
> Aug 25 15:26:14 NOTICE[1867]: Peer '5103' is now REACHABLE! (448ms
/ 1000ms)
> Aug 25 15:26:17 NOTICE[1867]: Peer '5107' is now REACHABLE! (449ms
/ 1000ms)
> Aug 25 15:26:19 NOTICE[1867]: Peer '5108' is now REACHABLE! (472ms
/ 1000ms)
> Aug 25 15:27:18 NOTICE[1867]: Peer '5103' is now UNREACHABLE!  Last
qualify:
> 448
> Aug 25 15:27:21 NOTICE[1867]: Peer '5107' is now UNREACHABLE!  Last
qualify:
> 449
> Aug 25 15:27:23 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 472
>
> NUMBER 2 -- Why "cause 3" and "Still have a call"
>
>
> Aug 25 11:08:47 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 460
> Aug 25 11:08:51 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
> Aug 25 11:08:55 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
> Aug 25 11:09:20 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
> Aug 25 11:09:28 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
> Aug 25 11:09:34 NOTICE[1867]: Peer '5103' is now REACHABLE! (457ms
/ 1000ms)
> Aug 25 11:09:39 NOTICE[1867]: Peer '5108' is now REACHABLE! (551ms
/ 1000ms)
> Aug 25 11:09:56 NOTICE[1867]: Still have a call...
> Aug 25 11:09:56 NOTICE[1867]: Peer '5001' is now REACHABLE! (83ms /
1000ms)
> Aug 25 11:40:29 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
> Aug 25 11:40:30 NOTICE[1867]: Peer '5107' is now REACHABLE! (350ms
/ 1000ms)
> Aug 25 11:40:31 NOTICE[1867]: Peer '5108' is now REACHABLE! (355ms
/ 1000ms)
> Aug 25 11:49:18 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 449
> Aug 25 11:49:42 NOTICE[1867]: Still have a call...
> Aug 25 11:49:42 NOTICE[1867]: Peer '5003' is now REACHABLE! (26ms /
1000ms)
> Aug 25 11:57:04 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
> Aug 25 11:58:14 NOTICE[1867]: Unable to create channel of type
'SIP' (cause
> 3)
>
> NUMBER 3 -- This is also repeated quite a bit.
>
>
> Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
> 36ef767b19f952fc6ea9f8b03b56126f@6.19.15.11 for seqno 102
> (Non-critical Request)
> Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
> 33eeb59a68abfc922b2f47b853f45ddc@6.19.15.11 for seqno 102
> (Non-critical Request)
> Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
> 5babbfc421a847f60ef5190514b89a91@6.90.15.11 for seqno 102
> (Non-critical Request)
>
> Any pointers, documents, help criticisms
> welcome..................Thanks...................Mike
>
 You've probably got qualify= on your peers in sip.conf. So Asterisk
is sending out a SIP OPTIONS msg to which it's waiting for the peer's
reply. If it doesn't respond, it then marks the peer as unreachable,
and you then cannot dial out to the peer because it's state is
UNREACHABLE which will cause (status 3) messages.

 You might consider increasing your qualify= time and see if that
corrects your problems. If not, you're going to need to start looking
at possible firewall/network interruptions between your Asterisk
instance and your devices to see if they are knocking down traffic
that might be trying to flow between.

 BJ

-- 
Bird's The Word Technologies, Inc.
http://www.btwtech.com/

Ferguson, Michael

2006-Aug-25 13:35 UTC

head link

[asterisk-users] What are my logs telling me here?

BJ,
Thanks much. I do have qualify in my sip.conf (see below) set at 1000.
Also, the asterisk box sits on a public ip ( no firewall) but the devices are
behind a WatchGuard firewall.

Thanks for the pointers. Send me more if you have any. Thanks


[5002]
type=friend 			; either "friend" (peer+user), "peer" or
"user"
host=dynamic
username=5002
secret=5002
context=toll-access
canreinvite=no
qualify=1000
callerid=<5002>
disallow=all
allow=ulaw
allow=alaw
mailbox=5002@extensions
nat=yes
dtmfmode=rfc2833

-----Original Message-----
From: asterisk-users-bounces@lists.digium.com
[mailto:asterisk-users-bounces@lists.digium.com] On Behalf Of BJ Weschke
Sent: Friday, August 25, 2006 4:00 PM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: Re: [asterisk-users] What are my logs telling me here?

On 8/25/06, Ferguson, Michael <ferguson@brvmlaw.com>
wrote:>
>
> G'Day All,
>
> I am trying to figure out and correct some of the issues showing up in 
> the messages log but, I am still a newbie and thus, somewhat at a 
> loss, so here
> goes:
>
> NUMBER 1 -- This appears continuously in the log REACHABLE and the
> UNREACHABLE:
>
>
> Aug 25 15:24:18 NOTICE[1867]: Peer '5103' is now REACHABLE! (418ms
/
> 1000ms) Aug 25 15:24:21 NOTICE[1867]: Peer '5107' is now REACHABLE!
> (448ms / 1000ms) Aug 25 15:24:23 NOTICE[1867]: Peer '5108' is now 
> REACHABLE! (445ms / 1000ms) Aug 25 15:25:22 NOTICE[1867]: Peer
'5103' is now UNREACHABLE!  Last qualify:
> 418
> Aug 25 15:25:25 NOTICE[1867]: Peer '5107' is now UNREACHABLE!  Last
qualify:
> 448
> Aug 25 15:25:27 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 445
> Aug 25 15:26:14 NOTICE[1867]: Peer '5103' is now REACHABLE! (448ms
/
> 1000ms) Aug 25 15:26:17 NOTICE[1867]: Peer '5107' is now REACHABLE!
> (449ms / 1000ms) Aug 25 15:26:19 NOTICE[1867]: Peer '5108' is now 
> REACHABLE! (472ms / 1000ms) Aug 25 15:27:18 NOTICE[1867]: Peer
'5103' is now UNREACHABLE!  Last qualify:
> 448
> Aug 25 15:27:21 NOTICE[1867]: Peer '5107' is now UNREACHABLE!  Last
qualify:
> 449
> Aug 25 15:27:23 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 472
>
> NUMBER 2 -- Why "cause 3" and "Still have a call"
>
>
> Aug 25 11:08:47 NOTICE[1867]: Peer '5108' is now UNREACHABLE!  Last
qualify:
> 460
> Aug 25 11:08:51 NOTICE[1867]: Unable to create channel of type
'SIP'
> (cause
> 3)
> Aug 25 11:08:55 NOTICE[1867]: Unable to create channel of type
'SIP'
> (cause
> 3)
> Aug 25 11:09:20 NOTICE[1867]: Unable to create channel of type
'SIP'
> (cause
> 3)
> Aug 25 11:09:28 NOTICE[1867]: Unable to create channel of type
'SIP'
> (cause
> 3)
> Aug 25 11:09:34 NOTICE[1867]: Peer '5103' is now REACHABLE! (457ms
/
> 1000ms) Aug 25 11:09:39 NOTICE[1867]: Peer '5108' is now REACHABLE!
> (551ms / 1000ms) Aug 25 11:09:56 NOTICE[1867]: Still have a call...
> Aug 25 11:09:56 NOTICE[1867]: Peer '5001' is now REACHABLE! (83ms /
> 1000ms) Aug 25 11:40:29 NOTICE[1867]: Unable to create channel of type 
> 'SIP' (cause
> 3)
> Aug 25 11:40:30 NOTICE[1867]: Peer '5107' is now REACHABLE! (350ms
/
> 1000ms) Aug 25 11:40:31 NOTICE[1867]: Peer '5108' is now REACHABLE!
> (355ms / 1000ms) Aug 25 11:49:18 NOTICE[1867]: Peer '5108' is now
UNREACHABLE!  Last qualify:
> 449
> Aug 25 11:49:42 NOTICE[1867]: Still have a call...
> Aug 25 11:49:42 NOTICE[1867]: Peer '5003' is now REACHABLE! (26ms /
> 1000ms) Aug 25 11:57:04 NOTICE[1867]: Unable to create channel of type 
> 'SIP' (cause
> 3)
> Aug 25 11:58:14 NOTICE[1867]: Unable to create channel of type
'SIP'
> (cause
> 3)
>
> NUMBER 3 -- This is also repeated quite a bit.
>
>
> Aug 24 14:36:30 WARNING[8809]: Maximum retries exceeded on call
> 36ef767b19f952fc6ea9f8b03b56126f@6.19.15.11 for seqno 102 
> (Non-critical Request) Aug 24 14:36:30 WARNING[8809]: Maximum retries 
> exceeded on call
> 33eeb59a68abfc922b2f47b853f45ddc@6.19.15.11 for seqno 102 
> (Non-critical Request) Aug 24 14:36:30 WARNING[8809]: Maximum retries 
> exceeded on call
> 5babbfc421a847f60ef5190514b89a91@6.90.15.11 for seqno 102 
> (Non-critical Request)
>
> Any pointers, documents, help criticisms 
> welcome..................Thanks...................Mike
>
 You've probably got qualify= on your peers in sip.conf. So Asterisk is
sending out a SIP OPTIONS msg to which it's waiting for the peer's
reply. If it doesn't respond, it then marks the peer as unreachable, and you
then cannot dial out to the peer because it's state is UNREACHABLE which
will cause (status 3) messages.

 You might consider increasing your qualify= time and see if that corrects your
problems. If not, you're going to need to start looking at possible
firewall/network interruptions between your Asterisk instance and your devices
to see if they are knocking down traffic that might be trying to flow between.

 BJ

--
Bird's The Word Technologies, Inc.
http://www.btwtech.com/
_______________________________________________
--Bandwidth and Colocation provided by Easynews.com --

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-users

asterisk users - Aug 2006 - What are my logs telling me here?

[asterisk-users] What are my logs telling me here?

[asterisk-users] What are my logs telling me here?

[asterisk-users] What are my logs telling me here?