diff --git a/README.md b/README.md index 7060966..a862563 100644 --- a/README.md +++ b/README.md @@ -210,9 +210,11 @@ effective settings are logged at start. `https`, a host and an optional port, and nothing more. - `SWWAF_INSTANCE_NAME` (default: the host's name, which docker sets to the first 12 characters of the container's id unless the deployment names one): - the name each request log line gives as `instance`. Set it, for example to + the name every log line and alert gives as `instance`, and every metric + carries as its label `instance` (see "Metrics" below). Set it, for example to `fsn1app1/gitea`, for a name that stays the same when a deploy replaces the - container, and that tells instances apart when several log to one place. + container, and that tells instances apart when several log to one place. A + name that is not valid UTF-8, such as one saved in Latin-1, stops the start. - `SWWAF_MODE` (default `enforce`): `enforce`, or `observe` to pass on the requests `smallwebwaf` would refuse and log what it would have done (see "What it does so far" above). @@ -513,7 +515,7 @@ A field that does not apply to a request is left out of its line, apart from No body is logged, and no header but those above. `smallwebwaf`'s own messages (start, the settings, stop, errors) share the stream as JSON lines marked -`"type":"process"`. +`"type":"process"`, each with `instance` as a request's line has it. Go's HTTP server, on which `smallwebwaf` is built, reads a request's line and headers before `smallwebwaf` sees the request, and some requests end there, @@ -897,6 +899,13 @@ empty directory or set `SWWAF_RULES_ENABLED=false`. format, for a scraper that sends `SWWAF_METRICS_TOKEN`, through traefik like any other request. No metric carries a client's address. +Every metric below, Go's and the process's included, carries the label +`instance`, `SWWAF_INSTANCE_NAME`, as a constant label set once on the registry +the metrics are kept in, rather than as a label each metric declares. Prometheus +gives each series it scrapes an `instance` label of its own, the address it +scraped, and keeps this one as `exported_instance` unless the scrape sets +`honor_labels: true`. + - `smallwebwaf_requests_total`, `smallwebwaf_request_bytes_total` and `smallwebwaf_response_bytes_total`: requests, and their body bytes each way, by `status_class`, such as `2xx`, or `none` when nothing was sent, and by diff --git a/internal/config/config.go b/internal/config/config.go index 1f4e59e..dd759fb 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -34,9 +34,10 @@ type Config struct { ListenAddr string // UpstreamURL is the app (SWWAF_UPSTREAM_URL). UpstreamURL *url.URL - // InstanceName is the name each request log line gives as instance - // (SWWAF_INSTANCE_NAME), by default the host's name, which docker sets - // to the first 12 characters of the container's id. + // InstanceName is the name every log line and alert gives as instance, + // and every metric carries as its label instance (SWWAF_INSTANCE_NAME), + // by default the host's name, which docker sets to the first 12 + // characters of the container's id. InstanceName string // Observe is true in observe mode, when SWWAF_MODE is observe rather // than enforce: a request that SWWAF_DENY_NETS, a ban, the country @@ -267,6 +268,7 @@ var ( "is not ban, permanent_ban, waf_block, anomaly, reputation_hit, " + "source_failure or file_error") errNotNumberOrOff = errors.New("is not a whole number above zero, such as 60, or off") + errNotUTF8 = errors.New("is not valid UTF-8") ) // FromEnvironment reads the settings with lookupEnv, normally @@ -276,11 +278,10 @@ var ( // setting that is set but invalid is an error that names it. func FromEnvironment(lookupEnv func(string) (string, bool)) (*Config, error) { env := &environment{lookupEnv: lookupEnv} - hostname, _ := os.Hostname() // "" when the host has no name to give cfg := &Config{ ListenAddr: env.address("SWWAF_LISTEN_ADDR", defaultListenAddr), UpstreamURL: env.appURL("SWWAF_UPSTREAM_URL", defaultUpstreamURL), - InstanceName: env.value("SWWAF_INSTANCE_NAME", hostname), + InstanceName: env.instanceName(), Observe: env.observe("SWWAF_MODE", "enforce"), TrustedProxies: env.netblocks("SWWAF_TRUSTED_PROXIES", privateRanges), ClientRequestTimeout: env.duration("SWWAF_CLIENT_REQUEST_TIMEOUT", "60s"), @@ -373,6 +374,16 @@ func ListenAddrAndUpstreamURL( return listenAddr, upstreamURL, nil } +// InstanceName reads only SWWAF_INSTANCE_NAME, which may be given as a +// file, as FromEnvironment does, so that the line saying a setting is +// invalid carries it too. A file that cannot be read gives the default +// here, and FromEnvironment then stops the start over it. +func InstanceName(lookupEnv func(string) (string, bool)) string { + env := &environment{lookupEnv: lookupEnv} + + return env.instanceName() +} + // privateRanges are the private address ranges, the default trusted // proxies. const privateRanges = "10.0.0.0/8,172.16.0.0/12,192.168.0.0/16" @@ -660,6 +671,19 @@ func (e *environment) facility(name, defaultValue string) int { return number } +// instanceName reads SWWAF_INSTANCE_NAME, by default the host's name. It +// must be valid UTF-8: the metrics library panics on a label that is not. +func (e *environment) instanceName() string { + hostname, _ := os.Hostname() // "" when the host has no name to give + + value := e.value("SWWAF_INSTANCE_NAME", hostname) + if !utf8.ValidString(value) { + e.check("SWWAF_INSTANCE_NAME", fmt.Errorf("%q %w", value, errNotUTF8)) + } + + return value +} + // appName reads the setting that is the APP-NAME of the records the log // lines are sent in, by default the instance name. Its value is checked // when it is set, and, while lines are sent, when it is the instance name. diff --git a/internal/config/config_test.go b/internal/config/config_test.go index f1df225..ecd53fa 100644 --- a/internal/config/config_test.go +++ b/internal/config/config_test.go @@ -737,6 +737,25 @@ func TestInstanceNameWithAControlCharacterStopsTheStartOnlyWithNtfySet(t *testin } } +func TestInstanceNameNotUTF8StopsTheStart(t *testing.T) { + t.Parallel() + + // café saved in Latin-1. + const latin1 = "caf\xe9" + + for name, env := range map[string]environment{ + "set": {instanceName: latin1}, + "in a file": {instanceName + "_FILE": writeFile(t, latin1+"\n")}, + } { + _, err := config.FromEnvironment(env.lookupEnv) + + want := instanceName + `: "caf\xe9" is not valid UTF-8` + if err == nil || err.Error() != want { + t.Errorf("%s: error %v, want %s", name, err, want) + } + } +} + func TestCodeOnBothCountryListsStopsTheStart(t *testing.T) { t.Parallel() diff --git a/internal/lookup/lookup_test.go b/internal/lookup/lookup_test.go index 8f24cc6..1f85297 100644 --- a/internal/lookup/lookup_test.go +++ b/internal/lookup/lookup_test.go @@ -199,7 +199,7 @@ func TestFailureIsLoggedWithoutTheAddressesAskedAbout(t *testing.T) { URL: lookup.URL, Now: time.Now, ProcessLog: slog.New(slog.NewTextHandler(&log, nil)), - Metrics: metrics.New(1), + Metrics: metrics.New(1, "app"), Alerts: alerts.New(alerts.Params{}), }) g.SetTransport(geojs) @@ -398,7 +398,7 @@ func TestClientsWithoutAnAnswerAreCounted(t *testing.T) { t.Parallel() synctest.Test(t, func(t *testing.T) { - m := metrics.New(1) + m := metrics.New(1, "app") g := lookup.New(lookup.Params{ URL: lookup.URL, Now: time.Now, @@ -589,7 +589,7 @@ func startWithAlerts() (*standIn, *testClock, *lookup.GeoJS, *alerts.Queue) { URL: lookup.URL, Now: clock.Now, ProcessLog: slog.New(slog.DiscardHandler), - Metrics: metrics.New(1), + Metrics: metrics.New(1, "app"), Alerts: queue, }) g.SetTransport(geojs) diff --git a/internal/metrics/metrics.go b/internal/metrics/metrics.go index 410f1f2..3eb8df2 100644 --- a/internal/metrics/metrics.go +++ b/internal/metrics/metrics.go @@ -21,7 +21,8 @@ import ( // Metrics are smallwebwaf's metrics. They are safe for concurrent use. type Metrics struct { - registry *prometheus.Registry + // registry gives every metric registered with it the label instance. + registry prometheus.Registerer handler http.Handler inFlight prometheus.Gauge @@ -55,13 +56,17 @@ type Metrics struct { // New returns the metrics, with the Go runtime's and the process's own. // topN is how many countries get series of their own -// (SWWAF_METRICS_TOP_N). -func New(topN int) *Metrics { +// (SWWAF_METRICS_TOP_N). Every metric carries instanceName +// (SWWAF_INSTANCE_NAME) as its label instance. +func New(topN int, instanceName string) *Metrics { byStatus := []string{"status_class", "action"} byFile := []string{"file"} + registry := prometheus.NewRegistry() m := &Metrics{ - registry: prometheus.NewRegistry(), + registry: prometheus.WrapRegistererWith( + prometheus.Labels{"instance": instanceName}, registry), + handler: promhttp.HandlerFor(registry, promhttp.HandlerOpts{}), inFlight: prometheus.NewGauge(prometheus.GaugeOpts{ Name: "smallwebwaf_requests_in_flight", Help: "Requests under way.", @@ -119,8 +124,6 @@ func New(topN int) *Metrics { byFile), } - m.handler = promhttp.HandlerFor(m.registry, promhttp.HandlerOpts{}) - m.registry.MustRegister( collectors.NewGoCollector(), collectors.NewProcessCollector(collectors.ProcessCollectorOpts{}), diff --git a/internal/proxy/metrics_test.go b/internal/proxy/metrics_test.go index 1d82beb..a6c3881 100644 --- a/internal/proxy/metrics_test.go +++ b/internal/proxy/metrics_test.go @@ -148,8 +148,8 @@ func TestMetricsCountTheTraffic(t *testing.T) { wantStatus(t, get(t, addr, "/_smallwebwaf/nothing"), http.StatusNotFound) out.requestLines(t, 2) - forward := `{action="forward",status_class="2xx"}` - notFound := `{action="admin",status_class="4xx"}` + forward := `{action="forward",instance="app",status_class="2xx"}` + notFound := `{action="admin",instance="app",status_class="4xx"}` // The request for the metrics is itself under way. metrics := scrape(t, addr) @@ -159,11 +159,13 @@ func TestMetricsCountTheTraffic(t *testing.T) { wantMetric(t, metrics, "smallwebwaf_response_bytes_total"+forward, 5) wantMetric(t, metrics, "smallwebwaf_response_bytes_total"+notFound, float64(len("Not Found\n"))) - wantMetric(t, metrics, "smallwebwaf_request_duration_seconds_count", 2) - wantMetric(t, metrics, "smallwebwaf_upstream_duration_seconds_count", 1) - wantMetric(t, metrics, "smallwebwaf_requests_in_flight", 1) - metric(t, metrics, "go_goroutines") - metric(t, metrics, "process_start_time_seconds") + wantMetric(t, metrics, + `smallwebwaf_request_duration_seconds_count{instance="app"}`, 2) + wantMetric(t, metrics, + `smallwebwaf_upstream_duration_seconds_count{instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_requests_in_flight{instance="app"}`, 1) + metric(t, metrics, `go_goroutines{instance="app"}`) + metric(t, metrics, `process_start_time_seconds{instance="app"}`) // A request the app holds is under way until it ends. httpClient := newClient(t) @@ -180,7 +182,7 @@ func TestMetricsCountTheTraffic(t *testing.T) { }() <-arrived - wantMetric(t, scrape(t, addr), "smallwebwaf_requests_in_flight", 2) + wantMetric(t, scrape(t, addr), `smallwebwaf_requests_in_flight{instance="app"}`, 2) releaseApp() err := <-ended @@ -189,7 +191,7 @@ func TestMetricsCountTheTraffic(t *testing.T) { } out.requestLines(t, 5) - wantMetric(t, scrape(t, addr), "smallwebwaf_requests_in_flight", 1) + wantMetric(t, scrape(t, addr), `smallwebwaf_requests_in_flight{instance="app"}`, 1) } func TestMetricsCountLimitsAndBans(t *testing.T) { @@ -219,15 +221,16 @@ func TestMetricsCountLimitsAndBans(t *testing.T) { metrics := s.scrape(scraper) wantMetric(t, metrics, - `smallwebwaf_requests_total{action="denied",status_class="none"}`, 1) - wantMetric(t, metrics, `smallwebwaf_rate_limit_hits_total{window="minute"}`, 1) - wantMetric(t, metrics, `smallwebwaf_offences_total{kind="limit"}`, 1) - wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit"}`, 1) - wantMetric(t, metrics, "smallwebwaf_active_bans", 1) - wantMetric(t, metrics, "smallwebwaf_permanent_bans", 0) + `smallwebwaf_requests_total{action="denied",instance="app",status_class="none"}`, 1) + wantMetric(t, metrics, + `smallwebwaf_rate_limit_hits_total{instance="app",window="minute"}`, 1) + wantMetric(t, metrics, `smallwebwaf_offences_total{instance="app",kind="limit"}`, 1) + wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit",instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_active_bans{instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_permanent_bans{instance="app"}`, 0) clk.advance(time.Hour) - wantMetric(t, s.scrape(scraper), "smallwebwaf_active_bans", 0) + wantMetric(t, s.scrape(scraper), `smallwebwaf_active_bans{instance="app"}`, 0) // A limit broken again right after would ban for three hours, longer // than SWWAF_MAX_BAN_DURATION, so the ban is permanent. @@ -235,13 +238,14 @@ func TestMetricsCountLimitsAndBans(t *testing.T) { s.get(client, 0, requestlog.ActionRateLimited) metrics = s.scrape(scraper) - wantMetric(t, metrics, `smallwebwaf_rate_limit_hits_total{window="minute"}`, 2) - wantMetric(t, metrics, `smallwebwaf_offences_total{kind="limit"}`, 2) - wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit"}`, 2) - wantMetric(t, metrics, "smallwebwaf_active_bans", 1) - wantMetric(t, metrics, "smallwebwaf_permanent_bans", 1) + wantMetric(t, metrics, + `smallwebwaf_rate_limit_hits_total{instance="app",window="minute"}`, 2) + wantMetric(t, metrics, `smallwebwaf_offences_total{instance="app",kind="limit"}`, 2) + wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit",instance="app"}`, 2) + wantMetric(t, metrics, `smallwebwaf_active_bans{instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_permanent_bans{instance="app"}`, 1) // denied, client, and the scraper as of its earlier requests. - wantMetric(t, metrics, "smallwebwaf_tracked_clients", 3) + wantMetric(t, metrics, `smallwebwaf_tracked_clients{instance="app"}`, 3) } func TestMetricsCountTheBansAnAdminMakes(t *testing.T) { @@ -255,7 +259,7 @@ func TestMetricsCountTheBansAnAdminMakes(t *testing.T) { rateLimitExemptNets: scraper, }) - const admins = `smallwebwaf_bans_made_total{cause="admin"}` + const admins = `smallwebwaf_bans_made_total{cause="admin",instance="app"}` wantMetric(t, s.scrape(scraper), admins, 0) @@ -319,28 +323,42 @@ func TestMetricsByCountryKeepTheBusiestAndCountTheRestAsOther(t *testing.T) { metrics := scrape(t, addr) lines++ - wantMetric(t, metrics, `smallwebwaf_country_requests_total{country="KP"}`, 3) - wantMetric(t, metrics, `smallwebwaf_country_requests_total{country="DE"}`, 2) - wantMetric(t, metrics, `smallwebwaf_country_requests_total{country="other"}`, 1) - wantMetric(t, metrics, `smallwebwaf_country_list_refusals_total{country="KP"}`, 3) - wantMetric(t, metrics, `smallwebwaf_country_request_bytes_total{country="KP"}`, 0) - wantMetric(t, metrics, `smallwebwaf_country_request_bytes_total{country="DE"}`, 6) - wantMetric(t, metrics, `smallwebwaf_country_response_bytes_total{country="KP"}`, + wantMetric(t, metrics, + `smallwebwaf_country_requests_total{country="KP",instance="app"}`, 3) + wantMetric(t, metrics, + `smallwebwaf_country_requests_total{country="DE",instance="app"}`, 2) + wantMetric(t, metrics, + `smallwebwaf_country_requests_total{country="other",instance="app"}`, 1) + wantMetric(t, metrics, + `smallwebwaf_country_list_refusals_total{country="KP",instance="app"}`, 3) + wantMetric(t, metrics, + `smallwebwaf_country_request_bytes_total{country="KP",instance="app"}`, 0) + wantMetric(t, metrics, + `smallwebwaf_country_request_bytes_total{country="DE",instance="app"}`, 6) + wantMetric(t, metrics, + `smallwebwaf_country_response_bytes_total{country="KP",instance="app"}`, float64(3*len("Forbidden\n"))) - wantMetric(t, metrics, `smallwebwaf_country_response_bytes_total{country="other"}`, + wantMetric(t, metrics, + `smallwebwaf_country_response_bytes_total{country="other",instance="app"}`, float64(len("hello"))) - wantNoSeries(t, metrics, `smallwebwaf_country_requests_total{country="FR"}`) + wantNoSeries(t, metrics, + `smallwebwaf_country_requests_total{country="FR",instance="app"}`) // Once FR is busier than DE, it takes DE's place: its series counts // from then on, and DE's is gone. send(fromFR, 3, http.StatusOK) metrics = scrape(t, addr) - wantMetric(t, metrics, `smallwebwaf_country_requests_total{country="KP"}`, 3) - wantMetric(t, metrics, `smallwebwaf_country_requests_total{country="FR"}`, 2) - wantMetric(t, metrics, `smallwebwaf_country_requests_total{country="other"}`, 2) - wantNoSeries(t, metrics, `smallwebwaf_country_requests_total{country="DE"}`) - wantNoSeries(t, metrics, `smallwebwaf_country_request_bytes_total{country="DE"}`) + wantMetric(t, metrics, + `smallwebwaf_country_requests_total{country="KP",instance="app"}`, 3) + wantMetric(t, metrics, + `smallwebwaf_country_requests_total{country="FR",instance="app"}`, 2) + wantMetric(t, metrics, + `smallwebwaf_country_requests_total{country="other",instance="app"}`, 2) + wantNoSeries(t, metrics, + `smallwebwaf_country_requests_total{country="DE",instance="app"}`) + wantNoSeries(t, metrics, + `smallwebwaf_country_request_bytes_total{country="DE",instance="app"}`) } func TestMetricsCountGeoJSRequestsAndFailures(t *testing.T) { @@ -370,16 +388,16 @@ func TestMetricsCountGeoJSRequestsAndFailures(t *testing.T) { deadline := time.Now().Add(waitLimit) metrics := scrape(t, addr) - for metric(t, metrics, "smallwebwaf_geojs_failures_total") == 0 && + for metric(t, metrics, `smallwebwaf_geojs_failures_total{instance="app"}`) == 0 && time.Now().Before(deadline) { time.Sleep(pollInterval) metrics = scrape(t, addr) } - wantMetric(t, metrics, "smallwebwaf_geojs_requests_total", 1) - wantMetric(t, metrics, "smallwebwaf_geojs_failures_total", 1) - wantMetric(t, metrics, "smallwebwaf_geojs_unanswered_total", 1) + wantMetric(t, metrics, `smallwebwaf_geojs_requests_total{instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_geojs_failures_total{instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_geojs_unanswered_total{instance="app"}`, 1) } // keptAnswer returns GeoJS's answer that the client at addr is in @@ -422,8 +440,9 @@ func (s *sender) scrape(from string) string { // metric returns the value of series in metrics, which are in the // Prometheus text format. series is a name and its labels in the order of -// their names, such as smallwebwaf_offences_total{kind="limit"}. It fails -// the test if there is no such series. +// their names, such as +// smallwebwaf_offences_total{instance="app",kind="limit"}. It fails the +// test if there is no such series. func metric(t *testing.T, metrics, series string) float64 { t.Helper() @@ -471,7 +490,8 @@ func wantNoSeries(t *testing.T, metrics, series string) { func wantLimitHits(t *testing.T, addr, limit string, hits int) { t.Helper() - series := `smallwebwaf_size_and_time_limit_hits_total{limit="` + limit + `"}` + series := `smallwebwaf_size_and_time_limit_hits_total{instance="app",limit="` + + limit + `"}` metrics := scrape(t, addr) if hits == 0 { diff --git a/internal/proxy/passthrough_test.go b/internal/proxy/passthrough_test.go index 5a7f015..c63ceb2 100644 --- a/internal/proxy/passthrough_test.go +++ b/internal/proxy/passthrough_test.go @@ -6,7 +6,6 @@ import ( "errors" "io" "net/http" - "os" "reflect" "slices" "strings" @@ -123,10 +122,8 @@ func wantAnswer(t *testing.T, got answer, body []byte) { func wantRequestFields(t *testing.T, line logLine, host string, sent, received int) { t.Helper() - hostname, _ := os.Hostname() - want := withTimings(line, requestlog.Line{ - Type: requestType, Time: line.Time, Instance: hostname, + Type: requestType, Time: line.Time, Instance: "app", ClientIP: localhost, Method: http.MethodPatch, Scheme: plain, Host: host, Path: rawPath, Query: rawQuery, Protocol: protocol, Status: http.StatusTeapot, RequestBytes: int64(sent), @@ -318,7 +315,7 @@ func TestServerHasTheDefaultLimits(t *testing.T) { server := proxy.New(proxy.Params{ Config: cfg, RequestLog: io.Discard, - ProcessLog: requestlog.NewProcessLogger(io.Discard), + ProcessLog: requestlog.NewProcessLogger(io.Discard, cfg.InstanceName), }) if server.Addr != ":8080" || server.MaxHeaderBytes != 28<<10 || diff --git a/internal/proxy/proxy.go b/internal/proxy/proxy.go index 1650cb6..21b1000 100644 --- a/internal/proxy/proxy.go +++ b/internal/proxy/proxy.go @@ -88,7 +88,7 @@ type Server struct { // applies the timeouts and size limits from then on. func New(params Params) *Server { errorLog := slog.NewLogLogger(params.ProcessLog.Handler(), slog.LevelWarn) - m := metrics.New(params.Config.MetricsTopN) + m := metrics.New(params.Config.MetricsTopN, params.Config.InstanceName) h := &handler{ config: params.Config, requestLog: params.RequestLog, diff --git a/internal/proxy/proxy_test.go b/internal/proxy/proxy_test.go index e47ed89..cb6fa66 100644 --- a/internal/proxy/proxy_test.go +++ b/internal/proxy/proxy_test.go @@ -217,7 +217,9 @@ func startProxyWithGeoJS( // startProxyWithClock is startProxyWithGeoJS with requests counted and // bans made by the time now tells, and returns the server as well. Unless -// env sets SWWAF_RULES_DIR, it is an empty directory, of no rules. +// env sets SWWAF_RULES_DIR, it is an empty directory, of no rules, and +// unless it sets SWWAF_INSTANCE_NAME, that is app, the label instance of +// every metric. func startProxyWithClock( t *testing.T, appURL, geojsURL string, now func() time.Time, env map[string]string, @@ -238,7 +240,9 @@ func startProxyWithAlerts( ) (string, *output, *proxy.Server, *alerts.Queue) { t.Helper() - settings := map[string]string{"SWWAF_UPSTREAM_URL": appURL, rulesDir: t.TempDir()} + settings := map[string]string{ + "SWWAF_UPSTREAM_URL": appURL, rulesDir: t.TempDir(), instanceName: "app", + } maps.Copy(settings, env) cfg, err := config.FromEnvironment(func(name string) (string, bool) { @@ -251,7 +255,7 @@ func startProxyWithAlerts( } out := &output{} - processLog := requestlog.NewProcessLogger(out) + processLog := requestlog.NewProcessLogger(out, cfg.InstanceName) ruleFiles, err := rules.Load(rules.Params{ Dir: cfg.RulesDir, Enabled: cfg.RulesEnabled, ProcessLog: processLog, diff --git a/internal/proxy/rulefiles_test.go b/internal/proxy/rulefiles_test.go index 7d85882..db27689 100644 --- a/internal/proxy/rulefiles_test.go +++ b/internal/proxy/rulefiles_test.go @@ -197,15 +197,15 @@ func TestMetricsCountRuleMatchesAndBansForAnAttack(t *testing.T) { metrics := s.scrape(scraper) wantMetric(t, metrics, - `smallwebwaf_rule_matches_total{action="block",rule_id="blocked"}`, 1) + `smallwebwaf_rule_matches_total{action="block",instance="app",rule_id="blocked"}`, 1) wantMetric(t, metrics, - `smallwebwaf_rule_matches_total{action="ban",rule_id="probe"}`, 1) - wantMetric(t, metrics, "smallwebwaf_rules_loaded", 2) - wantMetric(t, metrics, - `smallwebwaf_requests_total{action="rule_blocked",status_class="4xx"}`, 1) - wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="attack"}`, 1) - wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit"}`, 0) - wantMetric(t, metrics, "smallwebwaf_permanent_bans", 1) + `smallwebwaf_rule_matches_total{action="ban",instance="app",rule_id="probe"}`, 1) + wantMetric(t, metrics, `smallwebwaf_rules_loaded{instance="app"}`, 2) + wantMetric(t, metrics, `smallwebwaf_requests_total{action="rule_blocked",`+ + `instance="app",status_class="4xx"}`, 1) + wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="attack",instance="app"}`, 1) + wantMetric(t, metrics, `smallwebwaf_bans_made_total{cause="limit",instance="app"}`, 0) + wantMetric(t, metrics, `smallwebwaf_permanent_bans{instance="app"}`, 1) } // writeRules writes content as a rule file into a new directory, and diff --git a/internal/requestlog/requestlog.go b/internal/requestlog/requestlog.go index f7330c2..d18ffb2 100644 --- a/internal/requestlog/requestlog.go +++ b/internal/requestlog/requestlog.go @@ -171,8 +171,8 @@ func Milliseconds(d time.Duration) float64 { // NewProcessLogger returns the logger for the process's own messages: // JSON lines on w, marked "type":"process", with the time in the same form -// as a request line's. -func NewProcessLogger(w io.Writer) *slog.Logger { +// as a request line's, and instanceName, SWWAF_INSTANCE_NAME, as instance. +func NewProcessLogger(w io.Writer, instanceName string) *slog.Logger { handler := slog.NewJSONHandler(w, &slog.HandlerOptions{ ReplaceAttr: func(groups []string, attr slog.Attr) slog.Attr { if attr.Key == slog.TimeKey && len(groups) == 0 { @@ -183,5 +183,5 @@ func NewProcessLogger(w io.Writer) *slog.Logger { }, }) - return slog.New(handler).With("type", "process") + return slog.New(handler).With("type", "process", "instance", instanceName) } diff --git a/internal/requestlog/requestlog_test.go b/internal/requestlog/requestlog_test.go index 38303b6..eae737e 100644 --- a/internal/requestlog/requestlog_test.go +++ b/internal/requestlog/requestlog_test.go @@ -65,12 +65,12 @@ func TestWriteWritesOneJSONLineMarkedRequest(t *testing.T) { } } -func TestProcessLinesAreMarkedProcess(t *testing.T) { +func TestProcessLinesAreMarkedProcessAndGiveTheInstance(t *testing.T) { t.Parallel() var out bytes.Buffer - requestlog.NewProcessLogger(&out).Info("starting", "version", "v1") + requestlog.NewProcessLogger(&out, "fsn1app1/gitea").Info("starting", "version", "v1") var fields map[string]any @@ -79,8 +79,9 @@ func TestProcessLinesAreMarkedProcess(t *testing.T) { t.Fatalf("decode %q: %v", out.String(), err) } - if fields["type"] != "process" || fields["msg"] != "starting" || - fields["level"] != "INFO" || fields["version"] != "v1" { + if fields["type"] != "process" || fields["instance"] != "fsn1app1/gitea" || + fields["msg"] != "starting" || fields["level"] != "INFO" || + fields["version"] != "v1" { t.Errorf("process line %v", fields) } diff --git a/internal/smallwebwaf/smallwebwaf.go b/internal/smallwebwaf/smallwebwaf.go index 94113fb..b2c1fda 100644 --- a/internal/smallwebwaf/smallwebwaf.go +++ b/internal/smallwebwaf/smallwebwaf.go @@ -68,7 +68,8 @@ func Main(version string) int { // requests until ctx is done. It returns the process's exit status, 1 // when smallwebwaf cannot start. func Run(ctx context.Context, params Params) int { - processLog := requestlog.NewProcessLogger(params.Stdout) + processLog := requestlog.NewProcessLogger(params.Stdout, + config.InstanceName(params.LookupEnv)) cfg, err := config.FromEnvironment(params.LookupEnv) if err != nil { @@ -86,7 +87,7 @@ func Run(ctx context.Context, params Params) int { if cfg.LogRemoteURL != nil { remote = newRemoteLogSender(cfg) stdout = io.MultiWriter(params.Stdout, remote) - processLog = requestlog.NewProcessLogger(stdout) + processLog = requestlog.NewProcessLogger(stdout, cfg.InstanceName) stopSending := startSending(ctx, remote, processLog) defer stopSending() diff --git a/internal/smallwebwaf/smallwebwaf_test.go b/internal/smallwebwaf/smallwebwaf_test.go index e0e9099..bcc097b 100644 --- a/internal/smallwebwaf/smallwebwaf_test.go +++ b/internal/smallwebwaf/smallwebwaf_test.go @@ -38,10 +38,14 @@ const ( stateCounterInterval = "SWWAF_STATE_COUNTER_INTERVAL" rateLimitPerDay = "SWWAF_RATE_LIMIT_PER_DAY" rulesDir = "SWWAF_RULES_DIR" + instanceName = "SWWAF_INSTANCE_NAME" adminToken = "SWWAF_ADMIN_TOKEN" //nolint:gosec // the setting's name metricsToken = "SWWAF_METRICS_TOKEN" //nolint:gosec // the setting's name // adminSecret is the SWWAF_ADMIN_TOKEN the tests set. adminSecret = "fedcba9876543210fedcba9876543210" + // instance is the SWWAF_INSTANCE_NAME the tests set where they look at + // it. + instance = "fsn1app1/gitea" // greeting is what the tests' app answers. greeting = "hello from the app" ) @@ -118,7 +122,10 @@ func TestInvalidSettingStopsTheStart(t *testing.T) { out := &output{} - status := run(t.Context(), map[string]string{"SWWAF_REQUEST_MAX_BYTES": "lots"}, out) + status := run(t.Context(), map[string]string{ + "SWWAF_REQUEST_MAX_BYTES": "lots", + instanceName: instance, + }, out) if status != 1 { t.Errorf("exit status %d, want 1", status) } @@ -126,7 +133,8 @@ func TestInvalidSettingStopsTheStart(t *testing.T) { line := out.line(t, "msg", "invalid setting") message, _ := line["error"].(string) - if line["type"] != "process" || line["level"] != "ERROR" || + if line["type"] != "process" || line["instance"] != instance || + line["level"] != "ERROR" || !strings.HasPrefix(message, "SWWAF_REQUEST_MAX_BYTES: ") { t.Errorf("start refused with %v", line) } @@ -231,6 +239,46 @@ func TestServesUntilToldToStop(t *testing.T) { out.line(t, "msg", "stopped") } +func TestEveryLogLineAndMetricCarriesTheInstanceName(t *testing.T) { + t.Parallel() + + const token = "0123456789abcdef0123456789abcdef" + + env := map[string]string{ + listenAddr: localhost + ":0", + upstreamURL: startApp(t), + stateDir: t.TempDir(), + rulesDir: t.TempDir(), + metricsToken: token, + instanceName: instance, + } + + var metrics string + + out := runUntilStopped(t, env, func(url string) { + metrics = metricsText(t, url+"_smallwebwaf/metrics", token) + }) + + // The process's lines from its start to its stop, and the request's. + for line := range strings.Lines(out.text()) { + var fields map[string]any + + err := json.Unmarshal([]byte(line), &fields) + if err != nil || fields["instance"] != instance { + t.Errorf("line %q (%v), want instance %s", line, err, instance) + } + } + + // Each series, Go's and the process's included; the other lines are + // the comments. + for line := range strings.Lines(metrics) { + if !strings.HasPrefix(line, "#") && + !strings.Contains(line, `instance="fsn1app1/gitea"`) { + t.Errorf("series %q, without instance=\"fsn1app1/gitea\"", line) + } + } +} + func TestStateKeptAcrossRestarts(t *testing.T) { t.Parallel() @@ -519,6 +567,7 @@ func TestStalledRemoteLogEndpointHoldsUpNoRequest(t *testing.T) { "SWWAF_LOG_REMOTE_URL": "syslog+tls://" + endpoint.Addr().String(), "SWWAF_LOG_REMOTE_BUFFER": "1", metricsToken: token, + instanceName: instance, } out := runUntilStopped(t, env, func(url string) { @@ -528,16 +577,17 @@ func TestStalledRemoteLogEndpointHoldsUpNoRequest(t *testing.T) { // last. metrics := metricsText(t, url+"_smallwebwaf/metrics", token) for _, series := range []string{ - "smallwebwaf_remote_log_lines_sent_total 0", - "smallwebwaf_remote_log_buffer_depth 1", + `smallwebwaf_remote_log_lines_sent_total{instance="fsn1app1/gitea"} 0`, + `smallwebwaf_remote_log_buffer_depth{instance="fsn1app1/gitea"} 1`, } { if !strings.Contains(metrics, "\n"+series+"\n") { t.Errorf("no %q in the metrics:\n%s", series, metrics) } } - if strings.Contains(metrics, "\nsmallwebwaf_remote_log_lines_dropped_total 0\n") || - !strings.Contains(metrics, "\nsmallwebwaf_remote_log_lines_dropped_total ") { + const dropped = "\nsmallwebwaf_remote_log_lines_dropped_total" + + `{instance="fsn1app1/gitea"} ` + if strings.Contains(metrics, dropped+"0\n") || !strings.Contains(metrics, dropped) { t.Errorf("no line dropped in the metrics:\n%s", metrics) } @@ -547,6 +597,13 @@ func TestStalledRemoteLogEndpointHoldsUpNoRequest(t *testing.T) { }) out.line(t, "type", "request") + + // While the lines are sent, the process's lines give the instance name + // too. + line := out.line(t, "msg", "starting") + if line["instance"] != instance { + t.Errorf("start logged with instance %v, want %s", line["instance"], instance) + } } func TestBanIsAlertedAndAnAlertNotSentIsKeptAcrossARestart(t *testing.T) { @@ -569,6 +626,7 @@ func TestBanIsAlertedAndAnAlertNotSentIsKeptAcrossARestart(t *testing.T) { rulesDir: rules, "SWWAF_ALERT_WEBHOOK_URL": webhook.url, "SWWAF_ALERT_WEBHOOK_HEADERS": "Authorization:Bearer " + adminSecret, + instanceName: instance, } runUntilStopped(t, env, func(url string) { @@ -622,19 +680,13 @@ func TestBanIsAlertedAndAnAlertNotSentIsKeptAcrossARestart(t *testing.T) { runUntilStopped(t, env, func(url string) { webhook.waitFor(t, "permanent_ban", true) - // As long as that takes, so that a slow test process cannot fail - // the test. - const sent = "\nsmallwebwaf_alerts_sent_total{destination=\"webhook\"} 1\n" + const ofWebhook = `{destination="webhook",instance="fsn1app1/gitea"}` - metrics := metricsText(t, url+"_smallwebwaf/metrics", token) - for !strings.Contains(metrics, sent) { - time.Sleep(pollInterval) - - metrics = metricsText(t, url+"_smallwebwaf/metrics", token) - } + metrics := metricsWith(t, url+"_smallwebwaf/metrics", token, + "\nsmallwebwaf_alerts_sent_total"+ofWebhook+" 1\n") for _, series := range []string{"failed", "suppressed", "dropped"} { - zero := "\nsmallwebwaf_alerts_" + series + "_total{destination=\"webhook\"} 0\n" + zero := "\nsmallwebwaf_alerts_" + series + "_total" + ofWebhook + " 0\n" if !strings.Contains(metrics, zero) { t.Errorf("no %q in the metrics:\n%s", zero, metrics) } @@ -662,7 +714,7 @@ func TestBanIsAlertedToSlackAndNtfy(t *testing.T) { // The metrics are read from 127.0.0.1, which no limit counts. "SWWAF_ALLOW_NETS": localhost + "/32", metricsToken: token, - "SWWAF_INSTANCE_NAME": "fsn1app1/gitea", + instanceName: instance, "SWWAF_ALERT_SLACK_WEBHOOK_URL": slack.url, "SWWAF_ALERT_NTFY_URL": ntfy.url, "SWWAF_ALERT_NTFY_TOKEN": ntfyToken, @@ -698,17 +750,13 @@ func TestBanIsAlertedToSlackAndNtfy(t *testing.T) { // webhook, which is not set. As long as that takes, so that a slow // test process cannot fail the test. sent := []string{ - "\nsmallwebwaf_alerts_sent_total{destination=\"slack\"} 1\n", - "\nsmallwebwaf_alerts_sent_total{destination=\"ntfy\"} 1\n", - } - - metrics := metricsText(t, url+"_smallwebwaf/metrics", token) - for !strings.Contains(metrics, sent[0]) || !strings.Contains(metrics, sent[1]) { - time.Sleep(pollInterval) - - metrics = metricsText(t, url+"_smallwebwaf/metrics", token) + "\nsmallwebwaf_alerts_sent_total{destination=\"slack\"," + + "instance=\"fsn1app1/gitea\"} 1\n", + "\nsmallwebwaf_alerts_sent_total{destination=\"ntfy\"," + + "instance=\"fsn1app1/gitea\"} 1\n", } + metrics := metricsWith(t, url+"_smallwebwaf/metrics", token, sent...) if strings.Contains(metrics, `destination="webhook"`) { t.Errorf("the metrics give the webhook:\n%s", metrics) } @@ -974,6 +1022,26 @@ func metricsText(t *testing.T, url, token string) string { return string(body) } +// metricsWith asks for the metrics at url with token until they hold each +// of series, as long as that takes, so that a slow test process cannot +// fail the test, and returns them. +func metricsWith(t *testing.T, url, token string, series ...string) string { + t.Helper() + + for { + metrics := metricsText(t, url, token) + + missing := slices.ContainsFunc(series, func(one string) bool { + return !strings.Contains(metrics, one) + }) + if !missing { + return metrics + } + + time.Sleep(pollInterval) + } +} + // askAsAdmin sends a request with method to url, with body and // adminSecret, and checks that it is answered 200. func askAsAdmin(t *testing.T, method, url, body string) { diff --git a/internal/state/state_test.go b/internal/state/state_test.go index 1accc7d..a280ec6 100644 --- a/internal/state/state_test.go +++ b/internal/state/state_test.go @@ -736,8 +736,8 @@ func TestWritesAreCountedInTheMetrics(t *testing.T) { } const ( - ofBans = `{file="bans.json"}` - ofClients = `{file="clients.json"}` + ofBans = `{file="bans.json",instance="app"}` + ofClients = `{file="clients.json",instance="app"}` ) got := scrape(t, params) @@ -1162,7 +1162,7 @@ func TestEditsTakenInAreCountedInTheMetrics(t *testing.T) { wantTakenIn(t, lines, dir, bansJSON) wantMetric(t, scrape(t, params), - `smallwebwaf_state_file_edits_taken_in_total{file="bans.json"}`, 2) + `smallwebwaf_state_file_edits_taken_in_total{file="bans.json",instance="app"}`, 2) } func TestEditTakenInByAWriteIsLoggedAsWatchLogsIt(t *testing.T) { @@ -1227,7 +1227,7 @@ func TestEditsSetAsideAreCountedInTheMetrics(t *testing.T) { } wantMetric(t, scrape(t, params), - `smallwebwaf_state_file_edits_set_aside_total{file="bans.json"}`, 1) + `smallwebwaf_state_file_edits_set_aside_total{file="bans.json",instance="app"}`, 1) } func TestDirectoryThatCannotBeWatchedIsLogged(t *testing.T) { @@ -1262,7 +1262,7 @@ func midnight() time.Time { // hour, are never sent. func newParams(dir string) state.Params { discard := slog.New(slog.DiscardHandler) - m := metrics.New(1) + m := metrics.New(1, "app") return state.Params{ Dir: dir, @@ -1647,8 +1647,8 @@ func scrape(t *testing.T, params state.Params) string { } // metric returns the value of series in text, the metrics, such as -// smallwebwaf_state_file_writes_total{file="bans.json"}, or fails the test -// if there is no such series. +// smallwebwaf_state_file_writes_total{file="bans.json",instance="app"}, or +// fails the test if there is no such series. func metric(t *testing.T, text, series string) float64 { t.Helper() @@ -1677,7 +1677,7 @@ func wantWriteFailed(t *testing.T, params state.Params, name string) { t.Helper() got := scrape(t, params) - file := `{file="` + name + `"}` + file := `{file="` + name + `",instance="app"}` wantMetric(t, got, "smallwebwaf_state_file_writes_total"+file, 1) wantMetric(t, got, "smallwebwaf_state_file_write_failures_total"+file, 1)