<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Word 15 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
font-size:11.0pt;
font-family:"Calibri",sans-serif;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:#0563C1;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri",sans-serif;
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri",sans-serif;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="EN-US" link="#0563C1" vlink="#954F72" style="word-wrap:break-word">
<div class="WordSection1">
<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).<o:p></o:p></p>
<p class="MsoNormal">When we roll the VMs back to 18.12.1, we don’t see the behavior repeat.
<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">We have a Kamailio VM front ending the asterisk.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">It sends OPTIONS messages periodically.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">After startup (and also after reloading configuration settings), we see periods where the response can’t be sent.<o:p></o:p></p>
<p class="MsoNormal">After a period of time, it suddenly starts working.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Here is a sample of it failing, followed by it working for the next OPTIONS message received.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[12/06 20:40:55.797] VERBOSE[186673] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:192.168.12.10:5060 ---><o:p></o:p></p>
<p class="MsoNormal">OPTIONS <a href="sip:box_b@192.168.12.120:5060">sip:box_b@192.168.12.120:5060</a> SIP/2.0<o:p></o:p></p>
<p class="MsoNormal">Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0<o:p></o:p></p>
<p class="MsoNormal">To: <a href="sip:box_b@192.168.12.120:5060">sip:box_b@192.168.12.120:5060</a><o:p></o:p></p>
<p class="MsoNormal">From: <a href="sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971">
sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971</a><o:p></o:p></p>
<p class="MsoNormal">CSeq: 10 OPTIONS<o:p></o:p></p>
<p class="MsoNormal">Call-ID: <a href="mailto:5ff0944d46b1692c-2858982@192.168.12.10">
5ff0944d46b1692c-2858982@192.168.12.10</a><o:p></o:p></p>
<p class="MsoNormal">Max-Forwards: 70<o:p></o:p></p>
<p class="MsoNormal">Content-Length: 0<o:p></o:p></p>
<p class="MsoNormal">User-Agent: Genesis Proxy<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal"><o:p> </o:p></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)<o:p></o:p></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)<o:p></o:p></p>
<p class="MsoNormal">[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'<o:p></o:p></p>
<p class="MsoNormal">[12/06 20:40:55.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.12.10:5060 matches identify 'identify158'<o:p></o:p></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<o:p></o:p></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'<o:p></o:p></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'<o:p></o:p></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<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[12/06 20:40:55.797] ERROR[194583] res_pjsip/pjsip_options.c: Unable to send response (-1)<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Four minutes later (and ever since then), it’s been fine responding to the OPTIONS.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[12/06 20:40:59.797] VERBOSE[186673] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:192.168.12.10:5060 ---><o:p></o:p></p>
<p class="MsoNormal">OPTIONS <a href="sip:box_b@192.168.12.120:5060">sip:box_b@192.168.12.120:5060</a> SIP/2.0<o:p></o:p></p>
<p class="MsoNormal">Via: SIP/2.0/UDP 192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0<o:p></o:p></p>
<p class="MsoNormal">To: <a href="sip:box_b@192.168.12.120:5060">sip:box_b@192.168.12.120:5060</a><o:p></o:p></p>
<p class="MsoNormal">From: <a href="sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971">
sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971</a><o:p></o:p></p>
<p class="MsoNormal">CSeq: 10 OPTIONS<o:p></o:p></p>
<p class="MsoNormal">Call-ID: <a href="mailto:5ff0944d46b1692c-2858982@192.168.12.10">
5ff0944d46b1692c-2858982@192.168.12.10</a><o:p></o:p></p>
<p class="MsoNormal">Max-Forwards: 70<o:p></o:p></p>
<p class="MsoNormal">Content-Length: 0<o:p></o:p></p>
<p class="MsoNormal">User-Agent: Genesis Proxy<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></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)<o:p></o:p></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)<o:p></o:p></p>
<p class="MsoNormal">[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'<o:p></o:p></p>
<p class="MsoNormal">[12/06 20:40:59.797] DEBUG[194583] res_pjsip_endpoint_identifier_ip.c: Source address 192.168.12.10:5060 matches identify 'identify158'<o:p></o:p></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<o:p></o:p></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'<o:p></o:p></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'<o:p></o:p></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<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[12/06 20:40:59.798] VERBOSE[194583] res_pjsip_logger.c: <--- Transmitting SIP response (896 bytes) to UDP:192.168.12.10:5060 ---><o:p></o:p></p>
<p class="MsoNormal">SIP/2.0 200 OK<o:p></o:p></p>
<p class="MsoNormal">Via: SIP/2.0/UDP 192.168.12.10;received=192.168.12.10;branch=z9hG4bK10f.4d4a0332000000000000000000000000.0<o:p></o:p></p>
<p class="MsoNormal">Call-ID: <a href="mailto:5ff0944d46b1692c-2858982@192.168.12.10">
5ff0944d46b1692c-2858982@192.168.12.10</a><o:p></o:p></p>
<p class="MsoNormal">From: <a href="sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971">
sip:kamailio@192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971</a><o:p></o:p></p>
<p class="MsoNormal">To: <a href="sip:box_b@192.168.12.120;tag=z9hG4bK10f.4d4a0332000000000000000000000000.0">
sip:box_b@192.168.12.120;tag=z9hG4bK10f.4d4a0332000000000000000000000000.0</a><o:p></o:p></p>
<p class="MsoNormal">CSeq: 10 OPTIONS<o:p></o:p></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<o:p></o:p></p>
<p class="MsoNormal">Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER<o:p></o:p></p>
<p class="MsoNormal">Supported: 100rel, timer, replaces, norefersub<o:p></o:p></p>
<p class="MsoNormal">Accept-Encoding: identity<o:p></o:p></p>
<p class="MsoNormal">Accept-Language: en<o:p></o:p></p>
<p class="MsoNormal">Server: Asterisk PBX 18.15.1<o:p></o:p></p>
<p class="MsoNormal">Content-Length: 0<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Portion of the pjsip.conf settings…<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[Kamailio]<o:p></o:p></p>
<p class="MsoNormal">type = aor<o:p></o:p></p>
<p class="MsoNormal">authenticate_qualify = yes<o:p></o:p></p>
<p class="MsoNormal">contact = <a href="sip:192.168.10.235">sip:192.168.10.235</a><o:p></o:p></p>
<p class="MsoNormal">;outbound_proxy=sip:192.168.12.10<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[identify158]<o:p></o:p></p>
<p class="MsoNormal">type = identify<o:p></o:p></p>
<p class="MsoNormal">endpoint = Kamailio<o:p></o:p></p>
<p class="MsoNormal">match = 192.168.12.10<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">[Kamailio]<o:p></o:p></p>
<p class="MsoNormal">type = endpoint<o:p></o:p></p>
<p class="MsoNormal">context = IS<o:p></o:p></p>
<p class="MsoNormal">transport = transport1<o:p></o:p></p>
<p class="MsoNormal">aors = Kamailio<o:p></o:p></p>
<p class="MsoNormal">accountcode = 29<o:p></o:p></p>
<p class="MsoNormal">dtmf_mode = inband<o:p></o:p></p>
<p class="MsoNormal">device_state_busy_at = 48<o:p></o:p></p>
<p class="MsoNormal">force_rport = no<o:p></o:p></p>
<p class="MsoNormal">moh_passthrough = no<o:p></o:p></p>
<p class="MsoNormal">identify_by = username,ip,header<o:p></o:p></p>
<p class="MsoNormal">disallow = all<o:p></o:p></p>
<p class="MsoNormal">allow = ulaw<o:p></o:p></p>
<p class="MsoNormal">asymmetric_rtp_codec = yes<o:p></o:p></p>
<p class="MsoNormal">acl = acl6<o:p></o:p></p>
<p class="MsoNormal">outbound_proxy=sip:192.168.12.10<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Was there some configuration change introduced after 18.12.1 that I missed?<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Any thoughts?<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Dan<o:p></o:p></p>
</div>
</body>
</html>