Files
smallwebwaf/docs/request-log.md
T
clawbot d7c62f2854
check / check (push) Failing after 3m48s
Say which bytes the byte limits count, and what passing one does (closes #203)
sneak asked for every document to be audited for sentences that do not say what they mean. The byte limits now say which bytes count (response bodies, request bodies or both, as `SWW_BYTES_COUNT` says, WebSocket traffic included) and what passing one does. Other unclear or false sentences in `README.md`, `SPEC.md`, `EVALUATION.md` and `docs/` are rewritten.

Documents only. `REPO_POLICIES.md` is shared policy text and stayed out.

Model: fable-5-1 (first audit); opus-5-5 (rework)
2026-11-09 04:03:17 +01:00

242 lines
11 KiB
Markdown

# The request log's fields
The fields of the JSON objects `rproxy` and `discriminator` write about each
request. "Request log" and "The log" in [`SPEC.md`](../SPEC.md) say when a line
is written and how the log is sent to a syslog server. A field that does not
apply to a request is left out.
## `discriminator`'s lines
`sww discriminator` writes two lines for each question it answers, joined by
`request_id`. The field `discriminator_line` says which of the two a line is:
- `decision`: the line it writes once it has answered the question;
- `report`: the line it writes when `rproxy`'s report comes, with everything
known. The repetition is intended.
A request to its own endpoints writes one line, without `discriminator_line`. A
report writes no line but the `report` line of the request it names.
These questions write no line:
- a question refused with `400` (see "The question" under "`discriminator`" in
[`SPEC.md`](../SPEC.md));
- a question whose body stopped arriving, which gets no answer.
A `report` line:
```
{"type":"request","discriminator_line":"report","time":"2026-10-03T12:00:00.123Z","instance":"fsn1/discriminator","client_ip":"203.0.113.9","method":"GET","scheme":"https","host":"app.example","path":"/","query":"","protocol":"HTTP/1.1","status":200,"request_bytes":0,"response_bytes":5120,"referer":"","user_agent":"curl/8.9.1","request_id":"7Q2NHZ4KJ3VXW5YB6R3MEFTD2A","peer_ip":"172.18.0.2","forwarded_for":"203.0.113.9","client_group":"203.0.113.9/32","asn":"AS64496","as_name":"Example Net","country":"DE","request_headers":{"accept":"*/*"},"action":"forward","counts":{"minute":1,"hour":12,"day":40,"minute_bytes":5120,"hour_bytes":61440,"day_bytes":204800},"waf_score":0,"duration_total":3.217,"duration_checks":0.041,"duration_waf":0.029,"duration_upstream_total":3.104}
```
### Every line
Every one of these lines has:
- `type`: `request` (the process's own messages have `process`);
- the standard web log fields;
- `request_id`, `peer_ip` and `client_group`;
- `asn`, `as_name` and `country`;
- `action` and `duration_total`.
### Standard web log fields
- `time`: when `discriminator` had read the question's body, RFC 3339 with
milliseconds, in UTC. The `report` line gives the same time as the `decision`
line.
- `instance`: `SWW_INSTANCE_NAME`.
- `client_ip`: the visitor's address, as `rproxy` worked it out.
- `method`, `path` and `query`: the visitor's request.
- `scheme`: how the visitor reached `rproxy` or the trusted proxy in front of
it.
- `host`: the site the visitor asked for.
- `protocol`: the question's own, `HTTP/1.1`.
- `status`:
- on the `decision` line, what `discriminator` answered: `200` for `allow`,
the status of `deny`, or `0` for `close`, as the visitor is then sent
nothing;
- on the `report` line, what the visitor got, `0` if nothing.
- `request_bytes`:
- on the `decision` line, how much of the question's body the Core Rule Set
read;
- on the `report` line, the bytes of the visitor's body that `rproxy` read,
with what a WebSocket carried from the visitor.
- `response_bytes`:
- on the `decision` line, the body of `discriminator`'s answer;
- on the `report` line, the bytes of the answer's body, with what a
WebSocket carried from the app.
- `referer` and `user_agent`.
### Request detail
- `request_id`: the id `rproxy` made for the request when it arrived.
- `peer_ip`: the address of `rproxy`'s TCP peer, normally traefik.
- `forwarded_for`: the `X-Forwarded-For` header the visitor's request came with.
- `client_group`: the client as rate limiting counts it, an IPv4 address as a
/32 or an IPv6 group.
- `asn`, `as_name` and `country`: the client's, as looked up. Each is empty
when:
- lookups are off;
- the client is not looked up;
- the source cannot place the client;
- GeoJS had not answered by the time `discriminator` answered.
- `content_type`: the visitor's `Content-Type`.
- `content_length`: the body length the visitor announced.
- `request_headers`: the headers listed in `SWW_LOG_REQUEST_HEADERS`, by name in
lower case.
- `has_authorization` and `has_cookie`: true when the request had those headers.
Their values are never logged.
### Response detail
- `response_content_type`: the type of `discriminator`'s own answer.
- `aborted`: true when `rproxy` went away before the answer.
### Decision
- `action`: what was done:
- `forward`: answered `allow`, so that `rproxy` passes it to the app;
- `denied`: refused for `SWW_DENY_NETS`, for a reputation source with the
action `deny`, or for a tag in `SWW_TAG_DENY`;
- `banned`: refused under a ban, or for a `ban` rule, a trap path or a
CrowdSec decision, each of which bans the client;
- `country_denied`, `rate_limited`, `rule_blocked` and `waf_blocked`:
refused by that check;
- `too_large`: over a header limit;
- `admin`: answered at one of `discriminator`'s own endpoints, or `404` for
a path under `/_sww/`.
- `would_action`: in `observe` mode, what `enforce` mode would have done with a
request it would have refused. `action` then names what was done, normally
`forward`.
- `heuristic`: the heuristic that refused the request, in `observe` mode too. It
is left out when none did.
- `heuristic_figures`: an object of the figures that heuristic acted on. Each
heuristic and its figures:
- `deny_nets`: `netblock`, the entry of `SWW_DENY_NETS` the client is in;
- `active_ban`: `netblock`, the ban's netblock, and `ban_expires`;
- `countries`: `country`, and `setting`, the country list that refused it;
- `tag_deny`: `tag`, the tag of `SWW_TAG_DENY` the request carries;
- `blocklists`: `lists`, the blocklist URLs that list the client;
- `crowdsec`: `scenario`, the decision's scenario, and `expires`, when the
decision ends;
- `dnsbl`: `zones`, the DNS blocklist zones that list the client, their keys
masked;
- `abuseipdb`: `score`, and `min_score`, `SWW_ABUSEIPDB_MIN_SCORE`;
- `rate_limits`: `window`, `count` and `limit`;
- `trap_paths`: `path`, the trap path asked for;
- `rule_files`: `rule_id` and `rule_action`, of the rule that refused it;
- `header_limits`: `fields`, `fields_limit`, `cookies` and `cookies_limit`;
- `core_rule_set`: `score`, and `threshold`, `SWW_WAF_ANOMALY_THRESHOLD`;
- `refusal_limit`: `window`, `count` and `limit`, of the error burst;
- `byte_limits`: `window`, `count` and `limit`, the count in bytes.
- `after_answer_heuristic`: the heuristic that banned the client after
`discriminator` answered the request, in `observe` mode too: `refusal_limit`
or `byte_limits`.
- `after_answer_heuristic_figures`: an object of the figures that heuristic
acted on, as listed above.
`byte_limits` bans when the report comes, so only the `report` line names
it.
- `limit_percent` and `limit_percent_setting`: the client's percentage of the
rate limits and the setting that lowered it, when one did. `bytes_percent` and
`bytes_percent_setting` do the same for the byte limits.
- `counts`: the client's totals as rate limiting counts them, this request
included. It is left out when rate limiting did not count the request. It
holds:
- `minute`, `hour` and `day`: requests;
- `minute_bytes`, `hour_bytes` and `day_bytes`: the body bytes
`SWW_BYTES_COUNT` names, in that window.
A count can have a fraction (see "Counting method" in
[`SPEC.md`](../SPEC.md)). The bytes counted for an allowed request and its
response are added when its report comes. So on the `decision` line, the
three byte totals leave them out.
- `limit_hit`: the limit broken:
- `minute`, `hour` or `day` for a rate limit;
- `minute_bytes`, `hour_bytes` or `day_bytes` for a byte limit;
- `error_burst`.
When the bytes counted for a request and its response break a limit, the
request has been passed on whole, so its `action` stays `forward`. Only its
`report` line gives that limit.
- `rule_ids`: the rule file rules that matched, in order, up to the one that
refused.
- `waf_score` and `waf_rule_ids`: the Core Rule Set's score and the rules that
matched, for a request it inspected.
- `reputation`: the sources the client is on, in this order:
- blocklist URLs;
- the CrowdSec decision list's URL;
- DNS blocklist zones;
- `abuseipdb`.
- `tags`: the request's tags, sorted, left out when it has none. Each tag and
where it comes from is under "Request tags" in [`SPEC.md`](../SPEC.md).
- `offence`: `limit`, for a request that broke a limit.
- `ban_expires`: when the client's ban ends, for a request that made one or was
refused under one: a time, or `permanent`.
### Timings
All in milliseconds:
- `duration_total`:
- on the `decision` line, from `discriminator` having read the question's
body to the line;
- on the `report` line, from `rproxy` having read the request's headers to
the end of the answer.
- `duration_checks`: to the end of the checks;
- `duration_waf`: the part of that the Core Rule Set took;
- `duration_upstream_total`: on the `report` line of an allowed request, from
the hand-over to the app to the end of the answer.
### Requests to its own endpoints
The line of a request to `discriminator`'s own endpoints has these fields, with
these meanings where they differ:
- `client_ip` and `peer_ip`: the request's TCP peer.
- `request_id`: a new random one of 26 letters and digits.
- `scheme`: `http`.
- `time`: when the request's headers had been read.
- `request_bytes`: the bytes read of a ban to add, and otherwise `0`.
- `action`: `admin`.
- `duration_total`: from the request's headers being read to the line.
## `rproxy`'s line
`sww rproxy` writes one short line for each request. `request_id` joins it to
`discriminator`'s two. It has these fields and no others:
- `type`: `request`.
- `time`: when the request arrived, RFC 3339 with milliseconds, in UTC.
- `request_id`: the id `rproxy` made for the request when it arrived.
- `client_ip`: the visitor's address.
- `host` and `method`.
- `path` and `query`: as the visitor sent them.
- `status`: what the visitor got, `0` if nothing.
- `request_bytes`: the bytes of the visitor's body that `rproxy` read, with what
a WebSocket carried from the visitor.
- `response_bytes`: the bytes of the answer's body, with what a WebSocket
carried from the app.
- `duration_request`: milliseconds from the request's headers being read until
the app had been sent the whole request, or the answer started if that was
sooner. It includes the wait for `discriminator`.
- `duration_response`: milliseconds from then until the end of the answer.
- `disposition`: what was done with the request: `allow`, `deny` or `close`. It
is `discriminator`'s answer, or the value of `SWRP_DEFAULT_DISPOSITION`. It is
left out when:
- `discriminator` was not asked, as for the health check;
- the visitor went away while `discriminator` was being asked;
- `discriminator`'s answer had no valid `X-Sww-Disposition`;
- `rproxy` could not pass on `discriminator`'s answer, and answered `502`.
- `default_disposition`: `true` when `SWRP_DEFAULT_DISPOSITION` gave
`disposition`, and otherwise left out.
For example:
```
{"type":"request","time":"2026-10-03T12:00:00.123Z","request_id":"7Q2NHZ4KJ3VXW5YB6R3MEFTD2A","client_ip":"203.0.113.9","host":"app.example","method":"GET","path":"/","query":"","status":200,"request_bytes":0,"response_bytes":5120,"duration_request":1.204,"duration_response":3.104,"disposition":"allow"}
```