16 Nov
2005
16 Nov
'05
5:50 p.m.
Hey Greger,
Sorry, I made a typo, the message at 16:51:51.559657 should be listed
as going to the Cisco device at Z.Z.Z.Z and not Asterisk at X.X.X.X.
The interesting this is this usually only happens about once an hour
and all the other times the ACK leaves SER before the INVITE. We log
everything on our boxes pretty extensively (we log a bunch of human
readable data along with the entire message buffer via xlog) for most
messages and if I look through our logs I see the ACK being processed as
loose before the INVITE.
The loose route section of the config is pretty simple, it xlogs some
stuff and then sends it off to route(1) which sets up a reply handler,
adds an RPID and t_relay()'s so I'm not sure the config has anything to
do with this, especially because the ACK is delivered before the INVITE
approx 98 out of 100 times.
-Evan
Greger V. Teigre wrote:
Evan,
I'm not able to match your text with the messages you show. The message
timestamped 16:51:51.559657, does it go to Cisco? It is shown to go to
Asterisk and it doesn't make sense.
However, until the Cisco gw receives the ACK from Asterisk, no call has
been established and the reINVITE cannot be matched. IMO, this is not a
Cisco bug. It seems very strange indeed that ser should send a reINVITE
before the ACK in the same call. Even without FIFO, an INVITE is likely
to take more time to process than a loose routed ACK. I would try to log
more thoroughly in SER to see what happens in processing the ACK and the
reINVITE. It could be a problem in your ser.cfg, but it seems strange
indeed.
g-)
----- Original Message ----- From: "Evan Borgstrom"
<evan.borgstrom(a)ca.mci.com>
To: <serusers(a)lists.iptel.org>rg>; <serdev(a)lists.iptel.org>
Sent: Wednesday, November 16, 2005 12:05 AM
Subject: [Serdev] ACK before INVITE on re-INVITE causes Cisco AS's to
return a 500 error
Hey all,
This has more to do with Asterisk & Cisco AS's IMO but I thought it
would be interesting to get some responses from this group before I
begin the battle with Cisco to get a bug report underway.
We have an Asterisk box acting as a PBX sending calls to our SER
instances. The asterisk box has "reinvite=yes" in the sip.conf file
which causes Asterisk to send a re-INVITE for the call once it receives
the 200 OK. This re-INVITE has it's SDP changed to that of the IP Phone
behind the Asterisk box so that all media doesn't need to traverse it.
This works fine except in certain instances where messages get out of
order and it causes our Cisco GW's to error the call with a generic 500
message. When the messages are in the correct order the 500 error does
not appear.
So here's the situation, user behind the asterisk box picks up the
phone and dials a PSTN destination. Asterisk fires off the initial
invite and everything proceeds as normal and we eventually receive the
200 OK message to which the Asterisk box replies with ACK and a new
INVITE that come in this order (X = Asterisk, Y = SER, Z = Cisco):
U 2005/11/15 16:51:51.557322 X.X.X.X:5060 -> Y.Y.Y.Y:5060
ACK
#
U 2005/11/15 16:51:51.557948 X.X.X.X:5060 -> Y.Y.Y.Y:5060
INVITE
SER accordingly processes the two messages and replies 100 Trying to
the new INVITE message. Here's where the problem occurs, SER then sends
these messages out to the PSTN gateway but the order has been reversed:
#
U 2005/11/15 16:51:51.558937 Y.Y.Y.Y:5060 -> X.X.X.X:5060
SIP/2.0 100 trying
#
U 2005/11/15 16:51:51.559000 Y.Y.Y.Y:5060 -> Z.Z.Z.Z:5060
INVITE
#
U 2005/11/15 16:51:51.559657 Y.Y.Y.Y:5060 -> X.X.X.X:5060
ACK
When this happens the Cisco GW replies with a 500 error message and the
following is sent to the Cisco's logs:
#
U 2005/11/15 16:51:51.711355 Z.Z.Z.Z:5060 -> Y.Y.Y.Y:5060
SIP/2.0 500 Server Internal Error.
Nov 15 21:51:51.613: HandleUdpSocketReads :Msg enqueued for SPI with
IPaddr: Y.Y.Y.Y:5060
Nov 15 21:51:51.613: *****CCB found in UAS Request table. ccb=0x653BCD0C
Nov 15 21:51:51.613: CCSIP-SPI-CONTROL: act_sentsucc_new_message
Nov 15 21:51:51.617: CCSIP-SPI-CONTROL: act_sentsucc_new_message_request
Nov 15 21:51:51.617: Queued event from SIP SPI : SIPSPI_EV_SEND_MESSAGE
Nov 15 21:51:51.617: sip_stats_status_code
Nov 15 21:51:51.617: sipSPICheckRequest: CheckRequest fail on method 102
error code: 2 and status: 500
Is there any parameter that I can set to ensure that message leave SER
in the order they enter? Should the Cisco be able to handle this
condition (I check a number of different sections of the RFC but
couldn't find anything specific for either side)?
Thanks,
Evan
_______________________________________________
Serdev mailing list
serdev(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serdev