[OpenSIPS-Users] ACK not relaying - no NAT problem - SOLVED
Suresh
suresh.tupakula at sasken.com
Tue Dec 4 13:09:21 CET 2012
samuel <samu60 at ...> writes:
>
>
> I've located the problem:I had a sl_send_reply("100","Trying");just at the
start of the config file and when the ACK reached this point, it was
absorved....I'm not sure it it should be the right behaviour but at least I can
now make an if-else or similar for these cases.Apologies for the noise,Samuel.
> On 3 January 2012 14:01, samuel <samu60-
Re5JQEeQqe8AvxtiuMwx3w at public.gmane.org> wrote:
> Hi folks,I've seeing a weird issue with an opensips 1.7.1 installation and the
standard configuration. I can provide more information if required but it looks
like the ACK is absorved without being relayed. This ACK is the 3-rd handshake
of the session initiation, not an acknowledge. The INVITE-180 Ringing-200 OK is
sent between endpoints (blink 0.2.8 and sylkerver 1.3.0) but when the
sylkservers send the ACK to Blink, the SIP proxy, it does not forward it:T
IP.adress.of.Blink:47793 -> IP.adress.of.Opensips:5060 [AP] ACK sip:666159753-
zH6ZcRN9TvY8rTsCsKQflUJ6tjruZCfd at public.gmane.org:5060 SIP/2.0..Via:
SIP/2.0/tcp
IP.adress.of.Blink:47793;rport;branch=z9hG4bKPj7YGMzdPHc9T.PIoWqBj6f21w50CkGByH
>
> Max-Forwards: 70 From: "Samuel" <sip:sam-
6/gFXhCLHJRa3S8i2hKWQw at public.gmane.org>;tag=CRRPKM1rHO8cSe8vkBJNL93KupfjkiwC
To: <sip:666159753-
6/gFXhCLHJTUF6G2QusZNg at public.gmane.org.org>;tag=tnoBz19pYIcw9QmTB90CP3hC6g7Mday
k
>
> Call-ID: -SAKz4FlDSJ0rjEks.EUC5LTOlsttkFa CSeq: 19923 ACK Route:
<sip:IP.adress.of.Opensips;transport=tcp;lr;r2=on;did=cd4.66e94036> Route:
<sip:IP.adress.of.Opensips;lr;r2=on;did=cd4.66e94036>
>
> User-Agent: Blink 0.2.8 (Linux) Content-Length: 0Opensips' logs contain
the following lines:Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]:
DBG:core:parse_msg: method: <ACK>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]: DBG:core:parse_msg:
uri: <sip:666159753 at IP.adress.of.Sylkserver:5060>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]: DBG:core:parse_msg:
version: <SIP/2.0>Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]:
DBG:core:parse_headers: flags=2Jan 3 13:41:23 osip2
/usr/local/sbin/opensips[21833]: DBG:core:parse_via_param: found param type 235,
<rport> = <n/a>; state=6
>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]:
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bKPj7YGMzdPHc9T.PIoWqBj6f21w50CkGByH>; state=16Jan 3 13:41:23 osip2
/usr/local/sbin/opensips[21833]: DBG:core:parse_via: end of header reached,
state=5
>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]: DBG:core:parse_headers:
via found, flags=2Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]:
DBG:core:parse_headers: this is the first viaJan 3 13:41:23 osip2
/usr/local/sbin/opensips[21833]: DBG:core:receive_msg: After parse_msg...
>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]: DBG:core:receive_msg:
preparing to run routing scripts...Jan 3 13:41:23 osip2
/usr/local/sbin/opensips[21833]: DBG:sl:sl_filter_ACK: to late to be a local
ACK!
>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]: DBG:core:parse_headers:
flags=100Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]:
DBG:maxfwd:is_maxfwd_present: value = 70 Jan 3 13:41:23 osip2
/usr/local/sbin/opensips[21833]: DBG:core:destroy_avp_list: destroying list
(nil)
>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21833]: DBG:core:receive_msg:
cleaning upJan 3 13:41:23 osip2 /usr/local/sbin/opensips[21830]:
DBG:tm:cleanup_uac_timers: RETR/FR timers resetJan 3 13:41:23 osip2
/usr/local/sbin/opensips[21830]: DBG:tm:t_unref: UNREF_UNSAFE: [0x7f173201f8d8]
after is 0
>
> Jan 3 13:41:23 osip2 /usr/local/sbin/opensips[21830]:
DBG:core:destroy_avp_list: destroying list (nil)Jan 3 13:41:23 osip2
/usr/local/sbin/opensips[21830]: DBG:core:receive_msg: cleaning upIt looks like
the ACK is not even passed to route(0) because I do not see anything from the
config line appeared and no matter which log I setup in the start, its not
rendered in the logs.I'm using dialog module with db_mode 1 to trace dialogs in
database, so the ACK might trigger a hook in this module.I'm also using
mediaproxy with dialog built-in hooks, engage_mediaproxy() # account only
INVITEs
>
> if (is_method("INVITE")) { setflag(1); # do
accounting #modifications
create_dialog("PpB"); $dlg_val(caller) = $fu;
>
> $dlg_val(callee) = $ru;
engage_media_proxy(); }Does anyone see any issue with the ACK or any hint
to look into the configuration file so I can trace why the ACK is not sent?Thank
you very much in advance and apologies for the longitude,Samuel.
>
>
>
>
Hi,
I am facing the same issue. Moreover I also observed that P-CSCF mentions that
" I don't send reply for ACK". Appreciate if you can help in resolving this
issue.
Please check the snapshot attached.
qm_malloc(0x8165ec0, 808) called from receive.c: receive_msg(94)
qm_malloc(0x8165ec0, 808) returns address 0x81d889c frag. 0x81d8884 (size=808)
on 1 -th hit
SIP Request:
method: <ACK>
uri: <sip:+919611186584 at ims.sasken.com>
version: <SIP/2.0>
parse_headers: flags=2
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d9744 frag. 0x81d972c (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d98d4 frag. 0x81d98bc (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d91e8 frag. 0x81d91d0 (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d9558 frag. 0x81d9540 (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 44) called from parser/msg_parser.c: get_hdr_field(151)
qm_malloc(0x8165ec0, 44) returns address 0x81d8d78 frag. 0x81d8d60 (size=44) on
1 -th hit
qm_malloc(0x8165ec0, 24) called from parser/parse_to.c: parse_to_param(284)
qm_malloc(0x8165ec0, 24) returns address 0x81d9330 frag. 0x81d9318 (size=28) on
1 -th hit
DEBUG: add_param: tag=2bdbf2deb62ba4b2450140ea0953036e-48f6
end of header reached, state=29
DEBUG: get_hdr_field: <To> [78]; uri=[sip:+919611186584 at ims.sasken.com]
DEBUG: to body [<sip:+919611186584 at ims.sasken.com>]
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d8fb8 frag. 0x81d8fa0 (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 116) called from parser/msg_parser.c: get_hdr_field(111)
qm_malloc(0x8165ec0, 116) returns address 0x81da7ac frag. 0x81da794 (size=116)
on 1 -th hit
qm_malloc(0x8165ec0, 32) called from parser/parse_via.c: parse_via(2142)
qm_malloc(0x8165ec0, 32) returns address 0x81d9974 frag. 0x81d995c (size=32) on
1 -th hit
Found param type 232, <branch> =
<z9hG4bK99fad4f322ebab912027d09c4dc44acc353531>; state=6
qm_malloc(0x8165ec0, 32) called from parser/parse_via.c: parse_via(2142)
qm_malloc(0x8165ec0, 32) returns address 0x81d9ba4 frag. 0x81d9b8c (size=32) on
1 -th hit
Found param type 235, <rport> = <n/a>; state=17
end of header reached, state=5
parse_headers: Via found, flags=2
parse_headers: this is the first via
After parse_msg...
preparing to run routing scripts...
DEBUG : sl_filter_ACK: to late to be a local ACK!
DEBUG:maxfwd:is_maxfwd_present: value = 70
DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
Calling SELECT 0x81a5854
parse_headers: flags=ffffffffffffffff
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d9794 frag. 0x81d977c (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 20) called from parser/msg_parser.c: get_hdr_field(130)
qm_malloc(0x8165ec0, 20) returns address 0x81d8c94 frag. 0x81d8c7c (size=20) on
1 -th hit
get_hdr_field: cseq <CSeq>: <1> <ACK>
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d9478 frag. 0x81d9460 (size=32) on
1 -th hit
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d9f84 frag. 0x81d9f6c (size=32) on
1 -th hit
DEBUG: get_hdr_body : content_length=0
qm_malloc(0x8165ec0, 32) called from parser/msg_parser.c: parse_headers(298)
qm_malloc(0x8165ec0, 32) returns address 0x81d9508 frag. 0x81d94f0 (size=32) on
1 -th hit
found end of header
qm_free(0x8165ec0, 0x81d9508), called from parser/msg_parser.c:
parse_headers(314)
qm_free: freeing frag. 0x81d94f0 alloc'ed from parser/msg_parser.c:
parse_headers(298)
DBG:P-CSCF:P_check_sent_by(): Received from <27.57.179.243>
parse_headers: flags=ffffffffffffffff
DBG:P-CSCF:P_check_sent_by(): Via sent-by=<27.57.179.243>
DBG:P-CSCF:P_check_sent_by(): sent-by matches the actual IP received from
parse_headers: flags=200
qm_malloc(0x8165ec0, 36) called from parser/parse_rr.c: do_parse_rr_body(68)
qm_malloc(0x8165ec0, 36) returns address 0x81da158 frag. 0x81da140 (size=40) on
1 -th hit
qm_malloc(0x8165ec0, 36) called from parser/parse_rr.c: do_parse_rr_body(68)
qm_malloc(0x8165ec0, 36) returns address 0x81d96ec frag. 0x81d96d4 (size=40) on
1 -th hit
DBG:P-CSCF:P_mobile_terminating: Term indication not found in
<sip:164.164.56.9:4060> as <sip:term at pcscf.ims.sasken.com:4060>.
[01;32mDBG:P-CSCF:cscf_get_originating_contact: 2://27.57.179.243:4060
parse_headers: flags=40
[01;32mDBG:P-CSCF:cscf_get_terminating_contact: 0://ims.sasken.com:0
parse_headers: flags=40
qm_malloc(0x8165ec0, 54) called from ut.c: as_asciiz(135)
qm_malloc(0x8165ec0, 56) returns address 0x81da4d8 frag. 0x81da4c0 (size=60) on
1 -th hit
[01;34mWarning: sl_send_reply: I won't send a reply for ACK!!
Appreciating your suggestions.
More information about the Users
mailing list