Hello community,<div><br></div><div>I&#39;ve been running Asterisk on an embedded device for about six months, and my operation has been largely trouble-free. I&#39;m hoping I could get some help with a minor problem:</div>
<div><br></div><div>Every week or three, my PBX gets stuck in a state where it can receive calls, but it becomes completely unable to originate outgoing calls until I do a &quot;sip reload&quot;. After doing the SIP reload, everything immediately begins works perfectly again and I can make outgoing calls until it gets stuck again several weeks later.</div>
<div><br></div><div>I recently upgraded to Asterisk 1.6.2.13, although I was also running 1.6.2.1 for a long time with identical symptoms. My system is an embedded ar71xx running the OpenWRT distribution.</div><div><br></div>
<div>When I attempt to place a call, after Asterisk has transmitted the &quot;100 Trying&quot; message to the calling extension (an ATA), I see the following &quot;Unable to create channel of type SIP&quot; message in the log:</div>
<div><br></div><div><div>[Oct 27 18:46:48] DEBUG[25028]: pbx.c:3696 pbx_extension_helper: Launching &#39;Set&#39;</div><div>[Oct 27 18:46:48] DEBUG[25028]: pbx.c:3696 pbx_extension_helper: Launching &#39;Dial&#39;</div><div>
[Oct 27 18:46:48] DEBUG[25028]: chan_sip.c:23241 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw)</div><div>[Oct 27 18:46:48] DEBUG[25028]: chan_sip.c:7381 sip_alloc: Allocating new SIP dialog for <a href="mailto:2ccf324d10670f2c73f478b523f926a4@10.15.1.1">2ccf324d10670f2c73f478b523f926a4@10.15.1.1</a> - INVITE (With RTP)</div>
<div>Really destroying SIP dialog &#39;<a href="mailto:2ccf324d10670f2c73f478b523f926a4@10.15.1.1">2ccf324d10670f2c73f478b523f926a4@10.15.1.1</a>&#39; Method: INVITE</div><div>[Oct 27 18:46:48] WARNING[25028]: app_dial.c:1750 dial_exec_full: Unable to create channel of type &#39;SIP&#39; (cause 20 - Unknown)</div>
<div>[Oct 27 18:46:48] DEBUG[25028]: rtp.c:2148 ast_rtp_early_bridge: Channel &#39;&lt;unspecified&gt;&#39; has no RTP, not doing anything</div><div>[Oct 27 18:46:48] DEBUG[25028]: app_dial.c:2326 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL.</div>
<div>[Oct 27 18:46:48] DEBUG[25028]: pbx.c:3696 pbx_extension_helper: Launching &#39;Hangup&#39;</div><div>[Oct 27 18:46:48] DEBUG[25028]: pbx.c:4322 __ast_pbx_run: Spawn extension (phones,15102857673,3) exited non-zero on &#39;SIP/101-0000000a&#39;</div>
<div>[Oct 27 18:46:48] DEBUG[25028]: channel.c:1715 ast_softhangup_nolock: Soft-Hanging up channel &#39;SIP/101-0000000a&#39;</div></div><div><br></div><div>The calling extension then receives a &quot;480 Temporarily Unavailable&quot; and a fast busy.</div>
<div><br></div><div>Doing a &quot;sip show peers&quot; appears normal. When I do a detailed &quot;sip show mypeername&quot;, the one anomalous thing I see is that that the &quot;Addr-&gt;IP&quot; setting is listed as &quot;(Unspecified)&quot;.</div>
<div><br></div><div> * Name       : voipms</div><div>  Secret       : &lt;Set&gt;</div><div>[...]  </div><div>  ToHost       : <a href="http://dallas.voip.ms">dallas.voip.ms</a></div><div>  Addr-&gt;IP     : (Unspecified) Port 5060</div>
<div>  Defaddr-&gt;IP  : 0.0.0.0 Port 5060</div><div>  Prim.Transp. : UDP</div><div>  Allowed.Trsp : UDP</div><div>[...]</div><div><br></div><div>In contrast, after I do a &quot;sip reload&quot;, outbound calls start working again and the &quot;sip show&quot; output looks identical except for showing the correct address under &quot;Addr-&gt;IP&quot;:</div>
<div><br></div><div><div>* Name       : voipms</div><div>  Secret       : &lt;Set&gt;</div><div>[...]</div><div>  ToHost       : <a href="http://dallas.voip.ms">dallas.voip.ms</a></div><div>  Addr-&gt;IP     : 74.54.54.178 Port 5060</div>
<div>  Defaddr-&gt;IP  : 0.0.0.0 Port 5060</div><div>  Prim.Transp. : UDP</div><div>  Allowed.Trsp : UDP</div><div>[...]</div></div><div><br></div><div>Does anyone know how/where/why Asterisk could lose the IP address of the peer?</div>
<div><br></div><div>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:</div>
<div><br></div><div>NOTIFY sip:s@my.ip.add.ress:6010 SIP/2.0</div><div>Via: SIP/2.0/UDP 74.54.54.178:5060;branch=z9hG4bK008e70db;rport</div><div>From: &quot;Unknown&quot; &lt;<a href="mailto:sip%3AUnknown@74.54.54.178">sip:Unknown@74.54.54.178</a>&gt;;tag=as5c60da37</div>
<div>To: &lt;sip:s@my.ip.add.ress:6010&gt;</div><div>Contact: &lt;<a href="mailto:sip%3AUnknown@74.54.54.178">sip:Unknown@74.54.54.178</a>&gt;</div><div>Call-ID: <a href="mailto:266322e108872eab12fb307772a4af79@74.54.54.178">266322e108872eab12fb307772a4af79@74.54.54.178</a></div>
<div>CSeq: 102 NOTIFY</div><div>User-Agent: VoIPMS SERAST</div><div>Max-Forwards: 70</div><div>Event: message-summary</div><div>Content-Type: application/simple-message-summary</div><div>Content-Length: 92</div><div><br></div>
<div>Messages-Waiting: no</div><div>Message-Account: <a href="mailto:sip%3Aasterisk@74.54.54.178">sip:asterisk@74.54.54.178</a></div><div>Voice-Message: 0/0 (0/0)</div><div><br></div><div><div>SIP/2.0 489 Bad event</div><div>
Via: SIP/2.0/UDP 74.54.54.178:5060;branch=z9hG4bK008e70db;received=74.54.54.178;rport=5060</div><div>From: &quot;Unknown&quot; &lt;<a href="mailto:sip%3AUnknown@74.54.54.178">sip:Unknown@74.54.54.178</a>&gt;;tag=as5c60da37</div>
<div>To: &lt;sip:s@my.ip.add.ress:6010&gt;;tag=as4b162a1c</div><div>Call-ID: <a href="mailto:266322e108872eab12fb307772a4af79@74.54.54.178">266322e108872eab12fb307772a4af79@74.54.54.178</a></div><div>CSeq: 102 NOTIFY</div>
<div>Server: Asterisk PBX 1.6.2.13</div><div>Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO</div><div>Supported: replaces, timer</div><div>Content-Length: 0</div></div><div><br></div><div>Immediately after that exchange, I see the following curious set of messages:</div>
<div><br></div><div><div>[Oct 27 18:44:58] DEBUG[1676]: chan_sip.c:3608 __sip_xmit: Trying to put &#39;SIP/2.0 489&#39; onto UDP socket destined for <a href="http://74.54.54.178:5060">74.54.54.178:5060</a></div><div>[Oct 27 18:44:58] DEBUG[1676]: chan_sip.c:22105 handle_request_do: Invalid SIP message - rejected , no callid, len 541</div>
</div><div><br></div><div>Could those messages be related to my problem? I see this &quot;489 Bad Event&quot; issue may be related to <a href="https://issues.asterisk.org/view.php?id=17379">https://issues.asterisk.org/view.php?id=17379</a>, but it&#39;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.</div>
<div><br></div><div>Lastly, in case it matters, the general and peer-specific sections of my sip.conf are as follows:</div><div><br></div><div><div>[general]</div><div>dtmfmode = rfc2833</div><div>context=from-voipms</div>
<div>srvlookup=yes</div><div>register =&gt; myuserid:mypass@dallas.voip.ms:5060~600</div><div>session-timers=refuse</div><div>session-expires=3600</div><div>session-minse=600</div><div>session-refresher=uas</div><div>localnet=<a href="http://192.168.0.0/255.255.0.0">192.168.0.0/255.255.0.0</a></div>
<div>localnet=<a href="http://10.0.0.0/255.0.0.0">10.0.0.0/255.0.0.0</a></div><div>localnet=<a href="http://172.16.0.0/12">172.16.0.0/12</a></div><div>localnet=<a href="http://169.254.0.0/255.255.0.0">169.254.0.0/255.255.0.0</a></div>
<div>stunaddr=<a href="http://stun01.sipphone.com">stun01.sipphone.com</a></div><div>allow=ulaw</div><div>allow=gsm</div><div><br></div><div>[voipms]</div><div>canreinvite=yes</div><div>context=from-voipms</div><div>host=<a href="http://dallas.voip.ms">dallas.voip.ms</a></div>
<div>secret=mypass</div><div>type=friend</div><div>username=myuserid</div><div>disallow=all</div><div>allow=gsm</div><div>fromuser=myuserid</div><div>trustrpid=yes</div><div>sendrpid=yes</div><div>insecure=port,invite</div>
</div><div><br></div><div>I have complete logs and SIP debugging from the time that I discovered the latest incarnation of this problem, which I would be happy to provide...but since I don&#39;t dial out much, that logging presumably begins long past whatever point in time it was that the problem was triggered. My embedded device also has limited storage, so it would be difficult (but not impossible!) to run on full-debug logging for long periods of time.</div>
<div><br></div><div>Any advice or pointers would be appreciated! </div><div><br></div><div>Scott</div><div><br></div>