Hi,
I am trying to run the following setup.
Xten<-->Openser<-->Asterisk
openser ip = 192.168.1.21:5060
asterisk ip = 192.168.1.21:5070
xten = 192.168.1.35:5070
Xten is registered with openser and calls with particular prefixes are forwarded to asterisk. I record route all messages passing through openser. The initial INVITE and 200 OK messages are exchanged successfully but the associated ACK messages are not processed properly by openser. Part of the 200 OK received by xten is shown below
Via: SIP/2.0/UDP 192.168.1.23:5070;received=192.168.1.35;rport=5070;branch=z9hG4bK5B7D03B5696C9316CD87AB79100D0893
Record-Route: <sip:192.168.1.21;lr=on;ftag=386046356>
From: 1956 <sip:1956@192.168.1.21:5070>;tag=386046356
To: <sip:1313263@192.168.1.21>;tag=as36bd8053
Contact: <sip:1313263@192.168.1.21:5070>
The ACK sent out by xten is shown below
Request-Line: ACK sip:1313263@192.168.1.21:5070 SIP/2.0
Message Header
Via: SIP/2.0/UDP 192.168.1.23:5070;rport;branch=z9hG4bK3F391943F7AC4F861033318A443F92D7
From: 1956 <sip:1956@192.168.1.21:5070>;tag=386046356
To: <sip:1313263@192.168.1.21>;tag=as36bd8053
Contact: <sip:1956@192.168.1.23:5070>
Route: <sip:192.168.1.21;lr=on;ftag=386046356>
As can be seen, xten sets the RURI with the contact value received from 200 OK and Route is populated with the value from Record-Route.
When openser receives this ACK message, instead of confirming the Route address as its own it resets the RURI with the Route header value (which happens to be the openser address) and sends it out causing it loop back. It should have confirmed the Route value was its own address and removed it from the Route list. The ACK packet is shown below
Request-Line: ACK sip:192.168.1.21;lr=on;ftag=386046356 SIP/2.0
Message Header
Record-Route: <sip:192.168.1.21;lr=on;ftag=386046356>
Via: SIP/2.0/UDP 192.168.1.21;branch=0
Via: SIP/2.0/UDP 192.168.1.23:5070;received=192.168.1.35;rport=5070;branch=z9hG4bK3F391943F7AC4F861033318A443F92D7
From: 1956 <sip:1956@192.168.1.21:5070>;tag=386046356
To: <sip:1313263@192.168.1.21>;tag=as36bd8053
Contact: <sip:1956@192.168.1.35:5070>
For reference, Iam attaching relevant parts of my cfg and debug output. Kindly guide me if I need to rewrite my cfg in a particular way or is there a bug in openser, since I believe xten is behaving correctly. I am using the latest development version of openser, although I tested on the previous stable release as well, with the same results. BTW BYE messages sent out by xten also suffer the same fate as ACKS.
Regards,
Danish
DEBUG OUTPUT
4(17830) SIP Request:
4(17830) method: <ACK>
4(17830) uri: <sip:1313263@192.168.1.21:5070>
4(17830) version: <SIP/2.0>
4(17830) parse_headers: flags=2
4(17830) Found param type 235, <rport> = <n/a>; state=6
4(17830) Found param type 232, <branch> = <z9hG4bK3F391943F7AC4F861033318A443F92D7>; state=16
4(17830) end of header reached, state=5
4(17830) parse_headers: Via found, flags=2
4(17830) parse_headers: this is the first via
4(17830) After parse_msg...
4(17830) preparing to run routing scripts...
4(17830) DEBUG : sl_filter_ACK: to late to be a local ACK!
4(17830) parse_headers: flags=100
4(17830) DEBUG: add_param: tag=as36bd8053
4(17830) DEBUG:parse_to:end of header reached, state=29
4(17830) DBUG:parse_to: display={}, ruri={sip:1313263@192.168.1.21}
4(17830) DEBUG: get_hdr_field: <To> [47]; uri=[sip:1313263@192.168.1.21]
4(17830) DEBUG: to body [<sip:1313263@192.168.1.21>]
4(17830) get_hdr_field: cseq <CSeq>: <39751> <ACK>
4(17830) DEBUG:maxfwd:is_maxfwd_present: value = 70
4(17830) DEBUG: add_param: tag=386046356
4(17830) DEBUG:parse_to:end of header reached, state=29
4(17830) DBUG:parse_to: display={1956}, ruri={sip:1956@192.168.1.21:5070}
4(17830) parse_headers: flags=200
4(17830) is_preloaded: No
4(17830) grep_sock_info - checking if host==us: 12==12 && [192.168.1.21] == [192.168.1.21]
4(17830) grep_sock_info - checking if port 5060 matches port 5070
4(17830) grep_sock_info - checking if host==us: 12==12 && [192.168.1.21] == [192.168.1.21]
4(17830) grep_sock_info - checking if port 5060 matches port 5070
4(17830) after_strict: Next hop: 'sip:192.168.1.21;lr=on;ftag=386046356' is loose router
4(17830) parse_headers: flags=ffffffffffffffff
4(17830) DEBUG: get_hdr_body : content_length=0
4(17830) found end of header
4(17830) rewrite_uri: Rewriting Request-URI with 'sip:192.168.1.21;lr=on;ftag=386046356'
4(17830) after_strict: The last route URI: 'sip:192.168.1.21;lr=on;ftag=386046356'
4(17830) Danish: Entering loose route for method [ACK]
4(17830) DEBUG: has_totag: totag found
openser.cfg:
modparam("rr", "enable_full_lr", 1)
route {
# -----------------------------------------------------------------
# Sanity Check Section
# -----------------------------------------------------------------
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483", "Too Many Hops");
return;
};
if (msg:len > max_len) {
sl_send_reply("513", "Message Overflow");
return;
};
# -----------------------------------------------------------------
# Record Route Section
# -----------------------------------------------------------------
if (!method=="REGISTER") {
record_route();
};
if (method=="BYE" || method=="CANCEL") {
unforce_rtp_proxy();
}
# -----------------------------------------------------------------
# Loose Route Section
# -----------------------------------------------------------------
if (loose_route()) {
if (has_totag() && (method=="INVITE" || method =="ACK" || method=="BYE" || method=="INFO")) {
if (nat_uac_test("2")) {
setflag(6);
force_rport();
fix_nated_contact();
};
if (!search("^Content-Length:[ ]*0")) {
force_rtp_proxy();
}
};
route(1);
return;
};
route[1] {
# -----------------------------------------------------------------
# Default Message Handler
# -----------------------------------------------------------------
if (!t_relay()) {
if (method=="INVITE" && isflagset(6)) {
unforce_rtp_proxy();
};
sl_reply_error();
};
}