Mercurial > prosody-modules
changeset 6538:de1f17ed4dac
mod_firewall: Add support for tracing rule evaluation in real-time
| author | Matthew Wild <mwild1@gmail.com> |
|---|---|
| date | Mon, 11 May 2026 13:37:19 +0100 |
| parents | 9bc83fba89ac |
| children | 4d7e2d0db2ab |
| files | mod_firewall/README.md mod_firewall/actions.lib.lua mod_firewall/mod_firewall.lua mod_firewall/trace.lib.lua |
| diffstat | 4 files changed, 187 insertions(+), 2 deletions(-) [+] |
line wrap: on
line diff
--- a/mod_firewall/README.md Mon May 11 13:18:45 2026 +0100 +++ b/mod_firewall/README.md Mon May 11 13:37:19 2026 +0100 @@ -842,3 +842,73 @@ Example to limit stanzas per session type: LIMIT: normal on $(session.type) + +### Tracing + +mod_firewall has tracing functionality, to help with debugging scripts and +rules. + +To enable tracing for a script, add at the top: + +``` +@@ trace = on +``` + +All chains defined in the script will then have tracing activated. Note that +this has a small performance impact (in processing and in memory allocations), +even when the tracing functionality is not actively being used. + +You need to reload mod_firewall after enabling tracing in a script, so it will +pick up the change and recompile the rules. + +When tracing is enabled, you can trace all evaluations by running: + +``` +prosodyctl shell firewall trace HOST +``` + +Replace HOST with the name of the host/component you want to trace (obviously +mod_firewall must be loaded on that host). + +What is a trace? When tracing is enabled, a trace is generated each time a +chain runs an evaluation of a stanza. The trace records the script name, chain +name, the stanza that was being evaluated, and which rules/conditions matched. +This information is then sent to any active 'trace' commands. If no commands +are active, traces are discarded. + +Note that traces are per-chain and only printed when they are complete. This +can result in unintuitive ordering of the output when multiple chains are +invoked during processing of a stanza. Results of traces from "inner" chains +will be displayed before traces from an "outer" chain. + +#### Tagging traces + +Sometimes you only need to trace a subset of evaluations. To do this, you can +use the `TAG TRACE` action. This will apply a tag to the trace of the current +evaluation. + +For example, if you only want to trace stanzas sent to a specific JID: + +``` +TO: user@example.com +TAG TRACE=interesting +``` + +Then you can filter for this tag when you watch traces: + +``` +prosodyctl shell firewall trace --tag=interesting HOST +``` + +You can filter by the special tag name `untagged` to only show traces which +have not been tagged. + +Notes on trace tagging: + +- Traces are per chain, however tags will propagate through to future chains + which execute on the same event. This allows easily tracing a stanza through + multiple chains, for example. +- A trace may only have one tag. If `TAG TRACE` is used multiple times, it + will overwrite the tag for the current trace and any future chains which run + on this event/stanza. Chains (other than the current one) which already + began evaluation won't use the new tag.
--- a/mod_firewall/actions.lib.lua Mon May 11 13:18:45 2026 +0100 +++ b/mod_firewall/actions.lib.lua Mon May 11 13:37:19 2026 +0100 @@ -277,4 +277,8 @@ return code:format(where, reason, text), { "core_post_stanza", "current_host", "st", "new_short_id" }; end +function action_handlers.TAG_TRACE(tag_name) + return ("if trace_record then trace_record.tag, event.firewall_trace_tag = %q, %q end"):format(tag_name, tag_name), { "trace" }; +end + return action_handlers;
--- a/mod_firewall/mod_firewall.lua Mon May 11 13:18:45 2026 +0100 +++ b/mod_firewall/mod_firewall.lua Mon May 11 13:37:19 2026 +0100 @@ -328,7 +328,7 @@ }; trace = { - global_code = [[local trace_init = module:require("trace").init;]]; + global_code = [[local trace_init = module.environment.trace.init;]]; }; }; @@ -382,6 +382,15 @@ local condition_handlers = module:require("conditions"); local action_handlers = module:require("actions"); +module.environment.trace = module:require("trace"); + +local metadata_field_handlers = { + trace = function (v) + v = v:lower(); + return v == "on" or v == "true"; + end; +}; + if module:get_option_boolean("firewall_experimental_user_marks", true) then module:require"marks"; end @@ -450,6 +459,10 @@ if not k then return nil, errmsg("Unable to parse metadata assignment (expected '@@ key = value')"); end + local handler = metadata_field_handlers[k]; + if handler then + v = handler(v); + end metadata[k] = v; elseif not(state) and line:sub(1,1) == "%" then -- Definition (zone, limit, etc.) local what, name = line:match("^%%%s*([%w_]+) +([^ :]+)"); @@ -566,7 +579,7 @@ if metadata.trace then include_dep("trace", code); - table.insert(code, ("local trace = trace_init(%q, %q);"):format(metadata.filename, chain_name)) + table.insert(code, ("local trace_record <close>, trace = trace_init(%q, %q, stanza, event.firewall_trace_tag, source_rules);"):format(metadata.filename, chain_name)) end local condition_cache, n_conditions = {}, 0; @@ -611,6 +624,9 @@ ..table.concat(rule.actions, "\n\t\t\t") .."\n\t\tend\n"; else + if metadata.trace then + table.insert(rule.actions, 2, ("trace(%d, nil, true)"):format(rule_n)); + end rule_code = table.concat(rule.actions, "\n\t\t"); end table.insert(code, rule_code); @@ -676,6 +692,8 @@ function load_script(script) script = resolve_script_path(script); + local base_name = script:match("[^/]+$"); + local last_modified = (lfs.attributes(script) or {}).modification or os.time(); if loaded_scripts[script] then if loaded_scripts[script].last_modified == last_modified then
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/mod_firewall/trace.lib.lua Mon May 11 13:37:19 2026 +0100 @@ -0,0 +1,93 @@ +local async = require "prosody.util.async"; + +local tracers = {}; + +local trace_mt = { + __close = function (t) + for session, options in pairs(tracers) do + if not options.tag or options.tag == (t.tag or "untagged") then + session.print(("\n## Evaluating [%s::%s] (%s)"):format(t.filename, t.chain, t.tag or "untagged")); + local stanza_log = options.stanzas; + if stanza_log == "full" then + session.print(t.stanza); + elseif not stanza_log or stanza_log == "header" then + session.print(t.stanza:top_tag()); + end + + for rule_n, rule_trace in ipairs(t.rules) do + local source = t.source[rule_n].source; + for cond_n, matched in ipairs(rule_trace) do + session.print( + ("%s %s"):format( + matched and "✔" or "✖", + source.conditions[cond_n] or ("Rule %d condition %d"):format(rule_n, cond_n) + ) + ); + end + if rule_trace.matched then + for _, action in ipairs(source.actions) do + session.print("➜ "..action); + end + end + end + end + end + end; +}; + +local function init(filename, chain_name, stanza, tag, source_rules) + local rule_trace = {}; + local trace = setmetatable({ + filename = filename; + chain = chain_name; + rules = rule_trace; + stanza = stanza; + tag = tag; + source = source_rules; + }, trace_mt); + return trace, function (rule_n, cond_n, result) + local rule = rule_trace[rule_n]; + if not rule then + rule = {}; + rule_trace[rule_n] = rule; + end + + if cond_n then + rule[cond_n] = result; + return result; + else + -- Rule finished + rule.matched = result; + end + end; +end + + +module:add_item("shell-command", { + section = "firewall"; + section_desc = "mod_firewall commands"; + name = "trace"; + desc = "Trace executions"; + args = { + { name = "host", type = "string" }; + }; + host_selector = "host"; + flags = { + short_params = { t = "tag" }; + value_params = { tag = true, stanzas = true }; + }; + handler = function(self, host, opts) --luacheck: ignore 212/self 212/host + self.session.print("# Tracing mod_firewall on "..host); + tracers[self.session] = opts or {}; + + while self.session.is_connected() do + async.sleep(3); + end + + tracers[self.session] = nil; + return true; + end; +}); + + +return { init = init };
