[OpenSIPS-Users] OpenSIPS 1.4.2 memory corruption issue under extreme load?
joel garcia
joelphilipgarcia at yahoo.com
Mon Mar 2 17:43:59 CET 2009
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.227:5060 SIP/2.0
> From: <sip:+18668496441 at 63.xxx.xx.108:5060>;tag=telstage-67aa-49a935d9
> To: sip:+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.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
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.opensips.org/pipermail/users/attachments/20090302/9ae377a1/attachment-0001.htm
More information about the Users
mailing list