[OpenSIPS-Users] OpenSIPS 1.4.2 memory corruption issue under extreme load?
joel garcia
joelphilipgarcia at yahoo.com
Tue Mar 3 23:35:31 CET 2009
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 <bogdan at voice-system.ro>
To: joel garcia <joelphilipgarcia at yahoo.com>
Cc: Serge JF <serge at elasticall.com>; users at 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:+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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.opensips.org/pipermail/users/attachments/20090303/b3131461/attachment-0001.htm
More information about the Users
mailing list