Joshua C. Colp
2022-Dec-07 15:34 UTC
[asterisk-users] 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)
On Wed, Dec 7, 2022 at 11:26 AM Dan Cropp <dan at amtelco.com> wrote:> 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 at 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 at 192.168.12.120:5060 > > From: > sip:kamailio at 192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971 > > CSeq: 10 OPTIONS > > Call-ID: 5ff0944d46b1692c-2858982 at 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 at 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 at 192.168.12.120:5060 > > From: > sip:kamailio at 192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971 > > CSeq: 10 OPTIONS > > Call-ID: 5ff0944d46b1692c-2858982 at 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 at 192.168.12.10 > > From: > sip:kamailio at 192.168.12.10;tag=f1bcd6806a18022e516c4139c95990f1-92130971 > > To: > sip:box_b at 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 such things would be in the upgrade notes, but no.> > > Any thoughts? >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. -- Joshua C. Colp Asterisk Project Lead Sangoma Technologies Check us out at www.sangoma.com and www.asterisk.org -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20221207/5cab23f5/attachment-0001.html>
Joshua C. Colp
2022-Dec-07 15:37 UTC
[asterisk-users] 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)
On Wed, Dec 7, 2022 at 11:34 AM Joshua C. Colp <jcolp at sangoma.com> wrote:> On Wed, Dec 7, 2022 at 11:26 AM Dan Cropp <dan at amtelco.com> wrote: > >> 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. >> >> >> > 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. > >Ha, those changes haven't even landed yet. It's pretty much a thin wrapper over PJSIP stuff in 18.15.1. The PJSIP versions are also fairly close too. -- Joshua C. Colp Asterisk Project Lead Sangoma Technologies Check us out at www.sangoma.com and www.asterisk.org -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20221207/f060719a/attachment.html>