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

Bogdan-Andrei Iancu bogdan at voice-system.ro
Tue Mar 3 17:44:38 CET 2009


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:+18566654221 at 4.xx.xx.xx:5060 SIP/2.0
>  From: <sip:+18668496441 at 63.xx.xx.xx:5060>;tag=telstage-67aa-49a935d9
>  To: sip:+18566654221 at 8.xx.xx.xx;tag=gK02b2b6e2
>  Contact: <sip:63.xx.xx.xx:5060;transport=udp>
>  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330cddf at 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:+18668496441 at 63.xx.xx.xx:5060>;tag=telstage-67aa-49a935d9
>  To: sip:+18566654221 at 8.xx.xx.xx;tag=gK02b2b6e2
>  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330cddf at 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:+18566654221 at 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:+18668496441 at 63.xx.xx.xx:5060>;tag=telstage-67aa-49a935d9
>  To: sip:+18566654221 at 8.xx.xx.xx;tag=gK02b2b6e2
>  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330cddf at 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:+18566654221 at 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:+18666287097 at 63.xx.xx.xx:5060>;tag=telstage-31e5-49a935fc
>  To: sip:+19197639388 at 8.xx.xx.xx;tag=gK0ad718b1
>  Call-ID: 49a935fc-039b-00672427-07d84f2d-3f76ff5a at 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:+19197639388 at 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:+18668496441 at 63.xx.xx.xx:5060>;tag=telstage-67aa-49a935d9
>  To: sip:+18566654221 at 8.xx.xx.xx;tag=gK02b2b6e2
>  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330cddf at 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:+18566654221 at 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 <bogdan at voice-system.ro>
> *To:* Serge JF <serge at elasticall.com>
> *Cc:* users at 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:+18566654221 at 4.xx.xx <mailto:18566654221 at 4.xx.xx>.227:5060 SIP/2.0
> >  From: <sip:+18668496441 at 63.xxx.xx 
> <mailto:18668496441 at 63.xxx.xx>.108:5060>;tag=telstage-67aa-49a935d9
> >  To: sip:+18566654221 at 8.xx.xx 
> <mailto:18566654221 at 8.xx.xx>.19;tag=gK02b2b6e2
> >  Contact: <sip:63.xxx.xx.108:5060;transport=udp>
> >  Call-ID: 49a935d9-029f-0065abfa-8162901a-4330cddf at 63.xxx.xx 
> <mailto:49a935d9-029f-0065abfa-8162901a-4330cddf at 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 at lists.opensips.org <mailto:Users at lists.opensips.org>
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users




More information about the Users mailing list