Compare commits
3 Commits
cc5836d1f9
...
376ec2de92
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
376ec2de92 | ||
| 5888d14438 | |||
| 7702f38168 |
@@ -13,39 +13,19 @@ jobs:
|
||||
uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683 # v4.2.2 2024-10-23
|
||||
with:
|
||||
# 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
|
||||
|
||||
- name: Neutralize superseded run statuses
|
||||
- name: Mark superseded run statuses
|
||||
# Gitea cancels the in-flight run when another commit is pushed to the
|
||||
# same branch and records the cancellation as `failure`, so a commit
|
||||
# that was never tested reads red. The cancellation is unconditional
|
||||
# server-side for push events and cannot be disabled from a workflow
|
||||
# file, so the superseding run rewrites those statuses to `skipped`.
|
||||
# Only the exact cancellation status is touched; a real failure is
|
||||
# left alone.
|
||||
# that was never tested reads as a test result. The script rewrites
|
||||
# those statuses to say what happened. See its header for why the
|
||||
# state stays `failure` and not `skipped`.
|
||||
env:
|
||||
GITEA_TOKEN: ${{ secrets.GITEA_TOKEN }}
|
||||
run: |
|
||||
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
|
||||
run: script/ci-mark-superseded
|
||||
|
||||
- name: Fingerprint the build context
|
||||
# `.dockerignore` keeps docs out of the build context, so a docs-only
|
||||
|
||||
@@ -37,7 +37,9 @@ FROM golang:1.26.1-bookworm@sha256:4465644228bc2857a954b092167e12aa59c006a349228
|
||||
# Depend on lint stage passing
|
||||
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
|
||||
|
||||
|
||||
120
README.md
120
README.md
@@ -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/cibuild` — CI entrypoint: `docker build .` (the Dockerfile
|
||||
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/check`)
|
||||
- `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
|
||||
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
|
||||
bounded by neither limit: every request is recorded once at `INFO` with
|
||||
its full URL, served or rejected alike.
|
||||
bounded by neither limit: every request is recorded once at `INFO`,
|
||||
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
|
||||
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
|
||||
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
|
||||
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
|
||||
module downloads are not repeated. Invalidation is scoped to the one
|
||||
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
|
||||
verify` is documented as fetching its JSON schema over HTTPS, which
|
||||
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
|
||||
linked, which is what lets it run on the Alpine runtime image.
|
||||
|
||||
`script/cibuild` — `docker build .` — is the CI gate: the four check
|
||||
targets run inside the image, so a build that succeeds is a repo that
|
||||
is formatted, linted, tested and compiled. `script/lint` also uses
|
||||
Docker (`Dockerfile.lint`, see Linting above), so `make lint` and
|
||||
`make check` run the same pinned linter version the gate does; only
|
||||
`script/test` and `script/fmt-check` run on the host.
|
||||
`script/cibuild` — `docker build .` — is the CI gate: the checks run
|
||||
inside the image, so a build that succeeds is a repo that is formatted,
|
||||
linted, tested and compiled. `script/lint` also uses Docker
|
||||
(`Dockerfile.lint`, see Linting above), so `make lint` and `make check`
|
||||
run the same pinned linter version the gate does; only `script/test`
|
||||
and `script/fmt-check` run on the host.
|
||||
|
||||
#### CI gate honesty
|
||||
|
||||
@@ -1474,11 +1545,32 @@ way.
|
||||
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
|
||||
commit lands on the same branch and records that cancellation as a
|
||||
`failure` status, marking a commit red that was never tested.
|
||||
Cancellation is unconditional server-side for
|
||||
push events, so the superseding run rewrites the exact
|
||||
`Has been cancelled` status to `skipped`. Genuine failures are never
|
||||
touched.
|
||||
`failure` status, so a commit nothing ever tested reads as a test
|
||||
result. Cancellation is unconditional server-side for push events, so
|
||||
the superseding run calls `script/ci-mark-superseded`, which rewrites
|
||||
that exact status to `failure` /
|
||||
`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
|
||||
|
||||
|
||||
2
go.mod
2
go.mod
@@ -17,6 +17,7 @@ require (
|
||||
github.com/stretchr/testify v1.8.4
|
||||
go.uber.org/fx v1.20.1
|
||||
golang.org/x/crypto v0.38.0
|
||||
gopkg.in/yaml.v3 v3.0.1
|
||||
gorm.io/driver/sqlite v1.5.4
|
||||
gorm.io/gorm v1.25.5
|
||||
modernc.org/sqlite v1.28.0
|
||||
@@ -52,7 +53,6 @@ require (
|
||||
golang.org/x/text v0.25.0 // indirect
|
||||
golang.org/x/tools v0.21.1-0.20240508182429-e35e4ccd0d2d // indirect
|
||||
google.golang.org/protobuf v1.31.0 // indirect
|
||||
gopkg.in/yaml.v3 v3.0.1 // indirect
|
||||
lukechampine.com/uint128 v1.2.0 // indirect
|
||||
modernc.org/cc/v3 v3.40.0 // indirect
|
||||
modernc.org/ccgo/v3 v3.16.13 // indirect
|
||||
|
||||
387
internal/ciscript/ci_mark_superseded_test.go
Normal file
387
internal/ciscript/ci_mark_superseded_test.go
Normal 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
10
internal/ciscript/doc.go
Normal 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
|
||||
162
internal/ciscript/fakegitea_test.go
Normal file
162
internal/ciscript/fakegitea_test.go
Normal 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)
|
||||
}
|
||||
658
internal/middleware/accesslog_test.go
Normal file
658
internal/middleware/accesslog_test.go
Normal 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"])
|
||||
}
|
||||
@@ -6,9 +6,13 @@ import (
|
||||
"log/slog"
|
||||
"net"
|
||||
"net/http"
|
||||
"strings"
|
||||
"time"
|
||||
"unicode"
|
||||
"unicode/utf8"
|
||||
|
||||
basicauth "github.com/99designs/basicauth-go"
|
||||
"github.com/go-chi/chi"
|
||||
"github.com/go-chi/chi/middleware"
|
||||
"github.com/go-chi/cors"
|
||||
metrics "github.com/slok/go-http-metrics/metrics/prometheus"
|
||||
@@ -25,6 +29,75 @@ const (
|
||||
// corsMaxAge is the maximum time (in seconds) that a
|
||||
// preflight response can be cached.
|
||||
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.
|
||||
@@ -94,6 +167,178 @@ func (lrw *loggingResponseWriter) WriteHeader(code int) {
|
||||
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
|
||||
// timing and metadata.
|
||||
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",
|
||||
"request_start", start,
|
||||
"method", r.Method,
|
||||
"url", r.URL.String(),
|
||||
"useragent", r.UserAgent(),
|
||||
"request_id", requestID,
|
||||
"referer", r.Referer(),
|
||||
"method", truncateLogField(
|
||||
r.Method, maxLogMethodBytes,
|
||||
),
|
||||
"url", truncateLogField(
|
||||
accessLogURL(r, lrw.statusCode),
|
||||
maxLogFieldBytes,
|
||||
),
|
||||
"useragent", truncateLogField(
|
||||
r.UserAgent(), maxLogFieldBytes,
|
||||
),
|
||||
"request_id", truncateLogField(
|
||||
requestID, maxLogRequestIDBytes,
|
||||
),
|
||||
"referer", truncateLogField(
|
||||
r.Referer(), maxLogFieldBytes,
|
||||
),
|
||||
"proto", r.Proto,
|
||||
"remoteIP", ipFromHostPort(r.RemoteAddr),
|
||||
"status", lrw.statusCode,
|
||||
|
||||
152
script/ci-mark-superseded
Executable file
152
script/ci-mark-superseded
Executable 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 "$@"
|
||||
Reference in New Issue
Block a user