[Home]

Summary:ASTERISK-30069: res_pjsip: Asterisk keeps qualifying after contact expiry
Reporter:Yury Kirsanov (lt_flash)Labels:
Date Opened:2022-05-17 12:59:15Date Closed:2022-06-01 03:54:11
Priority:MinorRegression?
Status:Closed/CompleteComponents:Resources/res_pjsip
Versions:18.7.0 18.12.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Ubuntu 20.04.4LTSAttachments:( 0) asterisk.log
( 1) sip.pcap
Description:We have Asterisk server that acts as a registrar and a SIP device that connects to Asterisk via a SIP proxy that adds Path header to stay in between Asterisk and SIP device.

After successful registration if SIP device has disconnected without sending Unregister SIP packet with Expiry=0 Asterisk would keep qualifying that device forever.

'pjsips show contacts' show that contact is removed as well as 'database show'. Also logs show that contact has been removed due to expiry but still SIP proxy receives SIP OPTIONS packets from Asterisk.

Here's output of 'pjsip set logger host <sip_proxy>':

[May 18 03:57:10] <--- Transmitting SIP request (519 bytes) to UDP:X.X.X.X:5060 --->
[May 18 03:57:10] OPTIONS sip:XXXXXX@X.X.X.X:62024 SIP/2.0
[May 18 03:57:10] Via: SIP/2.0/UDP X.X.X.X:5060;rport;branch=z9hG4bKPj73d001de-73b5-445c-895e-2d492e876c25
[May 18 03:57:10] From: <sip:XXXXXX@X.X.X.X>;tag=43bd3567-53ed-46b5-8ddf-b2c5bddb4042
[May 18 03:57:10] To: <sip:XXXXXX@X.X.X.X>
[May 18 03:57:10] Contact: <sip:XXXXXX@X.X.X.X:5060>
[May 18 03:57:10] Call-ID: b1a62aed-8b66-40b4-8d1d-6b1f6718318c
[May 18 03:57:10] CSeq: 27361 OPTIONS
[May 18 03:57:10] Supported: path
[May 18 03:57:10] Route: <sip:X.X.X.X;lr;received=sip:X.X.X.X:62024%3btransport%3dwss>
[May 18 03:57:10] Max-Forwards: 70
[May 18 03:57:10] User-Agent: Agent
[May 18 03:57:10] Content-Length:  0

The only way to stop this is to restart Asterisk.
Comments:By: Asterisk Team (asteriskteam) 2022-05-17 12:59:17.211-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.

Please note that by submitting data, code, or documentation to Sangoma through JIRA, you accept the Terms of Use present at [https://www.asterisk.org/terms-of-use/|https://www.asterisk.org/terms-of-use/].
By: Joshua C. Colp (jcolp) 2022-05-17 13:04:59.153-0500

We require additional debug to continue with triage of your issue. Please follow the instructions on the wiki [1] for how to collect debugging information from Asterisk. For expediency, where possible, attach the debug with a '.txt' file extension so that the debug will be usable for further analysis.

Thanks!

[1] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information


By: Yury Kirsanov (lt_flash) 2022-05-20 02:42:55.999-0500

Thanks, I'll collect that information and get back to this case soon, please don't close it yet.
By: Yury Kirsanov (lt_flash) 2022-05-30 01:07:11.313-0500

Debug log of Asterisk
By: Yury Kirsanov (lt_flash) 2022-05-30 01:07:42.445-0500

PCAP capture showing that Asterisk keeps sending OPTIONS even though the contact has been removed from database.
By: Yury Kirsanov (lt_flash) 2022-05-30 01:07:44.385-0500

Hi,
My apologies, after digging deeper into this issue it turned out to be not really the way I described. Everything works fine when contact is managed by Asterisk. But if we use 'database deltree registrar/contact/XXXX' after the SIP device has crashed - Asterisk keeps sending Options.

But if the contact is getting deleted manually - by issuing asterisk console command "database del registrar/contact xxxxxxxxxxxxxxxxxxxxxxxx" - then Asterisk keeps sending OPTIONS forever.
An example of the second instance is as follows (I have timestamped some events so it would be easier to track them in the log file):

At 18:05:05 the SIP-device 100001 is registered with expire time 600;
At 18:09:00 the SIP-device 100001 was turned off - the power cable pulled out - so the SIP-device didn't send unregister;
Asterisk is trying to qualify the SIP-device 100001 - it receives "408 Request Timeout" response. At 18:09:09 SIP-device 100001 is getting marked as "Unavail"

At 18:11:23 the command is issued in asterisk console - "database del registrar/contact 100001;@0130c7279da65e995ae218246fddc1e4". The contact for 100001 is deleted as well as a record in the database

I'm attaching debug log and PCAP SIP capture showing this behaviour. Thanks!

By: Joshua C. Colp (jcolp) 2022-05-30 04:36:59.199-0500

External manipulation of the backend storage for contacts like that isn't supported by OPTIONS, it doesn't poll or know that anything happened. There are CLI commands "pjsip reload qualify endpoint" and "pjsip reload qualify aor" you could try to use to see if that will synchronize the state as you expect.
By: Yury Kirsanov (lt_flash) 2022-05-30 19:13:12.038-0500

Thanks, Joshua, I'll give that a go and see if it stops qualifying. I was using 'database deltree' to remove contacts because we had max_contacts=2 and after each reload of SIP proxy in front of  Asterisk it was creating a new contact on Asterisk and after 2 restarts Asterisk was starting to respond with 403 Forbidden. I've figured out the only way to stop that was to remove contacts from AstDB because even 'core restart now' won't help in this case as Asterisk would load all the contacts from DB upon restart. Is there any way to flush all the currently registered contacts from Asterisk without such complex manipulations? We need this because we're setting up a mid registrar SIP proxy that would modify Expiry time to large values like 3600 or even 86400 seconds so Asterisk's load would be reduced in terms of servicing REGISTER attempts. Thanks!
By: Joshua C. Colp (jcolp) 2022-05-31 03:41:06.822-0500

There is no functionality to manipulate contacts like that as far as I'm aware.
By: Yury Kirsanov (lt_flash) 2022-06-01 02:22:45.262-0500

Thanks, this ticket can be closed then!