[OpenSIPS-Users] "bad uri" response header collisions bug in OpenSIPS 2.4.3

Thu Dec 6 16:51:35 EST 2018

Hey Răzvan;

My apologies for the delay - that disaster last Monday when we were
talking ended up taking up a large portion of my previous and current
week, annoyingly.

I have yet to be able to reliably replicate this issue - when I saw it
(on just shy of 10% of calls) it was on a production service that I
had upgraded to 2.4.3 that morning. Because it was adversely affecting
production calls I had no choice but to (after getting a quick SIP
trap) restart the service on 2.4.2. This issue presented itself _the
instant_ 2.4.3 was brought up, and disappeared _the instant_ I
reverted to 2.4.2 - so there is no question that it is specific to
2.4.3. Unfortunately I can't tell you what or where!

I spent some time yesterday and the day before running calls through
my load testing mechanism. I was able to catch two (of our ~100,000
calls) but OpenSIPS debug was off at the time (d'oh). With debug on I
was unable to catch a single one. Whatever this is, it appears to only
show up when it has the chance to break my customer's traffic :) As
soon as I find time, I'll try and bring some other, less active, boxes
up to 2.4.3 and work outwards until I find something that appears to
make it happen and get you some debug dumps.

I mostly just wanted to let you know that there's definitely something
in 2.4.3 going on, and it's important to us, but I haven't had the
time to re-test sufficiently and I appreciate that there's probably
not a heap you can do without it.

To be continued;

 - JP

On Thu, Nov 29, 2018 at 2:41 AM Răzvan Crainea <razvan at opensips.org> wrote:
>
> Hi, Jock!
>
> The errors you dumped below are found in the proxy's logs (192.168.93.214)?
> I don't actually understand how OpenSIPS triggers the ACK parsing error
> if he's the one generating it. Is OpenSIPS somehow looping the ACK to
> itself to re-parse it? Are you also tracking the internal interface?
>
> Best regards,
> Răzvan
>
> On 11/28/18 10:59 PM, Jock McKechnie wrote:
> > Afternoon folks;
> >
> > I recently upgraded one of our production boxes to 2.4.3-1.el7 out of
> > the OpenSIPS yum repo and within a few minutes I started seeing errors
> > like this in the OpenSIPS logging:
> > ERROR:core:parse_uri: bad uri, state 0 parsed: < 183> (4) / < 183
> > Session Progress#015#012Via: SIP/2.0/UDP 20> (42)
> > ERROR:core:parse_sip_msg_uri: bad uri < 183 Session
> > Progress#015#012Via: SIP/2.0/UDP 20>
> > ERROR:perl:perl_exec2: failed to parse Request-URI
> > ERROR:core:parse_uri: bad uri, state 0 parsed: < 183> (4) / < 183
> > Session Progress#015#012Via: SIP/2.0/UDP 20> (42)
> > ERROR:core:parse_sip_msg_uri: bad uri < 183 Session
> > Progress#015#012Via: SIP/2.0/UDP 20>
> > ERROR:perl:perl_exec2: failed to parse Request-URI
> > ERROR:tm:_reply_light: failed to generate 400 reply when a final 400
> > was sent out
> > ERROR:signaling:sig_send_reply_mod: failed to send reply with tm module
> > ERROR:perl:perl_exec2: failed to send reply
> > ERROR:tm:_reply_light: failed to generate 500 reply when a final 400
> > was sent out
> >
> > I trapped SIP for a while and OpenSIPS appears to be periodically
> > responding to messages with impressively malformed response
> > type/headers:
> > ACK  183 Session Progress
> > Via: SIP/2.0/UDP 20 SIP/2.0
> >
> > This belongs to the end of the call flow below (from 192.168.80.13
> > through our 2.4.3 proxy 192.168.93.214, to the destination server
> > 192.168.80.56). You'll see the .56 returns a 403 Forbidden which the
> > OpenSIPS is supposed to be ACKing, but instead it does something Very
> > Odd with the header - and then proceeds to throw the logged errors
> > above and returns a 400 to the requesting server.
> >
> > U 2018/11/28 10:18:22.758859 192.168.80.56:5060 -> 192.168.93.214:5060
> > SIP/2.0 403 Forbidden
> > Via: SIP/2.0/UDP
> > 192.168.93.214:5060;received=192.168.93.214;branch=z9hG4bKcb74.9a10e3a3.0
> > Via: SIP/2.0/UDP
> > 192.168.80.13:5060;rport=5060;received=192.168.80.13;branch=z9hG4bKPjdb6efcd9-373b-4122-8bde-9d92a608d6ee
> > Record-Route: <sip:192.168.93.214;lr;ftag=c0d1ec70-fbaa-429c-acc9-17dec131459e;did=453.a5b161a2>
> > Call-ID: e33b7043-ef96-4102-9f6a-bcb9c97ac4da
> > From: <sip:+16465551212 at 192.168.80.13>;tag=c0d1ec70-fbaa-429c-acc9-17dec131459e
> > To: <sip:XFER_3235551212 at 192.168.80.56>;tag=f9e1dd31-b586-4f47-9fb8-3d541b658a67
> > CSeq: 5413 INVITE
> > Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE,
> > NOTIFY, REFER, MESSAGE, OPTIONS
> > Content-Length:  0
> >
> > U 2018/11/28 10:18:22.759216 192.168.93.214:5060 -> 192.168.80.56:5060
> > ACK  183 Session Progress
> > Via: SIP/2.0/UDP 20 SIP/2.0
> > Via: SIP/2.0/UDP 192.168.93.214:5060;branch=z9hG4bKcb74.9a10e3a3.0
> > From: <sip:+16465551212 at 192.168.80.13>;tag=c0d1ec70-fbaa-429c-acc9-17dec131459e
> > i: e33b7043-ef96-4102-9f6a-bcb9c97ac4da
> > To: <sip:XFER_3235551212 at 192.168.80.56>;tag=f9e1dd31-b586-4f47-9fb8-3d541b658a67
> > CSeq: 5413 ACK
> > Max-Forwards: 70
> > User-Agent: OpenSIPS (2.4.3 (x86_64/linux))
> > Content-Length: 0
> >
> > U 2018/11/28 10:18:22.759666 192.168.93.214:5060 -> 192.168.80.13:5060
> > SIP/2.0 400 Bad Request-URI
> > v: SIP/2.0/UDP 192.168.80.13:5060;received=192.168.80.13;rport=5060;branch=z9hG4bKPjdb6efcd9-373b-4122-8bde-9d92a608d6ee
> > f: sip:+16465551212 at 192.168.80.13;tag=c0d1ec70-fbaa-429c-acc9-17dec131459e
> > t: sip:+13235551212 at 192.168.93.214;tag=155c340f586c28d0300cf5a6ccf90d99-03d7
> > i: e33b7043-ef96-4102-9f6a-bcb9c97ac4da
> > CSeq: 5413 INVITE
> > Server: OpenSIPS (2.4.3 (x86_64/linux))
> > Content-Length: 0
> >
> > I'm going to try and get more detailed debug dumps from OpenSIPS but
> > it's only happening on a subset of calls and, of course, this was a
> > production box (I didn't notice this in my limited testing) so I'm not
> > able to safely live debug this box.
> >
> > I wanted to pitch it over the fence as soon as I could to get things
> > rolling in case you guys might have an idea what's going on.
> >
> > Thanks much,
> >
> >   - Jock
> >
> > _______________________________________________
> > Users mailing list
> > Users at lists.opensips.org
> > http://lists.opensips.org/cgi-bin/mailman/listinfo/users
> >
>
> --
> Răzvan Crainea
> OpenSIPS Core Developer
>    http://www.opensips-solutions.com
> Meet the OpenSIPS team at the next OpenSIPS Summit:
>    https://www.opensips.org/events
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users