[Users] problem accounting of ACKs
Klaus Darilion
klaus.mailinglists at pernau.at
Tue Jan 3 19:49:08 CET 2006
Hi!
I have problems accounting ACK (e2e ACKs after INVITE-200 Ok). I have
the following setup:
client1 proxy1 proxy2 proxy3 client2
|---INVITE--->| | | |
| rewritehostport | | |
| t_relay | | |
| |--INVITE->| | |
| | enum_lookup | |
| | t_relay | |
| | |-INVITE-->| |
| | | lookup() |
| | | t_relay |
| | | |-----INVITE->|
| | | | |
| | | |<----200 OK--|
| | |<--200 OK-| |
| |<--200 OK-| | |
| <--200 OK---| | | |
| | | | |
| ---ACK----> | | | |
| loose_route | | |
| |----ACK-> | | |
| | loose_route | |
| | |---ACK--->| |
| | | loose_route |
| | | |---ACK------>|
| | | | |
All proxies do accounting. I do see the INVITE and BYE requests
accountend by all proxies, but the ACK is only accounted by proxy1. All
proxies are configured nearly identical:
# accounting parameters
modparam("acc", "early_media", 1)
modparam("acc", "report_ack", 1)
modparam("acc", "report_cancels", 0)
modparam("acc", "multi_leg_enabled", 0)
modparam("acc", "failed_transaction_flag", 4) # radius, syslog and DB
modparam("acc", "log_flag", 1) # syslog
modparam("acc", "db_flag", 2) # DB
modparam("acc", "db_missed_flag", 3) # DB missed calles table
modparam("acc", "swap_direction", 1)
and all the flags are set for sure:
route{
setflag(1);setflag(2);
setflag(3);setflag(4);
Does somebody had a similar problem? Are there any known issues how ACKs
are handled? Studying the debug log. it looks like proxy 1 identifies
the ACK as belonging to a transaction, whereas proxy 2 does not find the
transaction (full debug at the end of the mail):
proxy 1:
-----------
t_lookup_request: start searching: hash=6242, isACK=1
parse_headers: flags=38
DEBUG: t_lookup_request: e2e proxy ACK found
parse_headers: flags=8
DEBUG: totag for e2e ACK found: 0
DBG: trans=0x406b1940, callback type 4, id 0 entered
parse_headers: flags=258
ACC: request acknowledged: method=ACK, i-uri=sip:user201 at .....
proxy 2:
-----------
t_lookup_request: start searching: hash=6242, isACK=1
DEBUG: proceeding to pre-RFC3261 transaction matching
DEBUG: t_lookup_request: no transaction found
DEBUG:tm:t_relay: forwarding ACK statelessly
DEBUG: mk_proxy: doing DNS lookup...
parse_headers: flags=1000
check_via_address(10.10.0.41, 10.10.0.41, 0)
Sending: ACK sip:user201 at 10.10.1.50:8737 SIP/2.0^M To: <sip:+43201 at proxy1
Thus, why is there a matching transaction in proxy 1, but not in proxy 2?
Why are ACKs not accounting in every case?
Thanks
Klaus
proxy 1 (full debug):
-------------------
SIP Request:
method: <ACK>
uri: <sip:user201 at 10.10.1.50:8737>
version: <SIP/2.0>
parse_headers: flags=2
DEBUG: add_param: tag=2b4e3b2d
DEBUG:parse_to:end of header reached, state=29
DEBUG: get_hdr_field: <To> [52]; uri=[sip:+43201 at proxy1.ienum.labs.nic.at]
DEBUG: to body [<sip:+43201 at proxy1.ienum.labs.nic.at>]
Found param type 232, <branch> = <z9hG4bK-d87543-685643142-1--d87543->;
state=6
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: add_param: tag=f937ab7a
DEBUG:parse_to:end of header reached, state=29
xl_printf: final buffer length 186
parse_headers: flags=100
get_hdr_field: cseq <CSeq>: <2> <ACK>
DEBUG:maxfwd:is_maxfwd_present: value = 70
parse_headers: flags=200
is_preloaded: No
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5060 matches port 8737
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5060 matches port 8737
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5061 matches port 8737
check_self: host != me
grep_sock_info - checking if host==us: 10==10 && [10.10.0.41] ==
[10.10.0.41]
grep_sock_info - checking if port 5060 matches port 5060
after_loose: Topmost route URI: 'sip:10.10.0.41;lr;ftag=f937ab7a' is me
after_loose: URI to be processed:
'sip:10.10.0.41:5062;r2=on;ftag=f937ab7a;lr=on'
after_loose: Next URI is a loose router
parse_headers: flags=ffffffffffffffff
DEBUG: get_hdr_body : content_length=0
found end of header
DEBUG: t_newtran: msg id=2 , global msg id=0 , T on entrance=0xffffffff
parse_headers: flags=ffffffffffffffff
parse_headers: flags=78
t_lookup_request: start searching: hash=6242, isACK=1
parse_headers: flags=38
DEBUG: t_lookup_request: e2e proxy ACK found
parse_headers: flags=8
DEBUG: totag for e2e ACK found: 0
DBG: trans=0x406b1940, callback type 4, id 0 entered
parse_headers: flags=258
ACC: request acknowledged: method=ACK,
i-uri=sip:user201 at 10.10.1.50:8737, o-uri=sip:user201 at 10.10.1.50:8737,
call_id=9c5e0930eb2b8e5a,
from="user101"<sip:user101 at proxy1.ienum.labs.nic.at>;tag=f937ab7a, code=200
parse_headers: flags=258
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5060 matches port 8737
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5060 matches port 8737
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5061 matches port 8737
check_self: host != me
Route ftag and From tag are same
DEBUG:tm:t_relay: forwarding ACK statelessly
DEBUG: mk_proxy: doing DNS lookup...
check_via_address(10.10.1.51, 10.10.1.51, 0)
Sending: ACK sip:user201 at 10.10.1.50:8737 SIP/2.0^M To: <sip:+43201 at proxy1
proxy 2 (full debug):
-------------------
SIP Request:
method: <ACK>
uri: <sip:user201 at 10.10.1.50:8737>
version: <SIP/2.0>
parse_headers: flags=2
DEBUG: add_param: tag=2b4e3b2d
DEBUG:parse_to:end of header reached, state=29
DEBUG: get_hdr_field: <To> [52]; uri=[sip:+43201 at proxy1.ienum.labs.nic.at]
DEBUG: to body [<sip:+43201 at proxy1.ienum.labs.nic.at>]
Found param type 232, <branch> = <0>; state=16
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: add_param: tag=f937ab7a
DEBUG:parse_to:end of header reached, state=29
xl_printf: final buffer length 186
parse_headers: flags=100
Found param type 232, <branch> = <z9hG4bK-d87543-685643142-1--d87543->;
state=6
Found param type 235, <rport> = <6477>; state=16
end of header reached, state=5
parse_headers: Via found, flags=100
parse_headers: this is the second via
get_hdr_field: cseq <CSeq>: <2> <ACK>
DEBUG:maxfwd:is_maxfwd_present: value = 69
parse_headers: flags=200
is_preloaded: No
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5062 matches port 8737
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5062 matches port 8737
grep_sock_info - checking if host==us: 10==10 && [10.10.1.50] ==
[10.10.0.41]
grep_sock_info - checking if port 5063 matches port 8737
check_self: host != me
grep_sock_info - checking if host==us: 10==10 && [10.10.0.41] ==
[10.10.0.41]
grep_sock_info - checking if port 5062 matches port 5062
after_loose: Topmost route URI:
'sip:10.10.0.41:5062;r2=on;ftag=f937ab7a;lr=on' is me
grep_sock_info - checking if host==us: 10==10 && [10.10.0.41] ==
[10.10.0.41]
grep_sock_info - checking if port 5063 matches port 5063
after_loose: URI to be processed:
'sip:10.10.0.42:5063;transport=tls;r2=on;ftag=f937ab7a;lr=on'
after_loose: Next URI is a loose router
DEBUG: has_totag: totag found
parse_headers: flags=ffffffffffffffff
DEBUG: get_hdr_body : content_length=0
found end of header
DEBUG: t_newtran: msg id=1 , global msg id=0 , T on entrance=0xffffffff
parse_headers: flags=ffffffffffffffff
parse_headers: flags=78
t_lookup_request: start searching: hash=6242, isACK=1
DEBUG: proceeding to pre-RFC3261 transaction matching
DEBUG: t_lookup_request: no transaction found
DEBUG:tm:t_relay: forwarding ACK statelessly
DEBUG: mk_proxy: doing DNS lookup...
parse_headers: flags=1000
check_via_address(10.10.0.41, 10.10.0.41, 0)
Sending: ACK sip:user201 at 10.10.1.50:8737 SIP/2.0^M To: <sip:+43201 at proxy1
More information about the Users
mailing list