Intermittently, people making calls to our company are not hearing any ringing - only silence. Followed by ‘we have not received a valid response’. This happens at odd times - and when it happens, it affects all of our inbound routes.
It appears that the caller is going straight to an IVR (with no announcement or voice).
I cannot pinpoint what happens, since I don’t know when it actually breaks. I end up finding out when an 30 minutes go by without a call and then get suspicious.
This happens on ALL of our routes, even routes that go directly to an extension or ring group without ever going to an IVR.
The only thing that resolves it is doing a restart of asterisk. I cannot find any errors in /var/log/asterisk/full.
I am scratching my head, any help would be appreciated.
This sounds like a “one-way audio” problem. It could either be a transcoding error (the call doesn’t negotiate the right codec) or it could be a firewall/router problem (RTP/NAT settings, VOIP “helpers” in the router, etc.)
An excerpt from /var/log/asterisk/full around the time of the call would certainly help.
Yes, but it depends on the way that the NAT is failing. The symptom I’m focusing on is the “no ringing” part.
The thing I’m thinking is that the NTP/Codec is messed up on the inbound leg, then the phone “makes a noise” or does an update of some kind that allows the router/codec to adjust to the call, at which point the sound proceeds as normal.
There have been reports of this in the past. Other things to check are things like the EarlyRTP stuff. Logs may help, but you may instead need to do a SIP DEBUG to get to the bottom of this.
This is the codec translation from the reboot (if I’m reading this right), so that’s good to know, but not a good example of the call failing.
It’s going to look like a phone call coming in, so it’s going to have your DID stuff and the route to the IVR in it. That should show us that you sent the IVR recording (or that there was an error). Since it’s an intermittent error, the possibility that it’s a Codec problem is still real. Another possibility: does the ‘second pass’ on the IVR recording work for these callers, or is it dead air.
Ok - I understand what type of log entries you are looking for. Unfortunately, after reviewing the logs I don’t see any SIP info. I am not sure if I had SIP debugging turned off.
I will have to reply with logs the next time the problem occurs I suppose. Thanks for the help thus far.
The next time the problem occurs, before restarting anything, make a test call from your mobile to a number that should ring directly to an extension. Assuming that your system (when working properly) doesn’t immediately answer the call (e.g. to play music or an ad), Asterisk should respond to the incoming INVITE with a 180 Ringing, which should cause the caller’s provider or device to play ringback tone. This does not depend on any audio sent from Asterisk; if ringback tone is not heard, there is an issue with Asterisk’s handling of the signaling, your network or your provider. It will be also useful to see whether the call indicated the correct DID and whether the called extension actually rang.
Ok guys. I had the problem happen again. One call, it didn’t ring and said ‘We have not received a valid response’ (the IVR message).
I called back again, and a third time, and I get an voice message: “An Error Has Occured”.
Again, this is an intermittent problem. Below, I’ve linked some SIP debug output. I am not sure what to look for.
Note: My cell phone number (the one I was calling inbound with, ends in 0098, and I do not see it in the logs anywhere. In the past, I have assumed this was an issue with my voip provider because I can’t see where the inbound call even hits the server.
If you can’t see the call on the /var/log/asterisk/full log (by incoming phone CID) then this is a very reasonable assumption, but the problem may be a trunk configuration error on your end.
Check with your provider and see if there is more than one server that could be sending calls to your PBX.
Another thing. I noticed, that I called and I got ‘An error has occured’.
I then see : [2018-02-13 09:25:06] NOTICE[2833]: chan_sip.c:15722 sip_reregister: – Re-registration for 7196341100@AAHTrunk
Full Output:
[2018-02-13 09:21:14] NOTICE[2833]: chan_sip.c:29559 check_rtp_timeout: Disconnecting call ‘SIP/AAHTrunk-00000018’ for lack of RTP activity in 31 seconds
[2018-02-13 09:21:34] WARNING[2833][C-0000001d]: chan_sip.c:24008 handle_response_invite: Received response: “Forbidden” from ‘“Afrd Hear” sip:[email protected]:5160;tag=as046818a6’
[2018-02-13 09:21:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:21:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:21:44] WARNING[2833][C-0000001e]: chan_sip.c:24008 handle_response_invite: Received response: “Forbidden” from ‘“Afrd Hear” sip:[email protected]:5160;tag=as66ea49f6’
[2018-02-13 09:21:58] WARNING[2833][C-00000021]: chan_sip.c:24008 handle_response_invite: Received response: “Forbidden” from ‘“Afrd Hear” sip:[email protected]:5160;tag=as1a396544’
[2018-02-13 09:22:12] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Kaitlin” sip:[email protected]:5160;tag=BCC7D58-4A4B7AC5’
[2018-02-13 09:22:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:22:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:23:20] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Kaitlin” sip:[email protected]:5160;tag=7D672319-DC7EF06’
[2018-02-13 09:23:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:23:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:24:26] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Kaitlin” sip:[email protected]:5160;tag=6D06CD4B-122A2E38’
[2018-02-13 09:24:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:24:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:25:06] NOTICE[2833]: chan_sip.c:15722 sip_reregister: – Re-registration for 7196341100@AAHTrunk
[2018-02-13 09:25:06] NOTICE[2833]: chan_sip.c:24543 handle_response_register: Outbound Registration: Expiry for AAHTrunk is 300 sec (Scheduling reregistration in 285 s)
ahtel03*CLI>
And suddenly the call goes through. I’m thinking this is a Trunk issue.
Again, the inbound call stopped working probably 2 minutes afterwards. ‘An Error has occured’
I wait the remaining 300 seconds, and immediately after Re-Regestration the call comes through fine.
Output:
Connected to Asterisk 13.17.2 currently running on ahtel03 (pid = 2227)
[2018-02-13 09:27:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:27:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:28:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:28:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:29:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:29:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:29:51] NOTICE[2833]: chan_sip.c:15722 sip_reregister: – Re-registration for 7196341100@AAHTrunk
[2018-02-13 09:29:51] NOTICE[2833]: chan_sip.c:24543 handle_response_register: Outbound Registration: Expiry for AAHTrunk is 300 sec (Scheduling reregistration in 285 s)
[2018-02-13 09:30:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:30:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:31:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:31:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:32:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:32:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:33:16] WARNING[2833][C-00000024]: chan_sip.c:25002 handle_response: Remote host can’t match request CANCEL to call ‘[email protected]’. Giving up.
[2018-02-13 09:33:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:33:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
[2018-02-13 09:34:36] NOTICE[2833]: chan_sip.c:15722 sip_reregister: – Re-registration for 7196341100@AAHTrunk
[2018-02-13 09:34:36] NOTICE[2833]: chan_sip.c:24543 handle_response_register: Outbound Registration: Expiry for AAHTrunk is 300 sec (Scheduling reregistration in 285 s)
[2018-02-13 09:34:41] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“ALICIA” sip:[email protected]:5160;tag=272FD025-7CA38D1C’
[2018-02-13 09:34:42] NOTICE[2833]: chan_sip.c:17278 check_auth: Correct auth, but based on stale nonce received from ‘“Dean” sip:[email protected]:5160;tag=D825F12-BE3630CF’
I Googled “pjsip Correct auth, but based on stale nonce received” and got several good threads that talk about both the cause and solutions. Have you looked at that yet?
Right - they are separate problems. The phone problem is solved by a combination of upgraded firmware in the phone, tightening up the re-registration timer on the extension settings, and fixes added to Asterisk in more recent versions of the system.
On the inbound problem - I had a similar problem with my carrier and I was rejecting the calls from the ITSP because I didn’t have a trunk for one of the new (and at the time, undocumented) servers. It was very intermittent and would only happen during periods of their peak operation. Double check with them and make sure you have an inbound trunk definition for every source they use. They can also help you troubleshoot the problem if you have the originating and destination phone numbers and the time of the failed call. I’m going to guess the call got dropped at their location, either because you rejected it or they were over committed with traffic.