[asterisk-bugs] [Asterisk 0018257]: Intermittent loss of IP address of SIP peer prevents outbound calls
Asterisk Bug Tracker
noreply at bugs.digium.com
Fri Dec 31 02:07:59 UTC 2010
A NOTE has been added to this issue.
======================================================================
https://issues.asterisk.org/view.php?id=18257
======================================================================
Reported By: essd
Assigned To:
======================================================================
Project: Asterisk
Issue ID: 18257
Category: Channels/chan_sip/General
Reproducibility: sometimes
Severity: minor
Priority: normal
Status: acknowledged
Asterisk Version: 1.6.2.13
JIRA: SWP-2602
Regression: No
Reviewboard Link:
SVN Branch (only for SVN checkouts, not tarball releases): N/A
SVN Revision (number only!):
Request Review:
======================================================================
Date Submitted: 2010-11-04 19:06 CDT
Last Modified: 2010-12-30 20:07 CST
======================================================================
Summary: Intermittent loss of IP address of SIP peer prevents
outbound calls
Description:
Running Asterisk on an embedded ar71xx device (running OpenWRT r20254).
This problem occurs under Asterisk 1.6.2.13, although I was also previously
running 1.6.2.1 for about six months prior with identical symptoms.
Every 2-3 weeks, the PBX gets stuck in a state where it can receive calls
from a peer, but it becomes completely unable to originate outgoing calls
to the same peer until I do a "sip reload". After doing the SIP reload,
everything immediately begins works perfectly again. I can make outgoing
calls (and receive incoming) until it gets stuck again several weeks later.
This is a low-traffic system where it is often a few days between outgoing
calls.
When in the failure state and trying to place a call, after Asterisk has
transmitted the "100 Trying" message to the local calling extension (an
ATA), I see the following "Unable to create channel of type SIP" message in
the log:
(see log-snippet-1.txt)
The calling extension then receives a "480 Temporarily Unavailable" and a
fast busy.
At this point, doing a "sip show peers" also results in seemingly-normal
results, as does "sip show registry". When I do a detailed "sip show
mypeername", the one anomalous thing I see is that that the "Addr->IP"
setting for my peer is listed as "(Unspecified)".
* Name : voipms
Secret : <Set>
[...]
ToHost : dallas.voip.ms
Addr->IP : (Unspecified) Port 5060
Defaddr->IP : 0.0.0.0 Port 5060
Prim.Transp. : UDP
Allowed.Trsp : UDP
[...]
In contrast, after I do a "sip reload", outbound calls start working again
and the "sip show" output looks identical except for showing the correct
address under "Addr->IP":
* Name : voipms
Secret : <Set>
[...]
ToHost : dallas.voip.ms
Addr->IP : 74.54.54.178 Port 5060
Defaddr->IP : 0.0.0.0 Port 5060
Prim.Transp. : UDP
Allowed.Trsp : UDP
[...]
(The full text of "sip show peer mypeername", when in the latter good
state, is attached as sip-show-peer.txt. The only difference between this
and the bad-state version is the Addr->IP.)
It seems like Asterisk has somehow lost the IP address of the peer, but I
do not know why.
One thing potentially related is that, in the previous registration to the
peer (two minutes prior to my failed call), we do the usual
REGISTER/Unauthorized+Nonce/REGISTER+Response/OK business. Immediately
after that, we get a NOTIFY from the remote, which Asterisk responds to
with a 489 Bad Event:
(see log-snippet-2.txt)
Immediately after that exchange, I saw the following curious set of
messages:
[Oct 27 18:44:58] DEBUG[1676]: chan_sip.c:3608 __sip_xmit: Trying to put
'SIP/2.0 489' onto UDP socket destined for 74.54.54.178:5060
[Oct 27 18:44:58] DEBUG[1676]: chan_sip.c:22105 handle_request_do: Invalid
SIP message - rejected , no callid, len 541
Could those messages be related to my problem? I see this "489 Bad Event"
issue may be related to https://issues.asterisk.org/view.php?id=17379, but it's
unclear if this can somehow cause
the SIP remote peer address to get lost, as opposed to just being
potentially bad manners with our SIP peer.
My sip.conf is as follows:
(see sip-config.txt)
A full debug log of trying to place an outbound call is listed here. The
call attempt starts at 19:02:17.
(see sip-log.txt)
Note that I enabled these logs after I discovered the problem, so the
system was already in some sort of invalid state from the beginning of the
detailed debug log.
Is any additional information needed to look into this? I am trying now to
capture full debug logging 24/7 (which is rather tricky given space
considerations on the embedded device), just in case I can somehow trace
down the source of the problem as it happens.
It may be another couple of weeks before the problem surfaces again, and
since I don't know exactly what I am looking for, I'd love to find out if
anyone has specific advice or types of debug output to capture. I've
already reviewed the issue submission guidelines, and checking in with the
asterisk-users list and #asterisk channels did not yield any suggestions.
======================================================================
----------------------------------------------------------------------
(0130068) essd (reporter) - 2010-12-30 20:07
https://issues.asterisk.org/view.php?id=18257#c130068
----------------------------------------------------------------------
The qualify statement did not stop this problem from occurring, since it
just happened again today. Regrettably, I had rebooted my device a few days
earlier and I forgot to restart the debug logging, so I do not yet have any
non-cursory logs that document the issue. I will keep trying to catch it.
Issue History
Date Modified Username Field Change
======================================================================
2010-12-30 20:07 essd Note Added: 0130068
======================================================================
More information about the asterisk-bugs
mailing list