[Users] Malformed CANCEL request from Asterisk possibly impacting OpenSER?
David Coulthart
davec at columbia.edu
Wed May 30 16:49:14 CEST 2007
We are currently experiencing problems with our production OpenSER
(1.1.0) environment where the load on the server is steadily increasing
and the OpenSER response time increases drastically (e.g., 30+ seconds
for an internal call to ring).
Capturing the network traffic when this happens we have noticed that our
Asterisk (1.2.10) voicemail server is sending malformed CANCEL requests
to our OpenSER proxy. We are not certain whether this is a cause or an
effect of the load problems on the OpenSER server. Here is the SIP data
from the bad CANCEL request:
Session Initiation Protocol
Request-Line: CANCEL :u43974 at 128.59.59.215:5069 SIP/2.0
Method: CANCEL
[Resent Packet: False]
Message Header
Via: SIP/2.0/UDP 128.59.59.215:5069;branch=z9hG4bK6734835b;rport
Transport: UDP
Sent-by Address: 128.59.59.215
Sent-by port: 5069
Branch: z9hG4bK6734835b
RPort: rport
Route: <sip:128.59.59.199;lr=on;ftag=4FC702F4-7F812557>
From: <sip:43974 at sip.columbia.edu;user=phone>
SIP from address: sip:43974 at sip.columbia.edu
To: "Jim Rios" <sip:47891 at sip.columbia.edu>;tag=4FC702F4-7F812557
SIP Display info: "Jim Rios"
SIP to address: sip:47891 at sip.columbia.edu
SIP tag: 4FC702F4-7F812557
Contact: <sip:u43974 at 128.59.59.215:5069>
Contact Binding: <sip:u43974 at 128.59.59.215:5069>
URI: <sip:u43974 at 128.59.59.215:5069>
SIP contact address: sip:u43974 at 128.59.59.215:5069
Call-ID: c9a0135b-41273fb6-f7b6cea9 at 160.39.14.100
CSeq: 101 CANCEL
Sequence Number: 101
Method: CANCEL
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0
Accompanying this bad CANCEL request are the following error messages
recorded by OpenSER to syslog when it attempts to process it:
May 29 15:34:07 cocoa openser[892]: ERROR: parse_uri: bad uri, state 0 parsed: <:u43> (4) / <:u43974 at 128.59.59.215:5069> (26)
May 29 15:34:07 cocoa openser[892]: ERROR: parse_sip_msg_uri: bad uri <:u43974 at 128.59.59.215:5069>
May 29 15:34:07 cocoa openser[892]: xl_get_ruri: ERROR while parsing the R-URI
May 29 15:34:08 cocoa openser[892]: c9a0135b-41273fb6-f7b6cea9 at 160.39.14.100: route[0] CANCEL r-uri <<null>> from <sip:43974 at sip.columbia.edu;user=phone> to <sip:47891 at sip.columbia.edu>
May 29 15:34:08 cocoa openser[892]: ERROR: parse_uri: bad uri, state 0 parsed: <:u43> (4) / <:u43974 at 128.59.59.215:5069> (26)
May 29 15:34:08 cocoa openser[892]: ERROR: parse_sip_msg_uri: bad uri <:u43974 at 128.59.59.215:5069>
May 29 15:34:08 cocoa openser[892]: loose_route: Error while parsing Request URI
May 29 15:34:08 cocoa openser[892]: ERROR: parse_uri: bad uri, state 0 parsed: <:u43> (4) / <:u43974 at 128.59.59.215:5069> (26)
May 29 15:34:09 cocoa openser[892]: ERROR: parse_sip_msg_uri: bad uri <:u43974 at 128.59.59.215:5069>
May 29 15:34:09 cocoa openser[892]: WARNING: do_action:error in expression
May 29 15:34:09 cocoa openser[892]: ERROR: parse_uri: bad uri, state 0 parsed: <:u43> (4) / <:u43974 at 128.59.59.215:5069> (26)
May 29 15:34:09 cocoa openser[892]: ERROR: parse_sip_msg_uri: bad uri <:u43974 at 128.59.59.215:5069>
May 29 15:34:09 cocoa openser[892]: ERROR: parse_uri: bad uri, state 0 parsed: <:u43> (4) / <:u43974 at 128.59.59.215:5069> (26)
May 29 15:34:10 cocoa openser[892]: ERROR: parse_sip_msg_uri: bad uri <:u43974 at 128.59.59.215:5069>
May 29 15:34:10 cocoa openser[892]: ERROR: parse_uri: bad uri, state 0 parsed: <:u43> (4) / <:u43974 at 128.59.59.215:5069> (26)
May 29 15:34:10 cocoa openser[892]: ERROR: parse_sip_msg_uri: bad uri <:u43974 at 128.59.59.215:5069>
May 29 15:34:10 cocoa openser[892]: alias_db_lookup: Error while parsing Request-URI
While the malformed packet is likely the fault of the Asterisk server
(we see no packets from OpenSER to Asterisk with the sip protocol
missing from the URI), we are wondering if OpenSER errors out in a bad
way when it tries to process this packet, possibly entering into some
sort of loop that is causing the load to go through the roof.
It is also unclear to us why the Asterisk voicemail server would be
responding with a cancel. In our packet capture we see no record of a
request initiated by the Asterisk server that it would be sending a
CANCEL for.
Any insight that could be offered into this problem would be greatly
appreciated.
Thx,
David Coulthart
More information about the Users
mailing list