Hi Alex,
Thanks for sharing more insights about that. Yes, indeed hard to say why its happens
without digging into TM internals.
Does this also happens e.g. if you just create a reply with send_reply/t_reply, and not
with the auth_challenge()?
If it’s a generic issue, it might be sensible to create an issue about it to at least
document it in a structure way.
Cheers,
Henning
From: Alex Balashov <abalashov(a)evaristesys.com>
Sent: Thursday, December 15, 2022 9:03 PM
To: Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org>
Subject: [SR-Users] Re: auth_challenge() and async
One more thing, and I apologise profusely for the spam:
This is not caused by immediate re-suspension of the transaction upon successful
authorisation of new INVITE+credentials. Even if I attempt to complete the onward routing
in the same route which does the authentication, without any further TM suspend/continue,
I get the 407 retransmissions from the previous transaction, e.g.
route[RESUME] {
pv_auth_check() and the rest
$ru = "sip:asterisk-receiver:5060";
t_on_reply("MAIN_REPLY");
if(!t_relay())
t_reply("500", "Internal server error");
exit;
}
I can't say for sure what's going on, not knowing TM internals.
-- Alex
On Dec 15, 2022, at 2:40 PM, Alex Balashov
<abalashov@evaristesys.com<mailto:abalashov@evaristesys.com>> wrote:
Setting tm.wt_timer to a very low value (e.g. 200 ms) does provide a hack around this
behaviour, but it doesn't seem to me that this is the correct solution.
│AC
172.24.0.9:39777 172.24.0.7:5060 │K
──────────┬───────── ──────────┬───────── │si
19:38:44.386913 │ INVITE (SDP) │ │p:
+0.001550 │ ──────────────────────────> │ │10
19:38:44.388463 │ 100 trying -- your call is │ │0@
+0.003336 │ <────────────────────────── │ │si
19:38:44.391799 │ 407 Proxy Authentication R │ │p-
+0.000234 │ <────────────────────────── │ │pr
19:38:44.392033 │ ACK │ │ox
+0.201070 │ ──────────────────────────> │ │y-
19:38:44.593103 │ INVITE (SDP) │ │di
+0.004226 │ ──────────────────────────> │ │ge
19:38:44.597329 │ 100 trying -- your call is │ │st
+0.003063 │ <────────────────────────── │ │-a
19:38:44.600392 │ 407 Proxy Authentication R │ │ut
+0.000489 │ <────────────────────────── │ │h:
19:38:44.600881 │ ACK │ │50
│ ──────────────────────────> │ │60
│ │ │ S
The real question is why the negative ACK for the first transaction doesn't seem to be
having the intended effect in this scenario.
-- Alex
On Dec 15, 2022, at 2:21 PM, Alex Balashov
<abalashov@evaristesys.com<mailto:abalashov@evaristesys.com>> wrote:
Adding further to this, it seems to me the real problem is that I can't use
t_release() in an async resume route, because it's internally structured to take place
inside a failure_route context. If I could, I think that would rid me of the first
transaction after I send the challenge and call 'exit'.
On Dec 15, 2022, at 12:42 PM, Alex Balashov
<abalashov@evaristesys.com<mailto:abalashov@evaristesys.com>> wrote:
As a test, I tried to put the auth_challenge() in the request_route before any async
suspension, and in that case works fine.
The issue is definitely with the way auth_challenge() issued from _within_ an async resume
route (failure_route context) bears upon transaction state.
-- Alex
On Dec 15, 2022, at 12:23 PM, Alex Balashov
<abalashov@evaristesys.com<mailto:abalashov@evaristesys.com>> wrote:
Well, the difference seems pretty clear. In a scenario with an auth challenge and no
subsequent INVITE+credentials, the negative ACK is matched:
4(54) DEBUG: <core> [core/receive.c:389]: receive_msg(): --- received sip message -
request - call-id: [01eed151-4234-4518-9a0e-9b9168f21a3f] - cseq: [288439 ACK]
4(54) DEBUG: <core> [core/receive.c:261]: ksr_evrt_pre_routing(): event route
core:pre-routing not defined
4(54) DEBUG: <core> [core/receive.c:471]: receive_msg(): preparing to run routing
scripts...
4(54) DEBUG: sl [sl_funcs.c:447]: sl_filter_ACK(): too late to be a local ACK!
4(54) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Content-Length] type 12
4(54) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field():
content_length=0
4(54) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of
header
4(54) DEBUG: maxfwd [mf_funcs.c:55]: is_maxfwd_present(): max_forwards header not found!
4(54) DEBUG: siputils [checks.c:123]: has_totag(): totag found
4(54) DEBUG: rr [loose.c:108]: find_first_route(): No Route headers found
4(54) DEBUG: rr [loose.c:1006]: loose_route_mode(): There is no Route HF
4(54) DEBUG: tm [t_lookup.c:1053]: t_check_msg(): msg (0xffffa72f7088) id=14/54 global
id=13/54 T start=0
4(54) DEBUG: tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=42311,
isACK=1
4(54) DEBUG: tm [t_lookup.c:439]: matching_3261(): RFC3261 transaction matched,
tid=SG.ceb57d44-7388-4739-9a86-d44ea04d974d
4(54) DEBUG: tm [t_lookup.c:692]: t_lookup_request(): transaction found
(T=0xffffa2f428a8)
4(54) DEBUG: tm [t_lookup.c:1122]: t_check_msg(): msg (0xffffa72f7088) id=14/54 global
id=14/54 T end=0xffffa2f428a8
4(54) DEBUG: tm [t_reply.c:1763]: cleanup_uac_timers(): RETR/FR timers reset
4(54) DEBUG: tm [t_funcs.c:120]: put_on_wait(): put T [0xffffa2f428a8] on wait
4(54) DEBUG: <core> [core/timer.c:557]: timer_add_safe(): timer_add called on an
active timer 0xffffa2f42930 (0xffffa2d05d08, 0xffffa2d05d08), flags 201
4(54) DEBUG: tm [t_funcs.c:143]: put_on_wait(): transaction 0xffffa2f428a8 already on
wait
However, in a scenario with an auth challenge with subsequent INVITE+credentials, the same
negative ACK is not matched to a known transaction.
2(52) DEBUG: <core> [core/receive.c:389]: receive_msg(): --- received sip message -
request - call-id: [895a7051-3e0c-410a-88ea-4bad7a1c21b6] - cseq: [939189 ACK]
2(52) DEBUG: <core> [core/receive.c:261]: ksr_evrt_pre_routing(): event route
core:pre-routing not defined
2(52) DEBUG: <core> [core/receive.c:471]: receive_msg(): preparing to run routing
scripts...
2(52) DEBUG: sl [sl_funcs.c:447]: sl_filter_ACK(): too late to be a local ACK!
2(52) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Content-Length] type 12
2(52) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field():
content_length=0
2(52) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of
header
2(52) DEBUG: maxfwd [mf_funcs.c:55]: is_maxfwd_present(): max_forwards header not found!
2(52) DEBUG: siputils [checks.c:123]: has_totag(): totag found
2(52) DEBUG: rr [loose.c:108]: find_first_route(): No Route headers found
2(52) DEBUG: rr [loose.c:1006]: loose_route_mode(): There is no Route HF
2(52) DEBUG: tm [t_lookup.c:1053]: t_check_msg(): msg (0xffffa72f7088) id=19/52 global
id=18/52 T start=0
2(52) DEBUG: tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=21251,
isACK=1
2(52) DEBUG: tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed -
via branch [z9hG4bKSG.c52861b7-2535-4080-84f5-2819c4169843]
2(52) DEBUG: tm [t_lookup.c:675]: t_lookup_request(): no transaction found
This makes sense intuitively; the auth_challenge(), and resulting 407 challenge, should
have ended the old transaction, so the negative ACK should just be absorbed.
But in that case, why does the 407 keep being retransmitted?
-- Alex
On Dec 15, 2022, at 12:00 PM, Alex Balashov
<abalashov@evaristesys.com<mailto:abalashov@evaristesys.com>> wrote:
Hi Henning,
On Dec 15, 2022, at 11:51 AM, Henning Westerholt
<hw@gilawa.com<mailto:hw@gilawa.com>> wrote:
Hi Alex,
it might not help you much, but recently I was implementing a similar structure in one
larger migration project, and it seems to work fine.
I am not using any special flags for the challenge etc..
It’s basically like this (pseudo-code)
route{
if no auth user -> auth_challenge()
else -> http_async_query(API, AUTH)
}
route[AUTH] {
get API result for password
if API failure -> auth_challenge()
else -> pv_auth_check(..)
route(next steps)
}
Yeah, that's more or less what I've got, except the first part.
I don't auth_challenge() every request because some requests are allowed by static IP,
and I don't know whether to auth_challenge() them unless I am already in the async
resume context.
I have eliminated the independent credentials query. At this point my process is more:
request_route {
...
http_async_query(API, RESUME)
}
route[RESUME] {
if(method == "INVITE") {
if(has_auth_attrib()) {
if(!pv_auth_check(...)) {
auth_challenge("realm", "1");
exit;
}
}
# Get more routing info.
http_async_query(API, RESUME2)
return;
}
}
route[RESUME2} {
t_relay() etc
}
-- Alex
--
Alex Balashov | Principal | Evariste Systems LLC
Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free)
Web:
http://www.evaristesys.com/,
http://www.csrpswitch.com/
--
Alex Balashov | Principal | Evariste Systems LLC
Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free)
Web:
http://www.evaristesys.com/,
http://www.csrpswitch.com/
--
Alex Balashov | Principal | Evariste Systems LLC
Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free)
Web:
http://www.evaristesys.com/,
http://www.csrpswitch.com/
--
Alex Balashov | Principal | Evariste Systems LLC
Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free)
Web:
http://www.evaristesys.com/,
http://www.csrpswitch.com/
--
Alex Balashov | Principal | Evariste Systems LLC
Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free)
Web:
http://www.evaristesys.com/,
http://www.csrpswitch.com/
--
Alex Balashov | Principal | Evariste Systems LLC
Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free)
Web:
http://www.evaristesys.com/,
http://www.csrpswitch.com/