clawbot
f61d821215
check / check (push) Successful in 3m45s
Each request log line now has the fields "Request log" in SPEC.md lists whose features are built: instance (SWWAF_INSTANCE_NAME), scheme, request_id (a trusted proxy's X-Request-ID or a new one, sent on to the app), forwarded_for, client_group, content_type, content_length, the headers SWWAF_LOG_REQUEST_HEADERS names, has_authorization, has_cookie, websocket, response_content_type, cache_control, location, counts, duration_checks, duration_upstream_connect and duration_upstream_first_byte. A field that does not apply is left out. Authorization, Cookie and Set-Cookie values are never logged. Deviation: counts has request totals only; byte totals come with the byte limits. Deviation: SWWAF_INSTANCE_NAME is on request lines only, not yet on process lines or metrics. Judgement call: the headers go under request_headers, a name SPEC.md does not give. Model: opus-5-5
96 lines
2.4 KiB
Go
96 lines
2.4 KiB
Go
package requestlog_test
|
|
|
|
import (
|
|
"bytes"
|
|
"encoding/json"
|
|
"strings"
|
|
"testing"
|
|
"time"
|
|
|
|
"sneak.berlin/go/smallwebwaf/internal/requestlog"
|
|
)
|
|
|
|
func TestWriteWritesOneJSONLineMarkedRequest(t *testing.T) {
|
|
t.Parallel()
|
|
|
|
var out bytes.Buffer
|
|
|
|
err := requestlog.Write(&out, &requestlog.Line{
|
|
Time: requestlog.FormatTime(time.Date(2026, 10, 3, 12, 0, 0, 0, time.UTC)),
|
|
ClientIP: "203.0.113.9",
|
|
Status: 200,
|
|
Action: requestlog.ActionForward,
|
|
DurationTotal: requestlog.Milliseconds(1500 * time.Microsecond),
|
|
})
|
|
if err != nil {
|
|
t.Fatalf("write: %v", err)
|
|
}
|
|
|
|
text := out.String()
|
|
if strings.Count(text, "\n") != 1 || !strings.HasSuffix(text, "\n") {
|
|
t.Fatalf("wrote %q, want one line", text)
|
|
}
|
|
|
|
var fields map[string]any
|
|
|
|
err = json.Unmarshal(out.Bytes(), &fields)
|
|
if err != nil {
|
|
t.Fatalf("decode %q: %v", text, err)
|
|
}
|
|
|
|
want := map[string]any{
|
|
"type": "request", "time": "2026-10-03T12:00:00.000Z",
|
|
"client_ip": "203.0.113.9", "status": 200.0, "action": "forward",
|
|
"duration_total": 1.5,
|
|
}
|
|
for name, value := range want {
|
|
if fields[name] != value {
|
|
t.Errorf("%s is %v, want %v", name, fields[name], value)
|
|
}
|
|
}
|
|
|
|
unset := []string{
|
|
"forwarded_for", "content_type", "content_length", "request_headers",
|
|
"has_authorization", "has_cookie", "websocket", "response_content_type",
|
|
"upstream_status", "cache_control", "location", "aborted", "counts",
|
|
"limit_hit", "offence", "ban_expires", "duration_checks",
|
|
"duration_upstream_connect", "duration_upstream_first_byte",
|
|
"duration_upstream_total",
|
|
}
|
|
for _, name := range unset {
|
|
_, present := fields[name]
|
|
if present {
|
|
t.Errorf("%s is there with no value to give", name)
|
|
}
|
|
}
|
|
}
|
|
|
|
func TestProcessLinesAreMarkedProcess(t *testing.T) {
|
|
t.Parallel()
|
|
|
|
var out bytes.Buffer
|
|
|
|
requestlog.NewProcessLogger(&out).Info("starting", "version", "v1")
|
|
|
|
var fields map[string]any
|
|
|
|
err := json.Unmarshal(out.Bytes(), &fields)
|
|
if err != nil {
|
|
t.Fatalf("decode %q: %v", out.String(), err)
|
|
}
|
|
|
|
if fields["type"] != "process" || fields["msg"] != "starting" ||
|
|
fields["level"] != "INFO" || fields["version"] != "v1" {
|
|
t.Errorf("process line %v", fields)
|
|
}
|
|
|
|
timeText, _ := fields["time"].(string)
|
|
|
|
logged, err := time.Parse(time.RFC3339, timeText)
|
|
if err != nil || !strings.HasSuffix(timeText, "Z") ||
|
|
len(timeText) != len("2006-01-02T15:04:05.000Z") ||
|
|
time.Since(logged) > time.Minute {
|
|
t.Errorf("process line time %q, want now in UTC with milliseconds", timeText)
|
|
}
|
|
}
|