Asterisk 18.12.1 to 18.15.0 upgrade seems to have introduced a behavior where PJSIP is unable to send a response to OPTIONS (seems to resolve after anywhere a period of time)

Dan Cropp <[email protected]> Wed, 7 Dec 2022 15:25:56 +0000
Newsgroups	gmane.comp.telephony.pbx.asterisk.user
Message-ID	<DM6PR13MB3116EAD57847C8BE649989FBA31A9@DM6PR13MB3116.namprd13.prod.outlook.com>
On two VMs, we encounter a strange behavior when we upgrade from 18.12.1 to 18.15.0 (also tried 18.15.1 last night).
When we roll the VMs back to 18.12.1, we don't see the behavior repeat.

We have a Kamailio VM front ending the asterisk.

It sends OPTIONS messages periodically.

After startup (and also after reloading configuration settings), we see periods where the response can't be sent.
After a period of time, it suddenly starts working.

Here is a sample of it failing, followed by it working for the next OPTIONS message received.


[12/06 20:40:55.797] VERBOSE[186673] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:192.168.12.10:5060 --->
OPTIONS sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0
To: sip:[email protected]:5060
From: sip:[email protected];tag=f1bcd6806a18022e516c4139c95990f1-92130971
CSeq: 10 OPTIONS
Call-ID: [email protected]<mailto:[email protected]>
Max-Forwards: 70
Content-Length: 0
User-Agent: Genesis Proxy


[12/06 20:40:55.797] DEBUG[186673] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg OPTIONS/cseq=10 (rdata0x7f88380385c8)
[12/06 20:40:55.797] DEBUG[186673] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-000002f9 to use for Request msg OPTIONS/cseq=10 (rdata0x7f88380385c8)
[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.12.10:5060 does not match identify 'identify140'
[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.12.10:5060 matches identify 'identify158'
[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Identify 'identify158' SIP message matched to endpoint Kamailio
[12/06 20:40:55.797] DEBUG[194583] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.12.10'
[12/06 20:40:55.797] DEBUG[194583] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.12.10' is 'UDP transport'
[12/06 20:40:55.797] DEBUG[194583] res_pjsip/pjsip_resolver.c: Target '192.168.12.10' is an IP address, skipping resolution

[12/06 20:40:55.797] ERROR[194583] res_pjsip/pjsip_options.c: Unable to send response (-1)


Four minutes later (and ever since then), it's been fine responding to the OPTIONS.

[12/06 20:40:59.797] VERBOSE[186673] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:192.168.12.10:5060 --->
OPTIONS sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0
To: sip:[email protected]:5060
From: sip:[email protected];tag=f1bcd6806a18022e516c4139c95990f1-92130971
CSeq: 10 OPTIONS
Call-ID: [email protected]<mailto:[email protected]>
Max-Forwards: 70
Content-Length: 0
User-Agent: Genesis Proxy

[12/06 20:40:59.797] DEBUG[186673] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg OPTIONS/cseq=10 (rdata0x7f8838027c18)
[12/06 20:40:59.797] DEBUG[186673] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-000002f9 to use for Request msg OPTIONS/cseq=10 (rdata0x7f8838027c18)
[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.12.10:5060 does not match identify 'identify140'
[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.12.10:5060 matches identify 'identify158'
[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Identify 'identify158' SIP message matched to endpoint Kamailio
[12/06 20:40:59.798] DEBUG[194583] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.12.10'
[12/06 20:40:59.798] DEBUG[194583] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.12.10' is 'UDP transport'
[12/06 20:40:59.798] DEBUG[194583] res_pjsip/pjsip_resolver.c: Target '192.168.12.10' is an IP address, skipping resolution

[12/06 20:40:59.798] VERBOSE[194583] res_pjsip_logger.c: <--- Transmitting SIP response (896 bytes) to UDP:192.168.12.10:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.12.10;received=192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0
Call-ID: [email protected]<mailto:[email protected]>
From: sip:[email protected];tag=f1bcd6806a18022e516c4139c95990f1-92130971
To: sip:[email protected];tag=z9hG4bK10f.4d4a0332000000000000000000000000.0
CSeq: 10 OPTIONS
Accept: application/sdp, application/dialog-info+xml, application/simple-message-summary, application/xpidf+xml, application/cpim-pidf+xml, application/pidf+xml, application/pidf+xml, application/dialog-info+xml, application/simple-message-summary, message/sipfrag;version=2.0
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub
Accept-Encoding: identity
Accept-Language: en
Server: Asterisk PBX 18.15.1
Content-Length:  0

Portion of the pjsip.conf settings...

[Kamailio]
type = aor
authenticate_qualify = yes
contact = sip:192.168.10.235
;outbound_proxy=sip:192.168.12.10

[identify158]
type = identify
endpoint = Kamailio
match = 192.168.12.10

[Kamailio]
type = endpoint
context = IS
transport = transport1
aors = Kamailio
accountcode = 29
dtmf_mode = inband
device_state_busy_at = 48
force_rport = no
moh_passthrough = no
identify_by = username,ip,header
disallow = all
allow = ulaw
asymmetric_rtp_codec = yes
acl = acl6
outbound_proxy=sip:192.168.12.10

Was there some configuration change introduced after 18.12.1 that I missed?

Any thoughts?

Dan

-- 
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --

Check out the new Asterisk community forum at: https://community.asterisk.org/

New to Asterisk? Start here:
      https://wiki.asterisk.org/wiki/display/AST/Getting+Started

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