Compare commits

3 Commits

Author SHA1 Message Date
clawbot
376ec2de92 Run all linting in Docker via Dockerfile.lint (closes #109)
All checks were successful
check / check (push) Successful in 2m47s
golangci-lint no longer runs on the host. script/lint builds
Dockerfile.lint, which copies the repo into the digest-pinned
golangci-lint image and lints as a build step, so a successful build is
a clean lint. The host binary shared one cache and one lock with every
other checkout on the machine, which produced findings attributed to
unrelated worktrees as well as unearned passes.

Three properties the wrapper has to get right:

- --no-cache-filter=lint forces the lint stage to re-execute. Without
  it an unchanged tree replays the layer and the build exits 0 in under
  a second having linted nothing. The deps stage stays cacheable.
- docker silently ignores --no-cache-filter when the stage name does
  not match, so the flag alone is a convention, not a guarantee: a
  rename or a typo restores the cached false green with no warning.
  script/lint therefore tees the build output and fails unless
  golangci-lint's own summary line ("N issues." / "N issues:") appears
  in it. No summary, no lint, whatever the exit code says.
- Both lint steps use RUN --network=none. golangci-lint config verify
  is documented as fetching its JSON schema over HTTPS; the pinned
  image resolves it with no network, and --network=none enforces that
  rather than trusting it. Verify is kept because golangci-lint run
  silently ignores config keys it does not recognize.

The main Dockerfile's lint stage now invokes golangci-lint directly
instead of `make lint`, which would otherwise need a docker daemon
inside the build.

golangci-lint installation is removed from script/bootstrap. Its curl
guard and its script/fetch-assets call are untouched.
2026-08-17 22:46:19 +00:00
5888d14438 Bound the access log line against client-chosen text (closes #146)
All checks were successful
check / check (push) Successful in 2m45s
The access log wrote one INFO line per request carrying the full
attacker-controlled URL, on the unauthenticated public receiver, so a
client inventing paths wrote unbounded arbitrary text into the
operator's logs.

Rejected requests now log the chi route pattern instead of the concrete
URL — extended to 3xx as well as 4xx, because RequireAuth answers 303
and so /user/<anything> was an unauthenticated path-varying vector. The
query is redacted on the branches that keep a concrete path, and every
client-supplied field is capped: url, useragent and referer at 512
bytes, request_id at 128, method at 32. The caps are spent in ENCODED
bytes, so escaping cannot multiply them.

One INFO line per request, at most 2,560 bytes — a figure derived
arithmetically rather than observed, with the fixed portion measured at
336 (JSON) and 286 (text).

Independently reviewed four times, and broken three of those times on
the same class of defect: a stated bound the code did not have. Round 1
left the 2xx query and the headers unbounded; round 2 counted raw bytes
against an encoded ceiling and broke at 2,611; round 3 charged 6 bytes
for every non-printable when strconv.Quote spells astral ones as
\UXXXXXXXX, and broke at 2,676. Two independent exhaustive audits over
all 1,112,064 code points, built by different methods, now both report
zero undercharged runes on either handler. Measured worst case over a
real TCP socket is 1,972 bytes, 77% of the ceiling.

Follow-up filed to assert that charge against every code point in the
suite, so the ceiling defends itself rather than resting on one
hand-picked rune.
2026-08-18 00:32:29 +02:00
7702f38168 Mark superseded commits honestly instead of skipped (closes #152)
Some checks failed
check / check (push) Superseded by a newer commit; never tested
Gitea records a cancelled run as failure, and the #119 repair rewrote
that to skipped. Gitea's Combine() folds skipped into success, so a
commit nothing ever tested reported a combined green — observed on three
commits on next, including the very change a prior integration review
had failed a PR for.

Superseded commits are now marked failure with an honest description, so
never-tested no longer reads as passed and git bisect archaeology can
tell "passed", "failed" and "never ran" apart. Option 1, re-running the
superseded commit, was verified unreachable for automation on Gitea
1.25.4: no rerun endpoint, dispatches takes a ref not a SHA and lands
under a different context, and CancelPreviousJobs is unconditional.

The rewrite moves out of the workflow into script/ci-mark-superseded so
the tested artifact is the shipped one, and every failure path in it is
loud: an unparseable or empty ANCESTOR_LIMIT, an unreadable ancestor
status, and a shallow clone all abort rather than exiting 0 having
marked nothing. Each has a regression test. The status context is
derived rather than hardcoded, which also closes #147 item 2; item 1
remains open.

Independently reviewed four times. The final reviewer confirmed the
shallow-clone test is genuinely shallow — a file:// URL is load-bearing,
since git silently ignores --depth on a local path — and that deleting
the guard fails that one test out of 331 and cannot pass for the wrong
reason. They also reproduced deterministically that go test's cache
serves a stale PASS after a script-only edit, which internal/ciscript's
doc.go now records.
2026-08-18 00:31:55 +02:00
10 changed files with 1750 additions and 48 deletions

View File

@@ -13,39 +13,19 @@ jobs:
uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2 2024-10-23 uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2 2024-10-23
with: with:
# The fingerprint step below needs history to find the last commit # The fingerprint step below needs history to find the last commit
# that touched the Docker build context. # that touched the Docker build context, and the superseded-status
# step needs it to walk ancestors (it aborts on a shallow clone).
fetch-depth: 0 fetch-depth: 0
- name: Neutralize superseded run statuses - name: Mark superseded run statuses
# Gitea cancels the in-flight run when another commit is pushed to the # Gitea cancels the in-flight run when another commit is pushed to the
# same branch and records the cancellation as `failure`, so a commit # same branch and records the cancellation as `failure`, so a commit
# that was never tested reads red. The cancellation is unconditional # that was never tested reads as a test result. The script rewrites
# server-side for push events and cannot be disabled from a workflow # those statuses to say what happened. See its header for why the
# file, so the superseding run rewrites those statuses to `skipped`. # state stays `failure` and not `skipped`.
# Only the exact cancellation status is touched; a real failure is
# left alone.
env: env:
GITEA_TOKEN: ${{ secrets.GITEA_TOKEN }} GITEA_TOKEN: ${{ secrets.GITEA_TOKEN }}
run: | run: script/ci-mark-superseded
set -eu
api="${GITHUB_API_URL}/repos/${GITHUB_REPOSITORY}"
ctx='check / check (push)'
for sha in $(git rev-list --max-count=20 "${GITHUB_SHA}^" || true); do
latest="$(curl -sf "${api}/commits/${sha}/status" | jq -r \
--arg c "$ctx" \
'[.statuses[] | select(.context == $c)][0] // empty
| "\(.status)|\(.description)"')" || continue
[ "$latest" = 'failure|Has been cancelled' ] || continue
curl -sf -X POST "${api}/statuses/${sha}" \
-H "Authorization: token ${GITEA_TOKEN}" \
-H 'Content-Type: application/json' \
-d "$(jq -nc --arg c "$ctx" '{
context: $c,
state: "skipped",
description: "Superseded by a newer commit; never tested"
}')" >/dev/null
echo "neutralized superseded status on ${sha}"
done
- name: Fingerprint the build context - name: Fingerprint the build context
# `.dockerignore` keeps docs out of the build context, so a docs-only # `.dockerignore` keeps docs out of the build context, so a docs-only

View File

@@ -37,7 +37,9 @@ FROM golang:1.26.1-bookworm@sha256:4465644228bc2857a954b092167e12aa59c006a349228
# Depend on lint stage passing # Depend on lint stage passing
COPY --from=lint /src/go.sum /dev/null COPY --from=lint /src/go.sum /dev/null
RUN apt-get update && apt-get install -y --no-install-recommends make curl ca-certificates && rm -rf /var/lib/apt/lists/* # jq is a runtime dependency of script/ci-mark-superseded, which the test
# suite executes.
RUN apt-get update && apt-get install -y --no-install-recommends make curl ca-certificates jq && rm -rf /var/lib/apt/lists/*
WORKDIR /build WORKDIR /build

120
README.md
View File

@@ -284,6 +284,8 @@ are inline commands with no script behind them. We provide:
- `script/docker` — build the Docker image tagged via `script/projectname` - `script/docker` — build the Docker image tagged via `script/projectname`
- `script/cibuild` — CI entrypoint: `docker build .` (the Dockerfile - `script/cibuild` — CI entrypoint: `docker build .` (the Dockerfile
runs the checks, so a green build implies a green repo) runs the checks, so a green build implies a green repo)
- `script/ci-mark-superseded` — CI helper: mark the commits whose run a
newer push cancelled (see [CI gate honesty](#ci-gate-honesty))
- `script/precommit` — pre-commit checks (`go mod tidy` guard, then - `script/precommit` — pre-commit checks (`go mod tidy` guard, then
`script/check`) `script/check`)
- `script/install-precommit` — install the git pre-commit hook that - `script/install-precommit` — install the git pre-commit hook that
@@ -996,8 +998,70 @@ requests and has the rest of its aggregate budget rejected there, so
the aggregate limit is what bounds those `WARN` lines — to under ten the aggregate limit is what bounds those `WARN` lines — to under ten
times `RECEIVER_RATE_LIMIT` per minute per client IP, 1080 at the times `RECEIVER_RATE_LIMIT` per minute per client IP, 1080 at the
defaults, where before it there was no bound at all. The access log is defaults, where before it there was no bound at all. The access log is
bounded by neither limit: every request is recorded once at `INFO` with bounded by neither limit: every request is recorded once at `INFO`,
its full URL, served or rejected alike. served or rejected alike.
What the access log does bound is the _content_ of those lines. A 3xx
or 4xx response logs the chi route pattern — `/webhook/{uuid}`,
`/user/{username}//`, or the literal `(unmatched)` when the request hit
no route at all — in place of the concrete URL. Those are the outcomes
an unauthenticated client can drive for free: 404 and 429 on any
invented receiver path, a login redirect on any invented profile path.
Logging the URL there would let a flood write text of its own choosing,
at a length of its own choosing, into the log. 2xx and 5xx responses
keep the concrete path — a success resolved against a static route or
against the operator's own data (on the receiver, against a stored
entrypoint UUID), and a 5xx is a bug in this service, where the exact
path is the evidence and no client can provoke one at will.
The query string is never logged; it is replaced by the fixed marker
`?(redacted)`. It is client-chosen on every route, and
`/.well-known/healthcheck` and `/s/*` answer 200 to anyone with no rate
limiter in front of them, so a query on a fixed 200 URL would otherwise
buy the same amplification as an invented path. Nothing debuggable is
lost: `page`, on the authenticated pagination links, is the only query
parameter this service reads.
The remaining client-supplied fields are truncated rather than dropped,
each to a fixed budget: 512 bytes for `url`, `useragent` and `referer`,
128 for `request_id` (chi passes an inbound `X-Request-Id` header
through), and 32 for `method`. A truncated `User-Agent` is still worth
reading; an absent one is not. A cut value ends in `[truncated]`, which
is charged on top of the budget rather than inside it.
Each budget is spent in _encoded_ bytes, not in the bytes the client
sent. Every rune is charged what the wider of the two log handlers
emits for it: two bytes for a quotation mark, a backslash or a tab; six
for a non-printable rune below U+10000; ten for one at or above it,
which the text handler spells `\UXXXXXXXX`. Go's header parser accepts
all of them in a header value, so a budget counted raw would buy a
field several times its nominal size — and the line, not the header, is
what an operator has to store. Plain ASCII encodes one byte for one, so
a real browser's `User-Agent` still fits whole; a value built out of
escapes keeps a proportionally shorter prefix, which is the right
trade.
Net: **one `INFO` line per request, of at most 2,560 bytes.** That
ceiling is arithmetic, not an observation: 3 × (512 + 11) for `url`,
`useragent` and `referer`, plus 128 + 11 for `request_id`, plus 32 + 11
for `method`, plus a 336-byte fixed portion (the field names, the
punctuation, both timestamps at their longest, an IPv6 `remoteIP` with
a zone, the status and the latency) — 2,087 bytes, stated at 2,560 so
the figure has headroom. `internal/middleware/accesslog_test.go`
asserts it against 8 KB of client-chosen text in the path, in the
query, and in each of `User-Agent`, `Referer` and `X-Request-Id`,
including cases built from the characters the handlers escape, and
against the widest line the service can be made to write: a 5xx that
keeps its concrete path while all three header fields are also at their
budget. Every case runs through both handlers `internal/logger` can
select — the JSON one and the text one it installs on a tty — since the
two do not escape alike and the ceiling is quoted unqualified. Measured
over a real connection, the widest line is 1,972 bytes.
Multiply that ceiling by the request rate to size log storage. Note
that the rate is not bounded by the limits above on every route:
`/.well-known/healthcheck` and `/s/*` sit behind no limiter, so there
the multiplier is whatever the deployment will serve.
Every limiter here — receiver, login, and password change — identifies Every limiter here — receiver, login, and password change — identifies
the client the same way, through one shared key function: the the client the same way, through one shared key function: the
@@ -1400,13 +1464,20 @@ a clean lint. A host binary would share one cache and one lock with
every other checkout on the machine, which has produced both invented every other checkout on the machine, which has produced both invented
findings attributed to other worktrees and unearned passes. findings attributed to other worktrees and unearned passes.
Two properties are load-bearing: Three properties are load-bearing:
- `script/lint` passes `--no-cache-filter=lint`. Without it an unchanged - `script/lint` passes `--no-cache-filter=lint`. Without it an unchanged
tree replays the lint layer from cache and the build exits 0 in under tree replays the lint layer from cache and the build exits 0 in under
a second having linted nothing. The `deps` stage stays cacheable, so a second having linted nothing. The `deps` stage stays cacheable, so
module downloads are not repeated. Invalidation is scoped to the one module downloads are not repeated. Invalidation is scoped to the one
stage; never prune the shared build cache. stage; never prune the shared build cache.
- `script/lint` does not trust that flag. Docker silently ignores
`--no-cache-filter` for a stage name that does not match, so a stage
rename or a one-character typo would restore the cached false green
with no warning and a fast exit 0. The script therefore tees the
build output and treats a run as a pass only if golangci-lint's own
summary line (`N issues.` / `N issues:`) appears in it: no summary,
no lint, whatever the exit code says.
- Both lint steps use `RUN --network=none`. `golangci-lint config - Both lint steps use `RUN --network=none`. `golangci-lint config
verify` is documented as fetching its JSON schema over HTTPS, which verify` is documented as fetching its JSON schema over HTTPS, which
would be an unpinned remote dependency; the pinned image resolves the would be an unpinned remote dependency; the pinned image resolves the
@@ -1444,12 +1515,12 @@ Both check stages use Debian rather than Alpine because
and does not compile against musl. Only the final binary is statically and does not compile against musl. Only the final binary is statically
linked, which is what lets it run on the Alpine runtime image. linked, which is what lets it run on the Alpine runtime image.
`script/cibuild` — `docker build .` — is the CI gate: the four check `script/cibuild` — `docker build .` — is the CI gate: the checks run
targets run inside the image, so a build that succeeds is a repo that inside the image, so a build that succeeds is a repo that is formatted,
is formatted, linted, tested and compiled. `script/lint` also uses linted, tested and compiled. `script/lint` also uses Docker
Docker (`Dockerfile.lint`, see Linting above), so `make lint` and (`Dockerfile.lint`, see Linting above), so `make lint` and `make check`
`make check` run the same pinned linter version the gate does; only run the same pinned linter version the gate does; only `script/test`
`script/test` and `script/fmt-check` run on the host. and `script/fmt-check` run on the host.
#### CI gate honesty #### CI gate honesty
@@ -1474,11 +1545,32 @@ way.
A separate workflow step, run before the fingerprint is written, covers A separate workflow step, run before the fingerprint is written, covers
a second way the gate lied: Gitea cancels an in-flight run when a newer a second way the gate lied: Gitea cancels an in-flight run when a newer
commit lands on the same branch and records that cancellation as a commit lands on the same branch and records that cancellation as a
`failure` status, marking a commit red that was never tested. `failure` status, so a commit nothing ever tested reads as a test
Cancellation is unconditional server-side for result. Cancellation is unconditional server-side for push events, so
push events, so the superseding run rewrites the exact the superseding run calls `script/ci-mark-superseded`, which rewrites
`Has been cancelled` status to `skipped`. Genuine failures are never that exact status to `failure` /
touched. `Superseded by a newer commit; never tested`.
The state stays `failure` on purpose: Gitea's combined status folds
`skipped` into `success`, so marking a never-tested commit `skipped`
made the status API report green for it, indistinguishable from a commit
that passed. Reading a commit's status on this repo therefore goes:
- `success` / `Successful in ...` — the checks ran and passed.
- `failure` / `Failing after ...` — the checks ran and failed.
- `failure` / `Superseded by a newer commit; never tested` — the run was
cancelled, by a newer push or by hand, and nothing was verified about
this commit. Test the commit itself before concluding anything about
it.
Genuine failures and successes are never touched, and no status is left
`pending`, which would block the commit indefinitely. The step derives
its context string from the workflow name, the job **id** and the event.
That is deliberately not byte-identical to Gitea's own rule, which uses
the job's display `name:` where the runner exports the id, so giving the
job a `name:` — or renaming the workflow — makes the derived context
stop matching. The step fails loudly when no status on the commit
carries that context, so no rename can silently disable the rewrite.
## TODO ## TODO

2
go.mod
View File

@@ -17,6 +17,7 @@ require (
github.com/stretchr/testify v1.8.4 github.com/stretchr/testify v1.8.4
go.uber.org/fx v1.20.1 go.uber.org/fx v1.20.1
golang.org/x/crypto v0.38.0 golang.org/x/crypto v0.38.0
gopkg.in/yaml.v3 v3.0.1
gorm.io/driver/sqlite v1.5.4 gorm.io/driver/sqlite v1.5.4
gorm.io/gorm v1.25.5 gorm.io/gorm v1.25.5
modernc.org/sqlite v1.28.0 modernc.org/sqlite v1.28.0
@@ -52,7 +53,6 @@ require (
golang.org/x/text v0.25.0 // indirect golang.org/x/text v0.25.0 // indirect
golang.org/x/tools v0.21.1-0.20240508182429-e35e4ccd0d2d // indirect golang.org/x/tools v0.21.1-0.20240508182429-e35e4ccd0d2d // indirect
google.golang.org/protobuf v1.31.0 // indirect google.golang.org/protobuf v1.31.0 // indirect
gopkg.in/yaml.v3 v3.0.1 // indirect
lukechampine.com/uint128 v1.2.0 // indirect lukechampine.com/uint128 v1.2.0 // indirect
modernc.org/cc/v3 v3.40.0 // indirect modernc.org/cc/v3 v3.40.0 // indirect
modernc.org/ccgo/v3 v3.16.13 // indirect modernc.org/ccgo/v3 v3.16.13 // indirect

View File

@@ -0,0 +1,387 @@
package ciscript_test
import (
"maps"
"os"
"os/exec"
"path/filepath"
"slices"
"strings"
"testing"
"github.com/stretchr/testify/require"
"gopkg.in/yaml.v3"
)
const (
// supersededDesc is the description script/ci-mark-superseded
// writes, and the one an earlier revision of it wrote alongside a
// `skipped` state.
supersededDesc = "Superseded by a newer commit; never tested"
// liveContext is the commit-status context Gitea uses for this
// repository's runs, as seen in its API. The script derives it from
// the workflow and job names rather than hardcoding it; the
// derivation is checked against this value below.
liveContext = "check / check (push)"
scriptPath = "../../script/ci-mark-superseded"
workflow = "../../.gitea/workflows/check.yml"
// failure is the only state that neither folds into a combined
// `success` (as `skipped` does) nor blocks the commit forever (as
// `pending` does).
failure = "failure"
)
// repo is a throwaway git history: parent is the commit a run would be
// cancelled on, head the commit that superseded it.
type repo struct {
dir string
head string
parent string
}
// scriptEnv is the run identity the Gitea runner exports and the script
// builds its context string from.
type scriptEnv struct {
workflow string
job string
event string
}
func defaultEnv() scriptEnv {
return scriptEnv{workflow: "check", job: "check", event: "push"}
}
func cancelled() commitStatus {
return commitStatus{
Context: liveContext,
Status: failure,
Description: "Has been cancelled",
}
}
func running() commitStatus {
return commitStatus{
Context: liveContext,
Status: "pending",
Description: "Has started running",
}
}
func TestMarkSuperseded(t *testing.T) {
t.Parallel()
cases := map[string]struct {
parent commitStatus
wantMark bool
}{
"a cancelled run is marked": {
parent: cancelled(),
wantMark: true,
},
"a laundered skipped status is marked": {
parent: commitStatus{
Context: liveContext,
Status: "skipped",
Description: supersededDesc,
},
wantMark: true,
},
"a genuine failure is left alone": {
parent: commitStatus{
Context: liveContext,
Status: failure,
Description: "Failing after 3m1s",
},
wantMark: false,
},
"a passing run is left alone": {
parent: commitStatus{
Context: liveContext,
Status: "success",
Description: "Successful in 2m52s",
},
wantMark: false,
},
"another context is left alone": {
parent: commitStatus{
Context: "other / other (push)",
Status: failure,
Description: "Has been cancelled",
},
wantMark: false,
},
}
for name, tc := range cases {
t.Run(name, func(t *testing.T) {
t.Parallel()
requireTools(t)
history := newRepo(t)
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, tc.parent)
out, err := runScript(t, history, api, defaultEnv())
require.NoError(t, err, out)
posted := fake.postedFor(history.parent)
if !tc.wantMark {
require.Empty(t, posted)
return
}
require.Equal(t, []postedStatus{{
Context: liveContext,
// Not `skipped`: Gitea's combined status folds
// that into `success`, which is what made a
// never-tested commit read green.
State: failure,
Description: supersededDesc,
}}, posted)
})
}
}
// A second run must not rewrite what the first one wrote, or every
// later push would post a duplicate status.
func TestMarkSupersededIsIdempotent(t *testing.T) {
t.Parallel()
requireTools(t)
history := newRepo(t)
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, cancelled())
for range 2 {
out, err := runScript(t, history, api, defaultEnv())
require.NoError(t, err, out)
}
require.Len(t, fake.postedFor(history.parent), 1)
}
// Renaming the workflow or the job changes the context string Gitea
// uses. The script must say so instead of quietly matching nothing.
func TestMarkSupersededRejectsAnUnknownContext(t *testing.T) {
t.Parallel()
requireTools(t)
history := newRepo(t)
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, cancelled())
env := defaultEnv()
env.job = "renamed"
out, err := runScript(t, history, api, env)
require.Error(t, err)
require.Contains(t, out, "renamed")
require.Contains(t, out, liveContext)
require.Empty(t, fake.postedFor(history.parent))
}
// ANCESTOR_LIMIT is a documented knob. A value that is set but unusable
// must abort: handing it to git and discarding the exit status left the
// walk empty and the step green, marking nothing.
func TestMarkSupersededRejectsAnUnparseableAncestorLimit(t *testing.T) {
t.Parallel()
requireTools(t)
history := newRepo(t)
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, cancelled())
out, err := runScript(
t, history, api, defaultEnv(), "ANCESTOR_LIMIT=twenty",
)
require.Error(t, err)
require.Contains(t, out, "ANCESTOR_LIMIT")
require.Contains(t, out, "twenty")
require.Empty(t, fake.postedFor(history.parent))
}
// A status read that fails is not the same as a commit with nothing to
// do. Losing curl's exit status through a pipe made the two identical
// and left a laundered commit laundered with no signal.
func TestMarkSupersededFailsOnAnUnreadableAncestorStatus(t *testing.T) {
t.Parallel()
requireTools(t)
history := newRepo(t)
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, cancelled())
fake.failStatusRead(history.parent)
out, err := runScript(t, history, api, defaultEnv())
require.Error(t, err)
require.Contains(t, out, history.parent)
require.Contains(t, out, "cannot read commit statuses")
require.Empty(t, fake.postedFor(history.parent))
}
// A shallow clone cannot resolve the parent, so it is indistinguishable
// from a root commit to rev-parse and the walk would exit 0 having
// marked nothing. It must abort instead: dropping `fetch-depth: 0` from
// the checkout step is one edit, and a silent no-op there restores the
// false-green bug this script exists to prevent.
func TestMarkSupersededRejectsAShallowRepository(t *testing.T) {
t.Parallel()
requireTools(t)
history := shallowClone(t, newRepo(t))
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, cancelled())
out, err := runScript(t, history, api, defaultEnv())
require.Error(t, err)
require.Contains(t, out, "shallow repository")
require.Empty(t, fake.postedFor(history.parent))
require.Empty(t, fake.postedFor(history.head))
}
// shallowClone returns the same history as a depth-1 clone. The `file://`
// URL is required: git ignores --depth for a plain local path.
func shallowClone(t *testing.T, history repo) repo {
t.Helper()
dir := t.TempDir()
//nolint:gosec // fixed argv, arguments are test-local paths
cmd := exec.CommandContext(t.Context(), "git", "clone", "-q",
"--depth=1", "file://"+history.dir, dir)
out, err := cmd.CombinedOutput()
require.NoError(t, err, string(out))
return repo{dir: dir, head: history.head, parent: history.parent}
}
// The derived context must equal the one Gitea actually uses, which is
// built from the same workflow and job names.
func TestDerivedContextMatchesGitea(t *testing.T) {
t.Parallel()
requireTools(t)
name, job := workflowIdentity(t)
history := newRepo(t)
fake, api := newFakeGitea(t)
fake.setStatus(history.head, running())
fake.setStatus(history.parent, cancelled())
out, err := runScript(t, history, api, scriptEnv{
workflow: name,
job: job,
event: "push",
})
require.NoError(t, err, out)
posted := fake.postedFor(history.parent)
require.Len(t, posted, 1)
require.Equal(t, liveContext, posted[0].Context)
}
// workflowIdentity reads the workflow name and its single job id out of
// the checked-in workflow file.
func workflowIdentity(t *testing.T) (string, string) {
t.Helper()
raw, err := os.ReadFile(workflow)
require.NoError(t, err)
var parsed struct {
Name string `yaml:"name"`
Jobs map[string]any `yaml:"jobs"`
}
require.NoError(t, yaml.Unmarshal(raw, &parsed))
jobs := slices.Collect(maps.Keys(parsed.Jobs))
require.Len(t, jobs, 1)
return parsed.Name, jobs[0]
}
func runScript(
t *testing.T, history repo, api string, env scriptEnv,
extra ...string,
) (string, error) {
t.Helper()
script, err := filepath.Abs(scriptPath)
require.NoError(t, err)
//nolint:gosec // fixed argv, repo-local script under test
cmd := exec.CommandContext(t.Context(), "sh", script)
cmd.Dir = history.dir
cmd.Env = append(os.Environ(),
"GITHUB_API_URL="+api,
"GITHUB_REPOSITORY=sneak/webhooker",
"GITHUB_SHA="+history.head,
"GITHUB_WORKFLOW="+env.workflow,
"GITHUB_JOB="+env.job,
"GITHUB_EVENT_NAME="+env.event,
"GITEA_TOKEN=test-token",
)
cmd.Env = append(cmd.Env, extra...)
out, err := cmd.CombinedOutput()
return string(out), err
}
func newRepo(t *testing.T) repo {
t.Helper()
dir := t.TempDir()
git := func(args ...string) string {
//nolint:gosec // fixed argv, arguments are test constants
cmd := exec.CommandContext(t.Context(), "git", args...)
cmd.Dir = dir
out, err := cmd.CombinedOutput()
require.NoError(t, err, string(out))
return strings.TrimSpace(string(out))
}
commit := func(message string) string {
git(
"-c", "user.email=ci@example.invalid",
"-c", "user.name=ci",
"-c", "commit.gpgsign=false",
"commit", "-q", "--allow-empty", "-m", message,
)
return git("rev-parse", "HEAD")
}
git("init", "-q", "-b", "main")
parent := commit("parent")
head := commit("head")
return repo{dir: dir, head: head, parent: parent}
}
func requireTools(t *testing.T) {
t.Helper()
for _, tool := range []string{"sh", "git", "curl", "jq"} {
_, err := exec.LookPath(tool)
if err != nil {
t.Skipf("%s is not installed: %v", tool, err)
}
}
}

10
internal/ciscript/doc.go Normal file
View File

@@ -0,0 +1,10 @@
// Package ciscript holds the tests for the repository's CI shell
// scripts in script/. It carries no runtime code: the scripts run on
// the CI runner, not inside the binary, but their behaviour still has
// to be verified by the test suite.
//
// The scripts under test are outside the Go build graph, so `go test`'s
// result cache serves a stale PASS when only a script changed: run the
// container build, or GOFLAGS=-count=1, to trust a result here after
// editing script/.
package ciscript

View File

@@ -0,0 +1,162 @@
package ciscript_test
import (
"encoding/json"
"net/http"
"net/http/httptest"
"sync"
"testing"
)
// commitStatus is the part of an entry in Gitea's combined-status
// response that script/ci-mark-superseded reads.
type commitStatus struct {
Context string `json:"context"`
Status string `json:"status"`
Description string `json:"description"`
}
// postedStatus is the part of a create-status request body the script
// writes.
type postedStatus struct {
Context string `json:"context"`
State string `json:"state"`
Description string `json:"description"`
}
// fakeGitea serves the two endpoints the script talks to. Like Gitea,
// the newest status for a context replaces the previous one, so a
// second run of the script sees what the first one wrote.
type fakeGitea struct {
mu sync.Mutex
statuses map[string][]commitStatus
posted map[string][]postedStatus
// failRead is a commit whose combined-status read answers HTTP
// 500, standing in for a status API that is down.
failRead string
}
// newFakeGitea returns the fake and the base URL to hand the script as
// GITHUB_API_URL.
func newFakeGitea(t *testing.T) (*fakeGitea, string) {
t.Helper()
fake := &fakeGitea{
mu: sync.Mutex{},
statuses: map[string][]commitStatus{},
posted: map[string][]postedStatus{},
failRead: "",
}
srv := httptest.NewServer(fake.routes())
t.Cleanup(srv.Close)
return fake, srv.URL
}
func (f *fakeGitea) routes() http.Handler {
mux := http.NewServeMux()
mux.HandleFunc(
"GET /repos/{owner}/{repo}/commits/{sha}/status",
f.handleCombined,
)
mux.HandleFunc(
"POST /repos/{owner}/{repo}/statuses/{sha}",
f.handleCreate,
)
return mux
}
func (f *fakeGitea) handleCombined(
w http.ResponseWriter, r *http.Request,
) {
f.mu.Lock()
defer f.mu.Unlock()
sha := r.PathValue("sha")
if f.failRead != "" && f.failRead == sha {
http.Error(w, "boom", http.StatusInternalServerError)
return
}
body := struct {
Statuses []commitStatus `json:"statuses"`
}{Statuses: f.statuses[sha]}
payload, err := json.Marshal(body)
if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError)
return
}
w.Header().Set("Content-Type", "application/json")
_, _ = w.Write(payload)
}
func (f *fakeGitea) handleCreate(w http.ResponseWriter, r *http.Request) {
var got postedStatus
err := json.NewDecoder(r.Body).Decode(&got)
if err != nil {
http.Error(w, err.Error(), http.StatusBadRequest)
return
}
sha := r.PathValue("sha")
f.mu.Lock()
defer f.mu.Unlock()
f.posted[sha] = append(f.posted[sha], got)
f.replaceLocked(sha, commitStatus{
Context: got.Context,
Status: got.State,
Description: got.Description,
})
w.WriteHeader(http.StatusCreated)
}
// failStatusRead makes the combined-status read for one commit answer
// HTTP 500.
func (f *fakeGitea) failStatusRead(sha string) {
f.mu.Lock()
defer f.mu.Unlock()
f.failRead = sha
}
// setStatus gives a commit its latest status for a context.
func (f *fakeGitea) setStatus(sha string, status commitStatus) {
f.mu.Lock()
defer f.mu.Unlock()
f.replaceLocked(sha, status)
}
// postedFor returns the statuses the script created for a commit.
func (f *fakeGitea) postedFor(sha string) []postedStatus {
f.mu.Lock()
defer f.mu.Unlock()
return append([]postedStatus(nil), f.posted[sha]...)
}
// replaceLocked requires f.mu.
func (f *fakeGitea) replaceLocked(sha string, status commitStatus) {
for i, existing := range f.statuses[sha] {
if existing.Context == status.Context {
f.statuses[sha][i] = status
return
}
}
f.statuses[sha] = append(f.statuses[sha], status)
}

View File

@@ -0,0 +1,658 @@
package middleware_test
import (
"bytes"
"context"
"encoding/json"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"testing"
"github.com/go-chi/chi"
chimw "github.com/go-chi/chi/middleware"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"sneak.berlin/go/webhooker/internal/config"
"sneak.berlin/go/webhooker/internal/middleware"
)
// floodRequests is the number of distinct invented paths each flood
// test drives through the access log.
const floodRequests = 64
// attackerMarker is embedded in every invented path. No access log
// line for a redirected or rejected request may contain it.
const attackerMarker = "QQATTACKERTEXTQQ"
// maxLineBytes bounds a single access log line whose client-supplied
// fields are of ordinary size. Well above what the fixed fields need,
// well below the length of the oversized input the amplification tests
// send.
const maxLineBytes = 1024
// maxCappedLineBytes bounds a single access log line when every
// client-supplied field arrives oversized and is truncated to its
// budget. This is the number the README quotes as the per-line cost an
// operator sizes log storage against, and it is a bound on the
// ENCODED line, which is what the operator's disk holds.
const maxCappedLineBytes = 2560
// oversizedSegmentBytes is the length of the single attacker-chosen
// path segment, query string or header used to show line size does not
// track input size.
const oversizedSegmentBytes = 8192
// tailMarker is placed at the END of an oversized header value, so its
// absence from the log proves the value was truncated rather than
// merely being short.
const tailMarker = "QQTRUNCATEDTAILQQ"
// These mirror the middleware's own budgets, which are unexported.
// They are duplicated rather than exported so that widening a budget
// in the middleware has to be restated here deliberately.
const (
maxFieldBytes = 512
maxRequestIDBytes = 128
maxMethodBytes = 32
truncationSuffix = "[truncated]"
unmatchedRouteLiteral = "(unmatched)"
)
// capturingMiddleware returns a Middleware whose logger writes JSON
// lines into the returned buffer, so the access log can be asserted
// on directly.
func capturingMiddleware(t *testing.T) (*middleware.Middleware, *bytes.Buffer) {
t.Helper()
buf := new(bytes.Buffer)
log := slog.New(slog.NewJSONHandler(
buf,
&slog.HandlerOptions{Level: slog.LevelInfo},
))
cfg := &config.Config{Environment: config.EnvironmentDev}
return middleware.NewForTest(log, cfg, nil), buf
}
// capturingTextMiddleware is capturingMiddleware for the other handler
// internal/logger can select: slog's text handler, which
// internal/logger/logger.go installs when stderr is a tty. It escapes
// differently from the JSON one, so the line bound has to be asserted
// against both.
func capturingTextMiddleware(
t *testing.T,
) (*middleware.Middleware, *bytes.Buffer) {
t.Helper()
buf := new(bytes.Buffer)
log := slog.New(slog.NewTextHandler(
buf,
&slog.HandlerOptions{Level: slog.LevelInfo},
))
cfg := &config.Config{Environment: config.EnvironmentDev}
return middleware.NewForTest(log, cfg, nil), buf
}
// accessLogRouter mirrors the production route shapes that an
// unauthenticated client can reach: the public receiver, the
// authenticated profile route (which redirects to login rather than
// rejecting outright), the health check (which answers 200 to anyone,
// behind no rate limiter at all), and a plain static route.
func accessLogRouter(m *middleware.Middleware) *chi.Mux {
router := chi.NewRouter()
// Production registers RequestID ahead of Logging, and chi's
// RequestID passes an inbound X-Request-Id header straight
// through, so the request_id field is client-supplied too.
router.Use(chimw.RequestID)
router.Use(m.Logging())
router.Get(
"/.well-known/healthcheck",
func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusOK)
},
)
router.HandleFunc(
"/webhook/{uuid}",
func(w http.ResponseWriter, r *http.Request) {
// Stands in for the real handler: an unknown entrypoint
// UUID 404s, a known one succeeds.
if chi.URLParam(r, "uuid") != "known" {
http.Error(w, "not found", http.StatusNotFound)
return
}
w.WriteHeader(http.StatusOK)
},
)
router.Route("/user/{username}", func(r chi.Router) {
r.Get("/", func(w http.ResponseWriter, r *http.Request) {
http.Redirect(
w, r, "/pages/login", http.StatusSeeOther,
)
})
})
boom := func(w http.ResponseWriter, _ *http.Request) {
http.Error(w, "boom", http.StatusInternalServerError)
}
router.Get("/boom", boom)
// The 5xx branch keeps the concrete path, so it needs a route that
// answers 500 to a path of the client's choosing: that is where the
// url field and the header fields are both at their budget on the
// same line.
router.Get("/boom/*", boom)
return router
}
// accessLogEntries decodes the captured buffer into one map per
// logged line, holding every line to maxLineBytes.
func accessLogEntries(
t *testing.T,
buf *bytes.Buffer,
) []map[string]any {
t.Helper()
return accessLogEntriesWithin(t, buf, maxLineBytes)
}
// accessLogEntriesWithin decodes the captured buffer into one map per
// logged line, holding every line to bound bytes.
func accessLogEntriesWithin(
t *testing.T,
buf *bytes.Buffer,
bound int,
) []map[string]any {
t.Helper()
var entries []map[string]any
for line := range strings.SplitSeq(
strings.TrimSpace(buf.String()), "\n",
) {
if line == "" {
continue
}
require.LessOrEqual(
t, len(line), bound,
"access log line exceeded its bound",
)
var entry map[string]any
require.NoError(t, json.Unmarshal([]byte(line), &entry))
entries = append(entries, entry)
}
return entries
}
// get drives one GET through the router.
func get(t *testing.T, router *chi.Mux, target string) int {
t.Helper()
return getWithHeaders(t, router, target, nil)
}
// getWithHeaders drives one GET through the router with the supplied
// request headers set.
func getWithHeaders(
t *testing.T,
router *chi.Mux,
target string,
headers map[string]string,
) int {
t.Helper()
req := httptest.NewRequestWithContext(
context.Background(), http.MethodGet, target, nil,
)
for name, value := range headers {
req.Header.Set(name, value)
}
w := httptest.NewRecorder()
router.ServeHTTP(w, req)
return w.Code
}
// assertFloodIsBounded drives floodRequests distinct invented paths
// built by pathFor and asserts every logged line names wantURL, that
// none carries the invented text, and that the line count is exactly
// one per request.
func assertFloodIsBounded(
t *testing.T,
pathFor func(i int) string,
wantStatus int,
wantURL string,
) {
t.Helper()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
for i := range floodRequests {
assert.Equal(t, wantStatus, get(t, router, pathFor(i)))
}
assert.NotContains(
t, buf.String(), attackerMarker,
"access log carried attacker-chosen path text",
)
entries := accessLogEntries(t, buf)
require.Len(t, entries, floodRequests)
for _, entry := range entries {
assert.Equal(t, wantURL, entry["url"])
assert.InDelta(
t, float64(wantStatus), entry["status"], 0,
)
}
}
func TestAccessLog_InventedReceiverPathsLogRoutePattern(t *testing.T) {
t.Parallel()
assertFloodIsBounded(
t,
func(i int) string {
return "/webhook/" + attackerMarker +
strings.Repeat("x", i) + "?q=" + attackerMarker
},
http.StatusNotFound,
"/webhook/{uuid}",
)
}
func TestAccessLog_InventedProfilePathsLogRoutePattern(t *testing.T) {
t.Parallel()
// The login redirect is a 3xx, not a 4xx, but it is just as free
// for an unauthenticated client to drive with invented input.
// The doubled slash is what chi's RoutePattern yields for a
// mounted subrouter's index route.
assertFloodIsBounded(
t,
func(i int) string {
return "/user/" + attackerMarker +
strings.Repeat("x", i) + "/"
},
http.StatusSeeOther,
"/user/{username}//",
)
}
func TestAccessLog_UnroutablePathsLogFixedLiteral(t *testing.T) {
t.Parallel()
assertFloodIsBounded(
t,
func(i int) string {
return "/" + attackerMarker + strings.Repeat("x", i)
},
http.StatusNotFound,
"(unmatched)",
)
}
// oversizedValue builds an 8 KB header value out of repetitions of ch,
// with the tail marker at its end.
//
// The leading 'x' is load-bearing for tab: net/textproto strips leading
// and trailing whitespace from a header value, so a value that were
// nothing but tabs would arrive empty over a real connection and the
// case would prove nothing.
func oversizedValue(ch string) string {
return "x" + strings.Repeat(ch, oversizedSegmentBytes) + tailMarker
}
// oversizedHeaders fills every client-supplied header the access log
// reads with the same value.
func oversizedHeaders(value string) map[string]string {
return map[string]string{
"User-Agent": value,
"Referer": value,
"X-Request-Id": value,
}
}
// sizeCase is one way of pointing 8 KB of client-chosen text at the
// access log.
type sizeCase struct {
target string
headers map[string]string
wantStatus int
wantURL string
bound int
}
// lineSizeCases enumerates every part of a request that reaches the
// access log, at 8 KB apiece.
func lineSizeCases() map[string]sizeCase {
cases := map[string]sizeCase{
"oversized path segment": {
target: "/webhook/" + attackerMarker +
strings.Repeat("x", oversizedSegmentBytes),
wantStatus: http.StatusNotFound,
wantURL: "/webhook/{uuid}",
bound: maxLineBytes,
},
// /.well-known/healthcheck answers 200 to anyone and has no
// rate limiter in front of it, so an oversized query appended
// to it would otherwise buy the same amplification as an
// invented 404 path, unauthenticated and unthrottled.
"oversized query on an unauthenticated 200": {
target: "/.well-known/healthcheck?q=" + attackerMarker +
strings.Repeat("x", oversizedSegmentBytes),
wantStatus: http.StatusOK,
wantURL: "/.well-known/healthcheck?(redacted)",
bound: maxLineBytes,
},
// These reach the line on every request, including one whose
// url field is correctly redacted.
"oversized headers": {
target: "/" + attackerMarker,
headers: oversizedHeaders(oversizedValue("h")),
wantStatus: http.StatusNotFound,
wantURL: unmatchedRouteLiteral,
bound: maxCappedLineBytes,
},
}
// The url field on a 5xx keeps the concrete path, so it reaches its
// own budget on the same line as the three header fields. That is
// the widest line the service can be made to write.
longPath := "/boom/" + strings.Repeat("x", oversizedSegmentBytes)
wantLongURL := longPath[:maxFieldBytes] + truncationSuffix
// escapeChars are the runes Go's header parser accepts in a header
// value and the log handler then escapes, coming out wider than
// they went in. A budget counted in raw bytes lets any of them buy
// a field several times its nominal size, so every one of them
// gets a case.
//
// The astral one is the case the JSON handler alone does not
// reach: U+1000C is unassigned, so it is non-printable, and
// strconv.Quote spells a non-printable rune at or above U+10000
// as a ten-byte \UXXXXXXXX. The JSON handler passes it through as
// its four UTF-8 bytes, so only the text-handler shape of this
// test holds the ten-byte charge honest.
escapeChars := map[string]string{
"quote": `"`,
"backslash": `\`,
"tab": "\t",
"astral": "\U0001000C",
}
for kind, char := range escapeChars {
fill := oversizedValue(char)
cases["oversized "+kind+" headers"] = sizeCase{
target: "/" + attackerMarker,
headers: oversizedHeaders(fill),
wantStatus: http.StatusNotFound,
wantURL: unmatchedRouteLiteral,
bound: maxCappedLineBytes,
}
cases["oversized "+kind+" headers with a 5xx concrete url"] =
sizeCase{
target: longPath,
headers: oversizedHeaders(fill),
wantStatus: http.StatusInternalServerError,
wantURL: wantLongURL,
bound: maxCappedLineBytes,
}
}
return cases
}
// TestAccessLog_LineSizeDoesNotTrackInputSize drives 8 KB of
// client-chosen text at the access log through each part of the
// request that reaches it, and holds the resulting line to a fixed
// bound in every case.
//
// The bound is on the ENCODED line, so the cases built out of
// characters the handler escapes are the ones that matter: a budget
// spent in raw bytes passes every plain-ASCII case here and still
// writes a line half again as long as the stated ceiling.
func TestAccessLog_LineSizeDoesNotTrackInputSize(t *testing.T) {
t.Parallel()
require.Equal(
t, middleware.MaxAccessLogLineBytes, maxCappedLineBytes,
"the README quotes this ceiling and the middleware derives "+
"it; they have to agree",
)
for name, tc := range lineSizeCases() {
t.Run(name, func(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t,
tc.wantStatus,
getWithHeaders(t, router, tc.target, tc.headers),
)
// accessLogEntriesWithin enforces the bound, which is
// orders of magnitude smaller than the input just sent.
entries := accessLogEntriesWithin(t, buf, tc.bound)
require.Len(t, entries, 1)
assert.Equal(t, tc.wantURL, entries[0]["url"])
// The markers sit at the far end of the client-chosen
// text, so their absence is what proves the redaction and
// the truncation actually ran.
assert.NotContains(
t, buf.String(), attackerMarker,
"access log carried attacker-chosen text",
)
assert.NotContains(
t, buf.String(), tailMarker,
"access log carried an untruncated client field",
)
})
}
}
// TestAccessLog_LineSizeDoesNotTrackInputSizeOnTheTextHandler runs the
// same cases through slog's text handler, which internal/logger
// selects on a tty.
//
// MaxAccessLogLineBytes is quoted to operators unqualified, so it has
// to hold for whichever handler is installed — and the two do not
// escape alike. The astral case is the one that separates them: the
// JSON handler emits U+1000C as its four UTF-8 bytes, while
// strconv.Quote spells it \U0001000C at ten. Charging six for it, as
// this code did, put a real 2,676-byte line on the wire here while
// every JSON case stayed comfortably inside the bound.
//
// Only the size bound is asserted; the url field's contents are the
// JSON shape's business above.
func TestAccessLog_LineSizeDoesNotTrackInputSizeOnTheTextHandler(
t *testing.T,
) {
t.Parallel()
for name, tc := range lineSizeCases() {
t.Run(name, func(t *testing.T) {
t.Parallel()
m, buf := capturingTextMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t,
tc.wantStatus,
getWithHeaders(t, router, tc.target, tc.headers),
)
line := strings.TrimSpace(buf.String())
require.NotEmpty(t, line)
assert.NotContains(
t, line, "\n", "expected exactly one log line",
)
require.LessOrEqual(
t, len(line), tc.bound,
"access log line exceeded its bound",
)
assert.Contains(t, line, "url=")
assert.NotContains(
t, line, attackerMarker,
"access log carried attacker-chosen text",
)
assert.NotContains(
t, line, tailMarker,
"access log carried an untruncated client field",
)
})
}
}
// TestAccessLog_OversizedMethodIsTruncated covers the last term in the
// MaxAccessLogLineBytes arithmetic that the size cases above cannot
// reach: Go accepts any RFC 7230 token as a method, and getWithHeaders
// only ever sends GET.
func TestAccessLog_OversizedMethodIsTruncated(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
method := strings.Repeat("M", oversizedSegmentBytes) + attackerMarker
req := httptest.NewRequestWithContext(
context.Background(), method, "/"+attackerMarker, nil,
)
rec := httptest.NewRecorder()
router.ServeHTTP(rec, req)
entries := accessLogEntriesWithin(t, buf, maxLineBytes)
require.Len(t, entries, 1)
assert.Equal(
t,
strings.Repeat("M", maxMethodBytes)+truncationSuffix,
entries[0]["method"],
)
assert.NotContains(
t, buf.String(), attackerMarker,
"access log carried attacker-chosen text",
)
}
// TestAccessLog_OversizedHeadersKeepATruncatedPrefix checks the other
// half of the header cap: the fields are cut, not dropped, so a
// truncated User-Agent is still worth reading.
func TestAccessLog_OversizedHeadersKeepATruncatedPrefix(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t,
http.StatusNotFound,
getWithHeaders(
t, router, "/nope",
oversizedHeaders(oversizedValue("h")),
),
)
entries := accessLogEntriesWithin(t, buf, maxCappedLineBytes)
require.Len(t, entries, 1)
for key, budget := range map[string]int{
"useragent": maxFieldBytes,
"referer": maxFieldBytes,
"request_id": maxRequestIDBytes,
} {
value, ok := entries[0][key].(string)
require.True(t, ok, key)
assert.LessOrEqual(
t, len(value), budget+len(truncationSuffix), key,
)
assert.Contains(t, value, truncationSuffix, key)
assert.Contains(t, value, "hhhh", key)
}
}
func TestAccessLog_SuccessKeepsConcretePathAndRedactsQuery(
t *testing.T,
) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t, http.StatusOK, get(t, router, "/webhook/known?src=ci"),
)
// The path resolved against a stored entrypoint, so it stays. The
// query never does: see TestAccessLog_UnauthenticatedSuccess...
entries := accessLogEntries(t, buf)
require.Len(t, entries, 1)
assert.Equal(t, "/webhook/known?(redacted)", entries[0]["url"])
assert.NotContains(t, buf.String(), "src=ci")
}
func TestAccessLog_ServerErrorKeepsConcreteURL(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t, http.StatusInternalServerError, get(t, router, "/boom"),
)
entries := accessLogEntries(t, buf)
require.Len(t, entries, 1)
assert.Equal(t, "/boom", entries[0]["url"])
}
func TestAccessLog_RetainsEveryOtherField(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t,
http.StatusNotFound,
get(t, router, "/webhook/"+attackerMarker),
)
entries := accessLogEntries(t, buf)
require.Len(t, entries, 1)
for _, key := range []string{
"request_start", "method", "url", "useragent", "request_id",
"referer", "proto", "remoteIP", "status", "latency_ms",
} {
assert.Contains(t, entries[0], key)
}
assert.Equal(t, http.MethodGet, entries[0]["method"])
assert.Equal(t, "HTTP/1.1", entries[0]["proto"])
}

View File

@@ -6,9 +6,13 @@ import (
"log/slog" "log/slog"
"net" "net"
"net/http" "net/http"
"strings"
"time" "time"
"unicode"
"unicode/utf8"
basicauth "github.com/99designs/basicauth-go" basicauth "github.com/99designs/basicauth-go"
"github.com/go-chi/chi"
"github.com/go-chi/chi/middleware" "github.com/go-chi/chi/middleware"
"github.com/go-chi/cors" "github.com/go-chi/cors"
metrics "github.com/slok/go-http-metrics/metrics/prometheus" metrics "github.com/slok/go-http-metrics/metrics/prometheus"
@@ -25,6 +29,75 @@ const (
// corsMaxAge is the maximum time (in seconds) that a // corsMaxAge is the maximum time (in seconds) that a
// preflight response can be cached. // preflight response can be cached.
corsMaxAge = 300 corsMaxAge = 300
// unmatchedRoute is logged in the access log's url field when a
// redirected or rejected request matched no route pattern at
// all. Every byte of such a path is client-chosen, so none of it
// is logged.
unmatchedRoute = "(unmatched)"
// redactedQuery stands in for the query string on the access log
// branches that keep the concrete URL. The query is client-chosen
// on every route, including the ones that answer an
// unauthenticated 200, so logging it verbatim would let a client
// pick the size of the line it writes.
redactedQuery = "?(redacted)"
// maxLogFieldBytes bounds each access log field whose value the
// client supplies outright: the URL, the User-Agent and the
// Referer. The budget is spent in ENCODED bytes (see
// truncateLogField), so 512 still holds a real browser's User-Agent
// whole — those are plain ASCII, which encodes one byte for one —
// while a value built from characters the encoder escapes keeps a
// shorter prefix. That is the intended trade: 500 quotation marks
// are not a debugging asset.
maxLogFieldBytes = 512
// maxLogRequestIDBytes bounds the request id, which is also
// client-supplied: chi's RequestID middleware passes an inbound
// X-Request-Id header through verbatim. Its generated form is an
// order of magnitude shorter than this.
maxLogRequestIDBytes = 128
// maxLogMethodBytes bounds the method. Go accepts any RFC 7230
// token there, bounded only by the header size limit, so it is
// client-chosen text like the rest. The longest registered method
// is half this.
maxLogMethodBytes = 32
// truncationMarker is appended to any field the access log cut, so
// a short value and a truncated one cannot be confused. It is
// charged on top of the budget, not inside it.
truncationMarker = "[truncated]"
// MaxAccessLogLineBytes is the ceiling on one JSON access log line,
// and the number an operator multiplies by the request rate to size
// log storage. It is not an observation of a sample: it is the sum
// of the budgets above, each of which truncateLogField enforces in
// ENCODED bytes, plus the part of the line no client can influence.
//
// url, useragent, referer 3*(512+11) = 1569
// request_id 128+11 = 139
// method 32+11 = 43
// fixed portion = 336
// ----
// 2087
//
// The fixed portion is the JSON punctuation, the field names, the
// level and the message, both timestamps at their longest, an IPv6
// remoteIP with a zone, a three-digit status and a full-width int64
// latency. Stated at 2560 so the figure carries headroom rather
// than sitting on the arithmetic.
//
// The tty text handler in internal/logger is covered by the same
// figure. encodedLogFieldBytes charges every rune at least what
// the wider of the two handlers emits for it — including the ten
// bytes strconv.Quote spends on a non-printable rune at or above
// U+10000, which is four more than the JSON handler ever spends —
// so each budget bounds the encoded field under either handler.
// The text handler's fixed portion is 286, the smaller of the two,
// which puts its worst case at 2037.
MaxAccessLogLineBytes = 2560
) )
//nolint:revive // MiddlewareParams is a standard fx naming convention. //nolint:revive // MiddlewareParams is a standard fx naming convention.
@@ -94,6 +167,178 @@ func (lrw *loggingResponseWriter) WriteHeader(code int) {
lrw.ResponseWriter.WriteHeader(code) lrw.ResponseWriter.WriteHeader(code)
} }
// encodedLogFieldBytes is what r costs on the line once the log
// handler has escaped it, taking the worse of the two handlers
// internal/logger configures.
//
// slog's JSON handler escapes quote, backslash, newline, carriage
// return and tab to two bytes each, and every other C0 control plus
// LINE SEPARATOR and PARAGRAPH SEPARATOR to a six-byte \u escape; it
// passes every other rune through as its own UTF-8. Its text handler
// quotes with strconv.Quote, which spells a non-printable rune below
// U+10000 as \uXXXX but one at or above U+10000 as \UXXXXXXXX — ten
// bytes, not six. The text handler is therefore the worse of the two
// for every non-printable rune, and by four bytes apiece for the
// 955,086 unassigned, private-use and format code points on planes 1
// to 16.
//
// Charging ten there is what makes MaxAccessLogLineBytes hold for the
// tty handler as well: U+1000C encodes as F0 90 80 8C, every byte
// >= 0x80, which httpguts.ValidHeaderFieldValue accepts and
// net/textproto does not strip, so a header can be filled with them.
//
// Both handlers pass printable runes through as their own UTF-8, so
// unicode.IsPrint separates the escaped cases from the plain ones for
// either handler.
func encodedLogFieldBytes(r rune) int {
const (
// A backslash and the character itself.
shortEscapeBytes = 2
// \uXXXX, which is also the width of \u00XX.
escapedRuneBytes = 6
// \UXXXXXXXX, strconv.Quote's spelling of a non-printable
// rune outside the basic multilingual plane.
escapedAstralRuneBytes = 10
// The first code point strconv.Quote spells with \U.
firstAstralRune = 0x10000
)
switch {
case r == '"' || r == '\\' || r == '\n' || r == '\r' || r == '\t':
return shortEscapeBytes
case !unicode.IsPrint(r) && r >= firstAstralRune:
return escapedAstralRuneBytes
case !unicode.IsPrint(r):
return escapedRuneBytes
default:
return utf8.RuneLen(r)
}
}
// truncateLogField caps s at maxBytes of ENCODED output, marking the
// value when it cuts.
//
// Budgeting raw bytes would not bound the line. Escaping only ever
// grows a value, so a raw budget spent on characters the encoder
// escapes buys a field several times its nominal size — and the line
// is the thing an operator is told to multiply by their request rate.
// Charging each rune what it will actually cost is what makes
// MaxAccessLogLineBytes true rather than merely larger. The visible
// consequence is that an escape-heavy value keeps a shorter prefix
// than a plain one, which is the correct trade.
//
// The result is always valid UTF-8. A cut on a byte boundary can split
// a multi-byte rune, and a header can carry bytes that were never
// valid UTF-8 to begin with; both are dropped rather than kept, since
// an encoder would otherwise spend six bytes replacing each one.
func truncateLogField(s string, maxBytes int) string {
// No rune encodes to fewer bytes than it occupies, so nothing past
// maxBytes raw can fit the budget. Slicing first bounds the scan
// below to the budget rather than to the size of the header the
// client sent.
window, cut := s, false
if len(window) > maxBytes {
window, cut = window[:maxBytes], true
}
var (
kept strings.Builder
spent int
)
for i := 0; i < len(window); {
r, size := utf8.DecodeRuneInString(window[i:])
if r == utf8.RuneError && size == 1 {
i += size
continue
}
cost := encodedLogFieldBytes(r)
if spent+cost > maxBytes {
cut = true
break
}
spent += cost
kept.WriteString(window[i : i+size])
i += size
}
if !cut {
return kept.String()
}
return kept.String() + truncationMarker
}
// concreteLogURL renders the request's own URL for the access log
// branches that keep it, with the query string replaced by a fixed
// marker.
//
// The path on those branches is bounded by the service's routes or by
// the operator's data — a 2xx on the receiver means the UUID named a
// stored entrypoint, a 2xx under /s means the file is in the embedded
// tree. The query is not bounded by anything: /.well-known/healthcheck
// and /s/* take no authentication and sit behind no rate limiter, and
// /pages/login behind only the login limiter, so any of them will
// answer 200 to a URL carrying an arbitrary number of arbitrary bytes
// after the '?'. Keeping the path and dropping the query is what makes
// this branch as bounded as the pattern branches below.
//
// Nothing debuggable is lost. One route in the service reads a query
// parameter at all — `page`, on the authenticated pagination links in
// internal/handlers/source_management.go — and the alternatives that
// would preserve more (a key count, a key allowlist) all require
// parsing an attacker-sized query on every request, which is work an
// unauthenticated client would then be choosing for us.
func concreteLogURL(r *http.Request) string {
path := r.URL.EscapedPath()
if r.URL.RawQuery == "" && !r.URL.ForceQuery {
return path
}
return path + redactedQuery
}
// accessLogURL returns the value for the access log's url field.
//
// 2xx and 5xx responses get the concrete path (see concreteLogURL). A
// success resolved against a static route or against the operator's
// own data — on the receiver, a 2xx means the UUID named a stored
// entrypoint — and a server error is our own bug, where the exact URL
// is the primary evidence and which no client can provoke at will.
//
// 3xx and 4xx responses get the chi route pattern instead. Those are
// the outcomes an unauthenticated client drives for free: 404 or 429
// on any invented /webhook/ path, 303 to the login page on any
// invented /user/ path. Logging the concrete URL there lets a flood
// write attacker-chosen text, of attacker-chosen length, into the
// operator's log at one line per request. The pattern comes from the
// router's own table, so it is bounded by the service's routes while
// still naming which class of request was rejected.
//
// The pattern is only populated once routing has run, so this must be
// called after the handler returns, not before.
func accessLogURL(r *http.Request, status int) string {
if status < http.StatusMultipleChoices ||
status >= http.StatusInternalServerError {
return concreteLogURL(r)
}
if rc := chi.RouteContext(r.Context()); rc != nil {
if pattern := rc.RoutePattern(); pattern != "" {
return pattern
}
}
return unmatchedRoute
}
// Logging returns middleware that logs each HTTP request with // Logging returns middleware that logs each HTTP request with
// timing and metadata. // timing and metadata.
func (s *Middleware) Logging() func(http.Handler) http.Handler { func (s *Middleware) Logging() func(http.Handler) http.Handler {
@@ -118,13 +363,27 @@ func (s *Middleware) Logging() func(http.Handler) http.Handler {
} }
} }
// Every field below that a client can influence is
// truncated to a fixed budget, so the size of this
// line does not track the size of the request.
s.log.Info("http request", s.log.Info("http request",
"request_start", start, "request_start", start,
"method", r.Method, "method", truncateLogField(
"url", r.URL.String(), r.Method, maxLogMethodBytes,
"useragent", r.UserAgent(), ),
"request_id", requestID, "url", truncateLogField(
"referer", r.Referer(), accessLogURL(r, lrw.statusCode),
maxLogFieldBytes,
),
"useragent", truncateLogField(
r.UserAgent(), maxLogFieldBytes,
),
"request_id", truncateLogField(
requestID, maxLogRequestIDBytes,
),
"referer", truncateLogField(
r.Referer(), maxLogFieldBytes,
),
"proto", r.Proto, "proto", r.Proto,
"remoteIP", ipFromHostPort(r.RemoteAddr), "remoteIP", ipFromHostPort(r.RemoteAddr),
"status", lrw.statusCode, "status", lrw.statusCode,

152
script/ci-mark-superseded Executable file
View File

@@ -0,0 +1,152 @@
#!/bin/sh
# script/ci-mark-superseded: record an honest status on commits whose CI
# run Gitea cancelled because a newer commit landed on the same branch.
# Gitea writes `failure` / "Has been cancelled" for such a run, which
# reads as a test result on a commit nothing ever tested. Cancellation is
# unconditional server-side for push events, so the superseding run
# rewrites those statuses to `failure` with a description that says the
# commit was never tested. `skipped` cannot be used: Gitea's combined
# status folds `skipped` into `success`, so a never-tested commit would
# report green. Genuine failures and successes are never touched.
#
# Called by the Gitea Actions workflow, which supplies GITHUB_API_URL,
# GITHUB_REPOSITORY, GITHUB_SHA, GITHUB_WORKFLOW, GITHUB_JOB,
# GITHUB_EVENT_NAME and GITEA_TOKEN. ANCESTOR_LIMIT (default 20) caps how
# far back the walk looks; a value that is set but not a positive integer
# aborts rather than silently disabling the walk.
set -eu
SUPERSEDED_DESC='Superseded by a newer commit; never tested'
# Gitea builds the commit-status context as
# "<workflow name> / <job name> (<event>)", so derive it rather than
# hardcoding the result.
#
# The derivation is deliberately not byte-exact with Gitea's own rule and
# must not be "fixed" into a silent fallback. Gitea uses the job's `name:`
# (falling back to the job id) and the workflow's `name:` (falling back to
# the workflow filename), while the runner exports GITHUB_JOB as the job
# *id* and GITHUB_WORKFLOW as the parsed workflow `name:`. So giving the
# job a display `name:`, or dropping the workflow's `name:`, makes the
# derived context stop matching --- and require_own_context below then
# turns every push red with a message. That loud failure is the point
# (https://git.eeqj.de/sneak/webhooker/issues/147 item 2); guessing at a
# fallback would restore the silent no-op it replaced.
context() {
printf '%s / %s (%s)' \
"$GITHUB_WORKFLOW" "$GITHUB_JOB" "$GITHUB_EVENT_NAME"
}
# ANCESTOR_LIMIT is a documented knob, so a value that is set but
# unusable must fail loudly instead of defaulting
# (https://git.eeqj.de/sneak/webhooker/issues/80). Passing it straight to
# git would print `fatal: not an integer` into a discarded exit status
# and mark nothing.
ancestor_limit() {
# `-` and not `:-`: an explicitly empty value is set-but-unusable
# config, so it aborts like any other bad value rather than silently
# running at the default.
_limit="${ANCESTOR_LIMIT-20}"
case "$_limit" in
'' | *[!0-9]* | 0*)
echo "ANCESTOR_LIMIT must be a positive integer," \
"got '${_limit}'" >&2
return 1
;;
esac
printf '%s' "$_limit"
}
# The status Gitea created for this very job proves which context string
# it uses. If the derived one is missing, the workflow or the job was
# renamed and the match below would silently stop firing, restoring the
# false-red bug with no signal. Fail loudly instead.
require_own_context() {
if ! _body="$(curl -sf --retry 3 --retry-delay 2 --max-time 30 \
"${1}/commits/${GITHUB_SHA}/status")"; then
echo "cannot read commit statuses for ${GITHUB_SHA}" >&2
return 1
fi
_found="$(printf '%s' "$_body" | jq -r '(.statuses // [])[].context')"
if printf '%s\n' "$_found" | grep -qxF "$2"; then
return 0
fi
echo "no commit status with context '${2}' on ${GITHUB_SHA}:" >&2
echo "workflow or job renamed? contexts present:" >&2
printf '%s\n' "$_found" >&2
return 1
}
# Latest status for our context on a commit, as "state|description".
# The read is retried and bounded, and a read that still fails aborts the
# step: a laundered commit that cannot be read is not the same as one
# with nothing to do, and piping curl into jq would discard the
# difference.
status_of() {
if ! _sbody="$(curl -sf --retry 3 --retry-delay 2 --max-time 30 \
"${1}/commits/${2}/status")"; then
echo "cannot read commit statuses for ${2}" >&2
return 1
fi
printf '%s' "$_sbody" | jq -r --arg c "$3" \
'[(.statuses // [])[] | select(.context == $c)][0] // empty
| "\(.status)|\(.description)"'
}
mark_superseded() {
curl -sf -X POST "${1}/statuses/${2}" \
-H "Authorization: token ${GITEA_TOKEN}" \
-H 'Content-Type: application/json' \
-d "$(jq -nc --arg c "$3" --arg d "$SUPERSEDED_DESC" \
'{context: $c, state: "failure", description: $d}')" \
>/dev/null
}
main() {
_api="${GITHUB_API_URL}/repos/${GITHUB_REPOSITORY}"
_ctx="$(context)"
_limit="$(ancestor_limit)"
require_own_context "$_api" "$_ctx"
# A shallow clone cannot resolve the parent, so it looks exactly like
# a root commit to rev-parse below and would exit 0 having walked
# nothing (or, at depth > 1, only the ancestors that happen to be
# present). The workflow checks out with `fetch-depth: 0`; verify
# that here rather than depend on it silently.
if [ "$(git rev-parse --is-shallow-repository)" = 'true' ]; then
echo "shallow repository: the ancestor walk needs full history" >&2
return 1
fi
# A root commit legitimately has no ancestors and is not an error.
# A SHA this repository does not have lands here too, since its
# parent is equally unresolvable, but require_own_context above has
# already aborted on the 404 for it. The walk itself carries no
# `|| true`, so a rev-list failure aborts.
if ! git rev-parse -q --verify "${GITHUB_SHA}^" >/dev/null; then
echo "no ancestor of ${GITHUB_SHA} to check"
return 0
fi
_walk="$(git rev-list --max-count="$_limit" "${GITHUB_SHA}^")"
for _sha in $_walk; do
_latest="$(status_of "$_api" "$_sha" "$_ctx")"
# A run that was cancelled, or one an earlier revision of this
# script laundered into `skipped`. Anything else stands.
case "$_latest" in
'failure|Has been cancelled' | "skipped|${SUPERSEDED_DESC}") ;;
*) continue ;;
esac
mark_superseded "$_api" "$_sha" "$_ctx"
echo "marked superseded: ${_sha}"
done
}
main "$@"