Re: [OpenSIPS-Users] OpenSIPS 1.4.2 memory corruption issue under extreme load?

[Bogdan-Andrei Iancu]

Hi Joel,

So, the the bogus VIA was received from the network level and not a 
result of whatever processing (more or less buggy) in OpenSIPS....

Cool you traced it down.

Regards,
Bogdan

joel garcia wrote:
> Hey Bogdan,
>
> Thanks for responding.
>
> We have resolved our issue. It was a network\carrier issue.
>
> We noticed that all of the corrupt sip messages were coming from 2 
> specific SBCs. It took a while, but we were finally able to narrow it 
> down. When we dynamically removed those SBCs from the 
> carrierroute.conf map, the parser via issue disappeared.
>  
> Thanks,
> Joel
>
>
> ------------------------------------------------------------------------
> *From:* Bogdan-Andrei Iancu <bog...@voice-system.ro>
> *To:* joel garcia <joelphilipgar...@yahoo.com>
> *Cc:* Serge JF <se...@elasticall.com>; users@lists.opensips.org
> *Sent:* Tuesday, March 3, 2009 8:44:38 AM
> *Subject:* Re: [OpenSIPS-Users] OpenSIPS 1.4.2 memory corruption issue 
> under extreme load?
>
> Hi Joel,
>
> whatever you do from the script, it is impossible to change the 
> original buffer (which is parsed by the via_parser).
>
> Can you post (or privately sent) the log (debug=6) for such a request 
> processing (if possible to capture).
>
> Thanks and regards,
> Bogdan
>
> joel garcia wrote:
> > Hey Bogdan,
> >
> > I'm working with Serge on this. Thank you for the helper facts.
> >
> > The TRACE log is before the error msg in the opensips.log. I've 
> attached the log to the bottom.
> >
> > I'm hoping that our changes to the opensips.cfg are the cause of 
> these errors. We're currently manipulating $avp(i:25) and $avp(i:35) 
> variables to handle different carriers. Do you see anything wrong in 
> this logic that could be corrupting the header or msg? Specifically, 
> what I notice is that the Carrier-Name is not set in the header for 
> this invite. We recently added some logic to default to a particular 
> carrier if no carrier is specified.
> >
> > Under volume, we are seeing a large number of these type of parser 
> errors in both the header and the msg. I have other examples.
> >  I've also added a portion of our route() implementation.
> >
> > Thanks for your assistance,
> > Joel
> >
> >
> > route{
> >
> >    xlog("TRACE:ROUTE: time($Ts) src($si:$sp) dst($Ri:$Rp) msg($mb)\n");
> >    ...
> >        if (is_method("INVITE")) {
> >
> >                # set carrier name
> >                if (is_present_hf("Carrier-Name")) {
> >                        $avp(i:25) = $(hdr(Carrier-Name){s.tolower});
> >                        # valid carrier name passed?
> >                        switch ($avp(i:25)) {
> >                case "carrierA" :
> >                                $avp(i:25) = "doA";
> >                                break;
> >                                case "carrierB" :
> >                if ($rU =~ "^\+?1?8[0|6|7|8]{2}[0-9]{5,8}") {
> >                    # doA needs to be used for 1-800, 1-866, 1-877 or 
> 1-888 calls
> >                    $avp(i:25) = "doA";
> >                } else {
> >                    # doB is required for non 1-800 calls
> >                    $avp(i:25) = "doB";
> >                }
> >                                                default :
> >                        ...
> >                        }
> >                } else {
> >                        xlog("L_WARN", "WARN:ROUTE:CARRIER: no 
> carrier name specified\n");
> >                        # dialing to the US or Canada?
> >                        # We didn't find the Carrier-Name in the 
> header. DoweI need to
> >                        # add the Carrier-Name tag to the header or 
> will just setting $avp(i:25) work?
> >                        if ($rU =~ "^1" || $rU =~ "^\+1") {
> >                                # doA is the default carrier for US 
> and Canadian calls
> >                                $avp(i:25) = "doA";
> >                        }
> >                        ... handle international
> >                }
> >      }
> > }
> >
> > We also tweak $avp(i:35)
> >
> > route[1] {
> >    if ($(hdr(Reason)) != null) {
> >        $avp(i:35) = $(hdr(Reason));
> >    };
> >        if (!t_relay()) {
> >        sl_reply_error();
> >    };
> >    exit;
> > }
> >
> > parse_via error msg logs
> >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: TRACE:ROUTE: 
> time(1235826197) src(63.xx.xx.xx:5060) dst(8.xx.xx.xx:5060) msg(INVITE 
> sip:+18566654...@4.xx.xx.xx <mailto:18566654...@4.xx.xx.xx>:5060 SIP/2.0
> >  From: <sip:+18668496...@63.xx.xx.xx 
> <mailto:18668496...@63.xx.xx.xx>:5060>;tag=telstage-67aa-49a935d9
> >  To: sip:+18566654...@8.xx.xx.xx 
> <mailto:18566654...@8.xx.xx.xx>;tag=gK02b2b6e2
> >  Contact: <sip:63.xx.xx.xx:5060;transport=udp>
> >  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx>
> >  CSeq: 32043 INVITE
> >  Content-Length: 177
> >  Content-Type: application/sdp
> >  Content-Disposition: session; handling=required
> >  Route: <sip:8.xx.xx.xx:5060;lr;ftag=telstage%2D67aa%2D49a935d9>
> >  Session-Expires: 1800;refresher=uac
> >  Supported: timer
> >  Max-Forwards: 70
> >  Via: SIP/2.0/UDP 
> 63.xx.xx.xx:5060;branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  v=0
> >  o=Sonus_UAC 8758 21805 IN IP4 4.xx.xx.xx
> >  s=SIP Media Capabilities
> >  c=IN IP4 4.xx.xx.xx
> >  t=0 0
> >  m=audio 11750 RTP/AVP 0
> >  a=rtpmap:0 PCMU/8000
> >  a=sendrecv
> >  a=maxptime:20
> >  )
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via:  invalid port number 
> <5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf>
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via:  <SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  From: <sip:+18668496...@63.xx.xx.xx 
> <mailto:18668496...@63.xx.xx.xx>:5060>;tag=telstage-67aa-49a935d9
> >  To: sip:+18566654...@8.xx.xx.xx 
> <mailto:18566654...@8.xx.xx.xx>;tag=gK02b2b6e2
> >  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx>
> >  CSeq: 32043 INVITE
> >  Record-Route: <sip:8.xx.xx.xx:5060;lr;ftag=telstage-67aa-49a935d9>
> >  Accept: application/sdp, application/isup, application/dtmf, 
> application/dtmf-relay,  multipart/mixed
> >  Contact: <sip:+18566654...@4.xx.xx.xx 
> <mailto:18566654...@4.xx.xx.xx>:5060>
> >  Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
> >  Content-Length:  177
> >  Content-Disposition: session; handling=required
> >  Content-Type: application/sdp
> >  v=0
> >  o=Sonus_UAC 11722 5484 IN IP4 4.xx.xx.xx
> >  s=SIP Media Capabilities
> >  c=IN IP4 4.xx.xx.xx
> >  t=0 0
> >  m=audio 22942 RTP/AVP 0
> >  a=rtpmap:0 PCMU/8000
> >  a=sendrecv
> >  a=maxptime:20
> >  >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via: parsed so far:<SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:get_hdr_field: bad via
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> INFO:core:parse_headers: bad header field
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:tm:t_check: reply cannot be parsed
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via:  invalid port number 
> <5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf>
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via:  <SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  From: <sip:+18668496...@63.xx.xx.xx 
> <mailto:18668496...@63.xx.xx.xx>:5060>;tag=telstage-67aa-49a935d9
> >  To: sip:+18566654...@8.xx.xx.xx 
> <mailto:18566654...@8.xx.xx.xx>;tag=gK02b2b6e2
> >  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx>
> >  CSeq: 32043 INVITE
> >  Record-Route: <sip:8.xx.xx.xx:5060;lr;ftag=telstage-67aa-49a935d9>
> >  Accept: application/sdp, application/isup, application/dtmf, 
> application/dtmf-relay,  multipart/mixed
> >  Contact: <sip:+18566654...@4.xx.xx.xx 
> <mailto:18566654...@4.xx.xx.xx>:5060>
> >  Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
> >  Content-Length:  177
> >  Content-Disposition: session; handling=required
> >  Content-Type: application/sdp
> >  v=0
> >  o=Sonus_UAC 11722 5484 IN IP4 4.xx.xx.xx
> >  s=SIP Media Capabilities
> >  c=IN IP4 4.xx.xx.xx
> >  t=0 0
> >  m=audio 22942 RTP/AVP 0
> >  a=rtpmap:0 PCMU/8000
> >  a=sendrecv
> >  a=maxptime:20
> >  >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via: parsed so far:<SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:get_hdr_field: bad via
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> INFO:core:parse_headers: bad header field
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:forward_reply: no 2nd via found in reply
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11609]: 
> TRACE:ONREPLY_ROUTE: time(1235826197) src(4.xx.xx.xx:5060) 
> dst(8.xx.xx.xx:5060) msg(SIP/2.0 200 OK
> >  Via: SIP/2.0/UDP 8.xx.xx.xx;branch=z9hG4bKff9d.4d7cb833.0
> >  Via: SIP/2.0/UDP 
> 63.xx.xx.xx:5060;branch=z9hG4bK49a935fc-039b-00672428-07d84f2d-3f76ff5a
> >  From: <sip:+18666287...@63.xx.xx.xx 
> <mailto:18666287...@63.xx.xx.xx>:5060>;tag=telstage-31e5-49a935fc
> >  To: sip:+19197639...@8.xx.xx.xx 
> <mailto:19197639...@8.xx.xx.xx>;tag=gK0ad718b1
> >  Call-ID: 49a935fc-039b-00672427-07d84f2d-3f76f...@63.xx.xx.xx 
> <mailto:49a935fc-039b-00672427-07d84f2d-3f76f...@63.xx.xx.xx>
> >  CSeq: 6600 INVITE
> >  Record-Route: <sip:8.xx.xx.xx:5060;lr;ftag=telstage-31e5-49a935fc>
> >  Accept: application/sdp, application/isup, application/dtmf, 
> application/dtmf-relay,  multipart/mixed
> >  Contact: <sip:+19197639...@4.xx.xx.xx 
> <mailto:19197639...@4.xx.xx.xx>:5060>
> >  Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
> >  Content-Length:  175
> >  Content-Disposition: session; handling=required
> >  Content-Type: application/sdp
> >  v=0
> >  o=Sonus_UAC 27689 2463 IN IP4 4.xx.xx.xx
> >  s=SIP Media Capabilities
> >  c=IN IP4 4.55.20.66
> >  t=0 0
> >  m=audio 26588 RTP/AVP 0
> >  a=rtpmap:0 PCMU/8000
> >  a=
> >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via: parsed so far:<SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:get_hdr_field: bad via
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> INFO:core:parse_headers: bad header field
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:tm:t_check: reply cannot be parsed
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via:  invalid port number 
> <5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf>
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via:  <SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >  From: <sip:+18668496...@63.xx.xx.xx 
> <mailto:18668496...@63.xx.xx.xx>:5060>;tag=telstage-67aa-49a935d9
> >  To: sip:+18566654...@8.xx.xx.xx 
> <mailto:18566654...@8.xx.xx.xx>;tag=gK02b2b6e2
> >  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xx.xx.xx>
> >  CSeq: 32043 INVITE
> >  Record-Route: <sip:8.xx.xx.xx:5060;lr;ftag=telstage-67aa-49a935d9>
> >  Accept: application/sdp, application/isup, application/dtmf, 
> application/dtmf-relay,  multipart/mixed
> >  Contact: <sip:+18566654...@4.xx.xx.xx 
> <mailto:18566654...@4.xx.xx.xx>:5060>
> >  Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE
> >  Content-Length:  177
> >  Content-Disposition: session; handling=required
> >  Content-Type: application/sdp
> >  v=0
> >  o=Sonus_UAC 11722 5484 IN IP4 4.xx.xx.xx
> >  s=SIP Media Capabilities
> >  c=IN IP4 4.xx.xx.xx
> >  t=0 0
> >  m=audio 22942 RTP/AVP 0
> >  a=rtpmap:0 PCMU/8000
> >  a=sendrecv
> >  a=maxptime:20
> >  >
> > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: 
> ERROR:core:parse_via: parsed so far:<SIP/2.0/UDP 
> 63.xx.xx.xx:5060branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> >
> >
> > ------------------------------------------------------------------------
> > *From:* Bogdan-Andrei Iancu <bog...@voice-system.ro 
> <mailto:bog...@voice-system.ro>>
> > *To:* Serge JF <se...@elasticall.com <mailto:se...@elasticall.com>>
> > *Cc:* users@lists.opensips.org <mailto:users@lists.opensips.org>
> > *Sent:* Monday, March 2, 2009 1:18:41 AM
> > *Subject:* Re: [OpenSIPS-Users] OpenSIPS 1.4.2 memory corruption 
> issue under extreme load?
> >
> > Hi Sergio,
> >
> > First, some helper facts:
> >
> > 1) the message buffer is kept in private memory, so it cannot be written
> > by other processes
> >
> > 2) parsing of the first via is done before starting the script
> > execution, so, none of the modules can interfere with the buffer.
> >
> > So, how do you get the TRACE log ? do you use the SIP TRACE module?
> >
> > Is the TRACE log after the via error?
> >
> > Regards,
> > Bogdan
> >
> > Serge JF wrote:
> > > Hello,
> > >
> > > We run a very high volume OpenSIPS 1.4.2 deployment with over 6 
> million
> > > calls processed daily on a single server running CentOS 5. After 3 
> days at
> > > maximum load we started seeing errors such as:
> > >
> > > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]:
> > > ERROR:core:parse_via:  invalid port number
> > > <5060?branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf>
> > >
> > > You'll notice the question mark ? after the port number. The 
> OpenSIPS parser
> > > does not like this and fails in the parsing - which had to be 
> expected. The
> > > issue is that the message according to the XLOG statement we got 
> at the very
> > > beginning of our route[] was received with a semicolon as expected:
> > >
> > > Feb 28 08:03:17 sip101 /usr/local/sbin/opensips[11614]: TRACE:ROUTE:
> > > time(1235826197) src(63.xx.xx.108:5060) dst(8.xx.xx.14:5060) 
> msg(INVITE
> > > sip:+18566654...@4.xx.xx <mailto:18566654...@4.xx.xx> 
> <mailto:18566654...@4.xx.xx <mailto:18566654...@4.xx.xx>>.227:5060 SIP/2.0
> > >  From: <sip:+18668496...@63.xxx.xx <mailto:18668496...@63.xxx.xx> 
> <mailto:18668496...@63.xxx.xx 
> <mailto:18668496...@63.xxx.xx>>.108:5060>;tag=telstage-67aa-49a935d9
> > >  To: sip:+18566654...@8.xx.xx <mailto:18566654...@8.xx.xx> 
> <mailto:18566654...@8.xx.xx 
> <mailto:18566654...@8.xx.xx>>.19;tag=gK02b2b6e2
> > >  Contact: <sip:63.xxx.xx.108:5060;transport=udp>
> > >  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330c...@63.xxx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xxx.xx> 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xxx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330c...@63.xxx.xx>>.108
> > >  CSeq: 32043 INVITE
> > >  Content-Length: 177
> > >  Content-Type: application/sdp
> > >  Content-Disposition: session; handling=required
> > >  Route: <sip:8.xx.xx.14:5060;lr;ftag=telstage%2D67aa%2D49a935d9>
> > >  Session-Expires: 1800;refresher=uac
> > >  Supported: timer
> > >  Max-Forwards: 70
> > >  Via: SIP/2.0/UDP
> > > 
> 63.xxx.xx.108:5060;branch=z9hG4bK49a93615-0234-0065adf8-8162901a-4330cddf
> > >
> > > Could this be due to some overwriting of string buffers in the 
> OpenSIPS CORE
> > > or TM module? How should we go about debugging this issue? It only 
> seems to
> > > happen after a few days under load. For the time being we have 
> introduced a
> > > nightly restart of the OpenSIPS to clear up the memory.
> > >
> > > Any pointer (sic) would be most welcome!
> > >
> > > Best Regards,
> > >
> > > Serge
> > >
> >
> > _______________________________________________
> > Users mailing list
> > Users@lists.opensips.org <mailto:Users@lists.opensips.org> 
> <mailto:Users@lists.opensips.org <mailto:Users@lists.opensips.org>>
> > http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>


_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users