Hi
My issue is how to construct ACK correctly in the dialog in case of NATed client. ( please see http://lists.sip-router.org/pipermail/sr-dev/2010-February/006145.html for the scenario detail )
nated-u1(bob)---> P1 --> nated-u2 (alice)
e.g: bob calls alcie,
(A) In the normal case,
U1 ---> P1 ---> U2 Invite-> <--200 OK ACK -->
The good ACK msg capted from P1 to U2 is: # U 67.154.255.47:4060 (P1) -> 67.154.250.3:2051 ( public ip/port for U2) ACK sip:alice@172.16.8.42:2051;line=e96ci3a9 SIP/2.0.
(B) In the abormal case,
U1 ---> P1 ---> U2 Invite-> ACK --> BYE --> <--488
P1 check something and need to send ACK/BYE to u2
The pseudo code try to use dialog module function:
dialog.request_inside(&method_ACK,&reqbuf,NULL, d,cb,cbp)
From the log file:
DEBUG:tm:t_uac: next_hop=sip:alice@centercall.net
The captured ACK msg:
U 67.154.255.47:4060 (P1) -> 67.154.255.44:5060 (i-cscf) ACK sip:alice@centercall.net SIP/2.0.
The two ACK msg is different.
Questions:
(1) How can I generate the correct ACK msg in this case?
(2) The issue with second ACK need more explaination ( from openims point of view):
i-cscf ---- s-cscf | U1 --> P1 --> U2
(i/s-cscf is sip proxy)
With this kind of ACK, the ACK first goes to i-cscf, which choose s-cscf, then goes back to P1, P1 will try to relay the ACK
route[Term_Subsequent]{ ... if (!P_security_relay()) P_NAT_relay();
t_relay() ... }
The log shows:
22106 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_funcs.c:184]: tm: put_on_wait: transaction 0xb59834b4 already on wait
It seems the tm module put this new ACK (the P1-generated ACK loop back to P1 now ) on hold, NOT relaying to U2.
From sniffed packets, the ACK never reaches the U2.
Any good way to resolve the issue?
Just FYI the BYE can reach U2 as it is a new tm transaction.
# U 67.154.255.47:4060 -> 67.154.255.44:5060 BYE sip:alice@centercall.net SIP/2.0.
22512 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found 22558 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_funcs.c:388]: SER: new transaction fwd'ed
/////////detailed log for ACK in Term_Subsequent /////////////// 21997 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [parser/msg_parser.c:627]: SIP Request: 21998 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [parser/msg_parser.c:629]: method: <ACK> 21999 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [parser/msg_parser.c:631]: uri: <sip:alice@172.16.8.42
:2051;line=otkb9mdz> 22000 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [parser/msg_parser.c:633]: version: <SIP/2.0>
22091 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: NOTICE: <script>: >> Term_Subsequent before relay 22092 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [mem/q_malloc.c:366]: qm_malloc(0x8272e60, 36) called from pcscf:
registration.c: P_security_relay(1086) 22093 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [mem/q_malloc.c:406]: qm_malloc(0x8272e60, 36) returns address
0x82e2140 frag. 0x82e2128 (size=36) on 1 -th hit 22094 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: pcscf [registration.c:1104]: ERR:P-CSCF:P_security_relay: we cannot find the
contact or its IPSec/TLS SAs for <0://172.16.8.42:2051>. 22095 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [mem/q_malloc.c:428]: qm_free(0x8272e60, 0x82e2140), called from pcscf:
registration.c: P_security_relay(1107) 22096 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [mem/q_malloc.c:450]: qm_free: freeing frag. 0x82e2128 alloc'ed from
pcscf: registration.c: P_security_relay(1086) 22097 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [mem/q_malloc.c:366]: qm_malloc(0x8272e60, 41) called from pcscf:
registration.c: get_NAT_dst_uri(921) 22098 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [mem/q_malloc.c:406]: qm_malloc(0x8272e60, 44) returns address
0x830605c frag. 0x8306044 (size=52) on 1 -th hit 22099 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: INFO: pcscf [registration.c:1031]: INFO:P-CSCF:P_NAT_relay: sip:67.154.250.3:2051 22100 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_lookup.c:1387]: DEBUG: t_newtran: msg id=77 , global msg id=76 , T on
entrance=0xffffffff 22101 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=37128, isACK=1 22102 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_lookup.c:470]: DEBUG: RFC3261 transaction matched, tid=8019.82c67232.0 22103 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_lookup.c:728]: DEBUG: t_lookup_request: transaction found (T =0xb59834b4) 22104 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_reply.c:1420]: DEBUG: cleanup_uac_timers: RETR/FR timers reset 22105 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: <core> [timer.c:595]: timer_add called on an active timer 0xb59834fc
(0xb5842c2c, 0xb5842c2c), flags 201 22106 Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: DEBUG: tm [t_funcs.c:184]: tm: put_on_wait: transaction 0xb59834b4 already on wait Mar 2 11:06:25 im1 /usr/sbin/ser[27551]: NOTICE: <script>: >> Term_Subsequent end
Kind Regards
Min Wang
.