<div dir="ltr"><div dir="ltr">On Wed, Dec 7, 2022 at 11:26 AM Dan Cropp <<a href="mailto:dan@amtelco.com">dan@amtelco.com</a>> wrote:<br></div><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div class="msg7966314364304626254">
<div lang="EN-US" style="overflow-wrap: break-word;">
<div class="m_7966314364304626254WordSection1">
<p class="MsoNormal">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).<u></u><u></u></p>
<p class="MsoNormal">When we roll the VMs back to 18.12.1, we don’t see the behavior repeat.
<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">We have a Kamailio VM front ending the asterisk.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">It sends OPTIONS messages periodically.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">After startup (and also after reloading configuration settings), we see periods where the response can’t be sent.<u></u><u></u></p>
<p class="MsoNormal">After a period of time, it suddenly starts working.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">Here is a sample of it failing, followed by it working for the next OPTIONS message received.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] VERBOSE[186673] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:<a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> ---><u></u><u></u></p>
<p class="MsoNormal">OPTIONS <a>sip:box_b@192.168.12.120:5060</a> SIP/2.0<u></u><u></u></p>
<p class="MsoNormal">Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0<u></u><u></u></p>
<p class="MsoNormal">To: <a>sip:box_b@192.168.12.120:5060</a><u></u><u></u></p>
<p class="MsoNormal">From: <a>
sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971</a><u></u><u></u></p>
<p class="MsoNormal">CSeq: 10 OPTIONS<u></u><u></u></p>
<p class="MsoNormal">Call-ID: <a href="mailto:5ff0944d46b1692c-2858982@192.168.12.10" target="_blank">
5ff0944d46b1692c-2858982@192.168.12.10</a><u></u><u></u></p>
<p class="MsoNormal">Max-Forwards: 70<u></u><u></u></p>
<p class="MsoNormal">Content-Length: 0<u></u><u></u></p>
<p class="MsoNormal">User-Agent: Genesis Proxy<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[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)<u></u><u></u></p>
<p class="MsoNormal">[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)<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address <a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> does not match identify 'identify140'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address <a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> matches identify 'identify158'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Identify 'identify158' SIP message matched to endpoint Kamailio<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.12.10'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.12.10' is 'UDP transport'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip/pjsip_resolver.c: Target '192.168.12.10' is an IP address, skipping resolution<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[12/06 20:40:55.797] ERROR[194583] res_pjsip/pjsip_options.c: Unable to send response (-1)<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">Four minutes later (and ever since then), it’s been fine responding to the OPTIONS.<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[12/06 20:40:59.797] VERBOSE[186673] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:<a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> ---><u></u><u></u></p>
<p class="MsoNormal">OPTIONS <a>sip:box_b@192.168.12.120:5060</a> SIP/2.0<u></u><u></u></p>
<p class="MsoNormal">Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0<u></u><u></u></p>
<p class="MsoNormal">To: <a>sip:box_b@192.168.12.120:5060</a><u></u><u></u></p>
<p class="MsoNormal">From: <a>
sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971</a><u></u><u></u></p>
<p class="MsoNormal">CSeq: 10 OPTIONS<u></u><u></u></p>
<p class="MsoNormal">Call-ID: <a href="mailto:5ff0944d46b1692c-2858982@192.168.12.10" target="_blank">
5ff0944d46b1692c-2858982@192.168.12.10</a><u></u><u></u></p>
<p class="MsoNormal">Max-Forwards: 70<u></u><u></u></p>
<p class="MsoNormal">Content-Length: 0<u></u><u></u></p>
<p class="MsoNormal">User-Agent: Genesis Proxy<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[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)<u></u><u></u></p>
<p class="MsoNormal">[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)<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address <a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> does not match identify 'identify140'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address <a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> matches identify 'identify158'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Identify 'identify158' SIP message matched to endpoint Kamailio<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:59.798] DEBUG[194583] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.12.10'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:59.798] DEBUG[194583] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.12.10' is 'UDP transport'<u></u><u></u></p>
<p class="MsoNormal">[12/06 20:40:59.798] DEBUG[194583] res_pjsip/pjsip_resolver.c: Target '192.168.12.10' is an IP address, skipping resolution<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[12/06 20:40:59.798] VERBOSE[194583] res_pjsip_logger.c: <--- Transmitting SIP response (896 bytes) to UDP:<a href="http://192.168.12.10:5060" target="_blank">192.168.12.10:5060</a> ---><u></u><u></u></p>
<p class="MsoNormal">SIP/2.0 200 OK<u></u><u></u></p>
<p class="MsoNormal">Via: SIP/2.0/UDP 192.168.12.10;received=192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0<u></u><u></u></p>
<p class="MsoNormal">Call-ID: <a href="mailto:5ff0944d46b1692c-2858982@192.168.12.10" target="_blank">
5ff0944d46b1692c-2858982@192.168.12.10</a><u></u><u></u></p>
<p class="MsoNormal">From: <a>
sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971</a><u></u><u></u></p>
<p class="MsoNormal">To: <a>
sip:box_b@192.168.12.120;tag=z9hG4bK10f.4d4a0332000000000000000000000000.0</a><u></u><u></u></p>
<p class="MsoNormal">CSeq: 10 OPTIONS<u></u><u></u></p>
<p class="MsoNormal">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<u></u><u></u></p>
<p class="MsoNormal">Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER<u></u><u></u></p>
<p class="MsoNormal">Supported: 100rel, timer, replaces, norefersub<u></u><u></u></p>
<p class="MsoNormal">Accept-Encoding: identity<u></u><u></u></p>
<p class="MsoNormal">Accept-Language: en<u></u><u></u></p>
<p class="MsoNormal">Server: Asterisk PBX 18.15.1<u></u><u></u></p>
<p class="MsoNormal">Content-Length: 0<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">Portion of the pjsip.conf settings…<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[Kamailio]<u></u><u></u></p>
<p class="MsoNormal">type = aor<u></u><u></u></p>
<p class="MsoNormal">authenticate_qualify = yes<u></u><u></u></p>
<p class="MsoNormal">contact = <a>sip:192.168.10.235</a><u></u><u></u></p>
<p class="MsoNormal">;outbound_proxy=sip:192.168.12.10<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[identify158]<u></u><u></u></p>
<p class="MsoNormal">type = identify<u></u><u></u></p>
<p class="MsoNormal">endpoint = Kamailio<u></u><u></u></p>
<p class="MsoNormal">match = 192.168.12.10<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">[Kamailio]<u></u><u></u></p>
<p class="MsoNormal">type = endpoint<u></u><u></u></p>
<p class="MsoNormal">context = IS<u></u><u></u></p>
<p class="MsoNormal">transport = transport1<u></u><u></u></p>
<p class="MsoNormal">aors = Kamailio<u></u><u></u></p>
<p class="MsoNormal">accountcode = 29<u></u><u></u></p>
<p class="MsoNormal">dtmf_mode = inband<u></u><u></u></p>
<p class="MsoNormal">device_state_busy_at = 48<u></u><u></u></p>
<p class="MsoNormal">force_rport = no<u></u><u></u></p>
<p class="MsoNormal">moh_passthrough = no<u></u><u></u></p>
<p class="MsoNormal">identify_by = username,ip,header<u></u><u></u></p>
<p class="MsoNormal">disallow = all<u></u><u></u></p>
<p class="MsoNormal">allow = ulaw<u></u><u></u></p>
<p class="MsoNormal">asymmetric_rtp_codec = yes<u></u><u></u></p>
<p class="MsoNormal">acl = acl6<u></u><u></u></p>
<p class="MsoNormal">outbound_proxy=sip:192.168.12.10<u></u><u></u></p>
<p class="MsoNormal"><u></u> <u></u></p>
<p class="MsoNormal">Was there some configuration change introduced after 18.12.1 that I missed?</p></div></div></div></blockquote><div><br></div><div>Any such things would be in the upgrade notes, but no.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div class="msg7966314364304626254"><div lang="EN-US" style="overflow-wrap: break-word;"><div class="m_7966314364304626254WordSection1"><p class="MsoNormal"> </p><p class="MsoNormal"><u></u></p>
<p class="MsoNormal">Any thoughts?</p></div></div></div></blockquote><div><br></div><div> I haven't seen this before, and haven't seen any other reports of it so far. The OPTIONS code itself hasn't changed between the two. There was a fix for a crash in send_stateful_response so adding log messages to the error cases is likely needed to see in particular which one is failing.</div></div><div><br></div>-- <br><div dir="ltr" class="gmail_signature"><div dir="ltr"><div><div dir="ltr"><div><div dir="ltr"><div dir="ltr"><div dir="ltr"><div dir="ltr"><div style="font-family:tahoma,sans-serif"><font color="#073763">Joshua C. Colp</font></div><div style="font-family:tahoma,sans-serif"><font color="#073763">Asterisk Project Lead</font></div><div style="font-family:tahoma,sans-serif"><font color="#073763">Sangoma Technologies</font></div><div style="font-family:tahoma,sans-serif"><font color="#073763">Check us out at <a href="http://www.sangoma.com" target="_blank">www.sangoma.com</a> and <a href="http://www.asterisk.org" target="_blank">www.asterisk.org</a></font><br></div></div></div></div></div></div></div></div></div></div></div>