Re: How to debug matching ACLs?
Hello Ricardo, On Fri, Jul 24, 2020 at 10:36:59AM +0200, Ricardo Fraile wrote: (...) > I think that the "set-var" way is more flexible, as you can combine it with > any other variable that helps to identify the client request. The proposed > "here" converter can helps more. OK, I'll try to think about it more. > As an idea, it would be nice if these debug modifications done over the ACLs > can be logged based on a condition, for example only with a particular > client pattern, something like: > >acl client_debug hdr_sub(User-Agent) client1-user-agent >log-format %ci,%[var(txn.last_expr)] if client_debug You cannot condition a log format versus another one, but what you can do is use an intermediary variable: acl client_debug hdr_sub(User-Agent) client1-user-agent http-request ser-var(txn.debug_expr) var(txn.last_expr) if client_debug log-format %ci,%[var(txn.debug_expr)] => your debug_expr variable will only be set if client_debug is true, otherwise it will log an empty string. Willy
Re: How to debug matching ACLs?
Hello Willy,
Following your suggestions, I've been testing the "debug" solution (in a
2.2 HAproxy) with this sample conf:
http-request use-service prometheus-exporter if { path,debug(buf0) -m
beg /metrics }
seeing from the socket the entries registered on buf0:
# echo "show events buf0" | socat stdio /var/run/haproxy.sock
<0>2020-07-24T09:24:19.598250+02:00 [debug] buf0: type=str
<0>2020-07-24T09:24:26.981110+02:00 [debug] buf0: type=str
<0>2020-07-24T09:24:34.598446+02:00 [debug] buf0: type=str
Later on, the same http condition, but now with "set-var":
http-request use-service prometheus-exporter if {
path,set-var(txn.last_expr) -m beg /metrics }
log-format %ci,%[var(txn.last_expr)]
and seeing the lines on the logs:
Jul 24 09:33:49 server1 haproxy[10291]: 192.168.1.17,/metrics
Jul 24 09:34:04 server1 haproxy[10291]: 192.168.1.17,/metrics
I think that the "set-var" way is more flexible, as you can combine it
with any other variable that helps to identify the client request. The
proposed "here" converter can helps more.
As an idea, it would be nice if these debug modifications done over the
ACLs can be logged based on a condition, for example only with a
particular client pattern, something like:
acl client_debug hdr_sub(User-Agent) client1-user-agent
log-format %ci,%[var(txn.last_expr)] if client_debug
Thanks for your detailed explanations,
Re: How to debug matching ACLs?
Hello Ricardo,
On Thu, Jul 23, 2020 at 05:52:55PM +0200, Ricardo Fraile wrote:
> Hello,
>
> On a complex configuration with multiples ACLs, is there a way to debug what
> of them are applied over a request?
Depending how you write them (and what version you are using), you may
be able to use the "debug" converter at the end of the expression to
capture the value and send it to a ring buffer that you can consult
elsewhere. You can also copy a value into a variable that you append
in the log.
> Is it possible to append the unique id of the ACLs to the line on the log?
Not really, the problem is that there isn't a single set of ACL, but a large
set which apply to many actions. I've seen configurations evaluating up to
6000 ACLs per request, it's definitely not even realistic to log anything
in such a mess. And there's no real "this use case is more common, let's
focus on it only" because there are many rulesets. In addition, anonymous
ACLs are fairly common, and sometimes more readable.
Cyril Bonté had worked on such a solution many years ago. By then we had
very few rulesets, and as we were adding new ones with many ACLs evaluated
for a single request, it quickly became difficult to exploit.
That's why I really encourage you to instead set a variable and log it.
There's even a "set-var" converter that duplicates the expression's
value into a variable. Thus for example, instead of doing :
use_backend foo if { path_beg /foo }
You could do:
use_backend foo if { path,set-var(txn.last_expr) -m beg /foo }
And log "var(txn.last_expr)" to always get the last evaluated ACL among
those you have instrumented.
This makes me think that it could be convenient to have a new converter
called "here" that, just like set-var() or debug(), passes the value and
stores the current config file's line number into a fixed variable so
that you could have it present in your logs.
You could then do something like:
use_backend foo if { path,here -m beg /foo }
If you'd place them on all final rules, you could easily detect what
rule was the one taking the final decision (redirect, deny, return,
etc). I suspect that we'd need a few sets, though (tcp-request,
http-request, tcp-response, http-response, use_backend, use-server).
But maybe in this case storing a history of the last 3-10 "here"
would help.
Note however that this would only be useful to know that a rule was
evaluated last. It doesn't guarantee that it matched, but if placed
on a final rule it will be reliable enough.
Hoping this helps, feel free to fuel the discussion with more ideas!
Willy
How to debug matching ACLs?
Hello, On a complex configuration with multiples ACLs, is there a way to debug what of them are applied over a request? Is it possible to append the unique id of the ACLs to the line on the log? Thanks,
