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:box_b@192.168.12.120:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0
To: sip:box_b@192.168.12.120:5060
From: sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971
CSeq: 10 OPTIONS
Call-ID: 5ff0944d46b1692c-2858982@192.168.12.10
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:box_b@192.168.12.120:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0
To: sip:box_b@192.168.12.120:5060
From: sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971
CSeq: 10 OPTIONS
Call-ID: 5ff0944d46b1692c-2858982@192.168.12.10
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: 5ff0944d46b1692c-2858982@192.168.12.10
From: sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971
To: sip:box_b@192.168.12.120;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