diff --git a/CHANGELOG.md b/CHANGELOG.md index 3ca79d5..fda1b44 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -70,6 +70,23 @@ because it turns other people's test suites red. ### Added +- **A log can be made quiet, or full of errors.** `--set level_mix=errors` on + a `log`, with `realistic`, `quiet`, `errors` and `debug` to choose from. It + decides which severities appear, the way `status_mix` already decides which + response codes do. + + Only the `plain` and `json-lines` entry formats carry a severity at all. Ask + for a mix beside one of the other four and the tool says so and stops, + naming both settings, rather than accepting a setting that would do nothing. + + One thing worth knowing before you pick `quiet`: it draws only `INFO`, which + is a shorter word than `ERROR`, so the smallest log it can write is one byte + smaller than the other mixes. The tool tells you the floor for the settings + you gave it. + + The default is `realistic`, the mix these logs have always had, so **no + existing file changes by a byte**. + - **An archive can compress what it holds.** `--set compression=best` on a `zip` or a `targz`, with `none`, `fast`, `default` and `best` to choose from. diff --git a/internal/format/logfile/address.go b/internal/format/logfile/address.go index cc2580e..fda3729 100644 --- a/internal/format/logfile/address.go +++ b/internal/format/logfile/address.go @@ -152,10 +152,14 @@ func longestAddress(o options) int { return v4Longest } +// longestLevel reads the SET IN FORCE rather than every level this format +// knows, because that is what the minimum entry has to leave room for. Reading +// the whole vocabulary instead would be wrong in the safe direction - a floor +// one byte too high - but it would announce a minimum the format can beat. +func longestLevel(o options) int { return longest(o.levels) } func longestMethod(o options) int { return longest(o.methods) } func longestAgent() int { return longest(agents) } func longestTag() int { return longest(tags) } -func longestLevel() int { return longest(levels) } func longest(xs []string) int { n := 0 diff --git a/internal/format/logfile/log.go b/internal/format/logfile/log.go index df122ad..594a44b 100644 --- a/internal/format/logfile/log.go +++ b/internal/format/logfile/log.go @@ -104,6 +104,11 @@ func properties() []format.Property { Choices: []string{"realistic", "success", "client-errors", "server-errors"}, Default: "realistic", Detail: "Which response codes appear. Realistic is mostly success with a tail of errors.", }, + { + Name: "level_mix", Kind: format.PropertyChoice, + Choices: levelMixIDs, Default: "realistic", + Detail: "Which severities appear. Only the plain and json-lines shapes carry one, and asking for it beside another shape is refused.", + }, { Name: "ip_version", Kind: format.PropertyChoice, Choices: []string{"v4", "v6", "mixed"}, Default: "v4", @@ -169,6 +174,9 @@ func (generator) Plan(r format.Request) (format.Plan, error) { if opt.shape.web || opt.shape.id == "json-lines" { p.Properties["status_mix"] = opt.statusMix } + if opt.shape.levelled { + p.Properties["level_mix"] = opt.levelMix + } m := memo{seed: r.Seed, opt: opt} if r.Label { @@ -277,4 +285,36 @@ const ( var tags = []string{"sshd", "cron", "systemd", "kernel", "nginx", "dockerd"} -var levels = []string{"INFO", "INFO", "INFO", "WARN", "ERROR", "DEBUG"} +// levelSets are the severity mixes, drawn from one vocabulary on purpose. +// +// Every set here is built from DEBUG, INFO, WARN and ERROR and nothing else, +// so the longest level in any of them is five bytes. That is not tidiness: the +// shortest entry a shape can write leaves room for the longest level it might +// draw, so a set carrying a longer word would move the minimum for plain and +// JSON lines. Adding CRITICAL later is allowed, it just has to be a decision +// about the minimum rather than a word slipped into a list. +// +// Repeats are the weighting. There is no separate share for each level because +// a list with three INFOs in it says the same thing and is what the draw +// already reads. +var levelSets = map[string][]string{ + // realistic is the mix this format has always written, in the order it has + // always been in. D11 rests on that: the same seed has to draw the same + // levels it did before this setting existed, so this slice is the old + // variable moved rather than rewritten. + "realistic": {"INFO", "INFO", "INFO", "WARN", "ERROR", "DEBUG"}, + // quiet is the boring baseline - a service with nothing to report. Useful + // as the control when a reader is being tested for what it does with the + // levels rather than for whether it parses. + "quiet": {"INFO"}, + // errors is a service having a bad day, for a reader whose error handling + // is what is under test. + "errors": {"ERROR", "ERROR", "ERROR", "WARN", "WARN", "INFO"}, + // debug is a build left verbose, which is how a log gets large in the first + // place. + "debug": {"DEBUG", "DEBUG", "DEBUG", "INFO", "INFO", "WARN"}, +} + +// levelMixIDs is the closed set the registry offers, in one order so that +// every surface lists them the same way. +var levelMixIDs = []string{"realistic", "quiet", "errors", "debug"} diff --git a/internal/format/logfile/options.go b/internal/format/logfile/options.go index 2f9cd8a..a22caed 100644 --- a/internal/format/logfile/options.go +++ b/internal/format/logfile/options.go @@ -46,6 +46,9 @@ type options struct { statusMix string statuses []int + levelMix string + levels []string + ipVersion string ipv6 bool ipMixed bool @@ -63,6 +66,8 @@ func defaultOptions() options { methods: methodSets["get"], statusMix: "realistic", statuses: statusSets["realistic"], + levelMix: "realistic", + levels: levelSets["realistic"], ipVersion: "v4", } return o @@ -94,7 +99,7 @@ func parseOptions(props map[string]string) (options, error) { o := defaultOptions() for _, read := range []func(map[string]string, *options) error{ readShape, readLineEnding, readTimestamps, readRate, - readMethods, readStatusMix, readIPVersion, + readMethods, readStatusMix, readLevelMix, readIPVersion, } { if err := read(props, &o); err != nil { return options{}, err @@ -205,6 +210,34 @@ func readStatusMix(props map[string]string, o *options) error { return nil } +// readLevelMix reads the severity mix, which only two shapes carry. +// +// Unlike status_mix, the set chosen here can move the MINIMUM: the shortest +// entry a shape can write has to leave room for the longest level it might +// draw, and quiet draws only INFO. That is why the set is settled here and +// read back out of options by longestLevel, rather than either of them +// reaching for the vocabulary directly. +func readLevelMix(props map[string]string, o *options) error { + v, ok := value(props, "level_mix") + if !ok { + return nil + } + set, known := levelSets[v] + if !known { + return badValue("level_mix", v, "it has to be realistic, quiet, errors or debug") + } + // Only a real choice can disagree with the shape - see asked. A window + // sends this key on every run, so refusing whenever it arrived would put + // the four shapes without a level out of reach from the window entirely, + // which is the defect reported from a screenshot on 2026-08-31. + if _, chosen := asked(props, "level_mix", "realistic"); chosen && !o.shape.levelled { + return conflict("level_mix and entry_format", v, + "the "+o.shape.id+" shape carries no severity") + } + o.levelMix, o.levels = v, set + return nil +} + func readIPVersion(props map[string]string, o *options) error { v, ok := value(props, "ip_version") if !ok { diff --git a/internal/format/logfile/shapes.go b/internal/format/logfile/shapes.go index dbd07d8..0ebae3b 100644 --- a/internal/format/logfile/shapes.go +++ b/internal/format/logfile/shapes.go @@ -38,6 +38,11 @@ type shape struct { // if the method, status and address settings mean anything for it. A // setting that would do nothing is refused rather than ignored. web bool + // levelled says whether this shape carries a severity, which decides the + // same thing for level_mix. Separate from web rather than derived from it, + // because the two do not line up: no web shape carries a level, and of the + // three that are not web, only two do. + levelled bool // appendTo writes one entry. want below zero means whatever length it // comes out. Any other value is the exact length the line must have, its // terminator included, and the stretchable field reaches it. @@ -65,8 +70,8 @@ var shapes = map[string]*shape{ "apache-combined": {id: "apache-combined", web: true, appendTo: appendApacheCombined, shortest: shortestApacheCombined, label: hashLabel}, "nginx": {id: "nginx", web: true, appendTo: appendNginx, shortest: shortestNginx, label: hashLabel}, "syslog": {id: "syslog", web: false, appendTo: appendSyslog, shortest: shortestSyslog, label: hashLabel}, - "plain": {id: "plain", web: false, appendTo: appendPlain, shortest: shortestPlain, label: hashLabel}, - "json-lines": {id: "json-lines", web: false, appendTo: appendJSONLine, shortest: shortestJSONLine, label: jsonLabel}, + "plain": {id: "plain", web: false, levelled: true, appendTo: appendPlain, shortest: shortestPlain, label: hashLabel}, + "json-lines": {id: "json-lines", web: false, levelled: true, appendTo: appendJSONLine, shortest: shortestJSONLine, label: jsonLabel}, } // shapeIDs is the closed set the registry offers, in one order so that every @@ -253,7 +258,7 @@ func pidWidth(pid int) int { // most home grown loggers write and the one with the least agreement about it, // so this is the plainest reading of it. func appendPlain(dst []byte, st *state, want int64) []byte { - level := pick(st.rng, levels) + level := pick(st.rng, st.opt.levels) at := st.clock.tick() base := int64(len(isoTime)+1+len(level)+1) + int64(len(st.opt.eol)) @@ -266,7 +271,7 @@ func appendPlain(dst []byte, st *state, want int64) []byte { } func shortestPlain(o options) int64 { - return int64(len(isoTime)+1+longestLevel()+1) + int64(len(o.eol)) + 1 + return int64(len(isoTime)+1+longestLevel(o)+1) + int64(len(o.eol)) + 1 } // JSON lines: one object a line, which is what makes it the one shape here @@ -277,7 +282,7 @@ func shortestPlain(o options) int64 { // nothing in it ever needs escaping - which matters, because an escape would // make the line longer than the arithmetic said. func appendJSONLine(dst []byte, st *state, want int64) []byte { - level := pick(st.rng, levels) + level := pick(st.rng, st.opt.levels) status := pick(st.rng, st.opt.statuses) at := st.clock.tick() @@ -302,7 +307,7 @@ func appendJSONLine(dst []byte, st *state, want int64) []byte { func shortestJSONLine(o options) int64 { return int64(len(`{"time":"","level":"","status":,"msg":""}`)+ - len(isoTime)+longestLevel()+statusWidth) + int64(len(o.eol)) + 1 + len(isoTime)+longestLevel(o)+statusWidth) + int64(len(o.eol)) + 1 } // appendMessage writes the sentence the message shapes end with, stretched to diff --git a/internal/guard/logshapes_test.go b/internal/guard/logshapes_test.go index 5559f19..10ca4b6 100644 --- a/internal/guard/logshapes_test.go +++ b/internal/guard/logshapes_test.go @@ -4,6 +4,7 @@ import ( "bytes" "context" "encoding/json" + "errors" "fmt" "regexp" "strings" @@ -287,6 +288,8 @@ func TestALogRefusesASettingThatWouldChangeNothing(t *testing.T) { {map[string]string{"entry_format": "syslog", "ip_version": "v6"}}, {map[string]string{"entry_format": "plain", "status_mix": "success"}}, {map[string]string{"timestamps": "fixed", "rate": "5"}}, + {map[string]string{"entry_format": "nginx", "level_mix": "quiet"}}, + {map[string]string{"entry_format": "syslog", "level_mix": "errors"}}, } for _, c := range cases { t.Run(fmt.Sprint(c.props), func(t *testing.T) { @@ -339,3 +342,167 @@ func TestTheLogLabelIsALineItsOwnReaderAccepts(t *testing.T) { t.Errorf("the syslog label is not a hash comment, so the one line that is not an entry does not say so") } } + +// The severity mix is the set that gets drawn, and it moves the minimum. +// +// Two things could be wrong here and they fail differently. +// +// The first is the setting doing nothing: level_mix is read, stored, and then +// the draw reaches for the whole vocabulary anyway. Nothing else would see it - +// the size stays exact, every line still parses, and the manifest still says +// which mix was asked for. So this asks the FILE which severities are in it. +// +// The second is subtler and is why this guard exists at all. The shortest entry +// a shape can write has to leave room for the LONGEST severity it might draw, +// because the closing entry is built to an exact length and the unluckiest draw +// has to fit. quiet draws only INFO, four bytes, where realistic can draw ERROR +// or DEBUG at five. If the arithmetic reads the whole vocabulary instead of the +// set in force, the minimum is one byte too high for quiet - a floor the format +// can actually beat, announced as if it could not. That is checked by asking +// for the announced minimum and for one byte below it, rather than by repeating +// the arithmetic here, which would only prove the guard agrees with itself. +func TestTheLogSeverityMixIsDrawnAndSetsTheMinimum(t *testing.T) { + d, err := format.Get("log") + if err != nil { + t.Fatal(err) + } + + // What each declared mix is allowed to contain. Stated here on purpose: + // this guard is outside the package, so it says what the contract is rather + // than reading it back out of the thing under test. A mix added to the + // registry without a line here stops the guard instead of slipping past it. + allowed := map[string]map[string]bool{ + "realistic": {"DEBUG": true, "INFO": true, "WARN": true, "ERROR": true}, + "quiet": {"INFO": true}, + "errors": {"INFO": true, "WARN": true, "ERROR": true}, + "debug": {"DEBUG": true, "INFO": true, "WARN": true}, + } + + var mixes []string + for _, p := range d.Properties { + if p.Name == "level_mix" { + mixes = p.Choices + } + } + if len(mixes) == 0 { + t.Fatal("the log format declares no level_mix, so this guard would check nothing") + } + for _, m := range mixes { + if allowed[m] == nil { + t.Fatalf("level_mix offers %q and this guard does not say what may be in it. "+ + "Add the line rather than deleting this check - a mix nobody described is a mix nobody verified.", m) + } + } + + // Which shapes carry a severity is asked of the product, not listed here. + // A shape reports level_mix in its plan exactly when it has one. + var levelled, flat []string + for _, shape := range logShapes(t) { + p, err := d.Generator.Plan(format.Request{Bytes: 20 << 10, Seed: 7741, Label: true, + Properties: map[string]string{"entry_format": shape}}) + if err != nil { + t.Fatalf("%s would not plan at its defaults: %v", shape, err) + } + if _, ok := p.Properties["level_mix"]; ok { + levelled = append(levelled, shape) + } else { + flat = append(flat, shape) + } + } + if len(levelled) == 0 || len(flat) == 0 { + t.Fatalf("found %d shapes with a severity and %d without, so this guard is walking nothing", + len(levelled), len(flat)) + } + + severity := regexp.MustCompile(`\b(DEBUG|INFO|WARN|ERROR)\b`) + minimum := func(shape, mix string) int64 { + t.Helper() + props := map[string]string{"entry_format": shape, "level_mix": mix} + _, err := d.Generator.Plan(format.Request{Bytes: 1, Seed: 7741, Label: true, Properties: props}) + var below *format.BelowMinimumError + if !errors.As(err, &below) { + t.Fatalf("%s/%s took a one byte log, or refused it without saying what the floor is: %v", shape, mix, err) + } + return below.Minimum + } + + for _, shape := range levelled { + for _, mix := range mixes { + t.Run(shape+"/"+mix, func(t *testing.T) { + props := map[string]string{"entry_format": shape, "level_mix": mix} + + // The file, not the manifest, says which severities are in it. + body := writeLog(t, 64<<10, props) + seen := map[string]bool{} + for _, m := range severity.FindAllString(string(body), -1) { + seen[m] = true + } + if len(seen) == 0 { + t.Fatalf("no severity at all in 64 kB of %s, so nothing here is being read", shape) + } + for level := range seen { + if !allowed[mix][level] { + t.Errorf("%s is in a %s log and that mix does not offer it, "+ + "so the setting was stored and then the draw ignored it", level, mix) + } + } + + // The floor it announces is the floor it takes, and one below is + // refused. This is where a minimum read off the whole vocabulary + // rather than off this mix goes red. + n := minimum(shape, mix) + if _, err := d.Generator.Plan(format.Request{Bytes: n, Seed: 7741, Label: true, + Properties: props}); err != nil { + t.Errorf("%s/%s announces %d B as its minimum and then refuses it: %v", shape, mix, n, err) + } + if _, err := d.Generator.Plan(format.Request{Bytes: n - 1, Seed: 7741, Label: true, + Properties: props}); err == nil { + t.Errorf("%s/%s took %d B, one below the %d B it calls its minimum", shape, mix, n-1, n) + } + + // Exact to the byte at every seed, because the closing entry is + // built to a length and the severity is part of that arithmetic. + for seed := int64(1); seed <= 8; seed++ { + for _, size := range []int64{n, n + 1, 777, 4 << 10} { + if size < n { + continue + } + p, err := d.Generator.Plan(format.Request{Bytes: size, Seed: uint64(seed), + Label: true, Properties: props}) + if err != nil { + t.Fatalf("seed %d, %d B: %v", seed, size, err) + } + var buf bytes.Buffer + if err := d.Generator.Write(context.Background(), &buf, p); err != nil { + t.Fatalf("seed %d, %d B: %v", seed, size, err) + } + if int64(buf.Len()) != size { + t.Fatalf("seed %d asked for %d B and got %d", seed, size, buf.Len()) + } + } + } + }) + } + + // The mixes are not all the same thing under different names, and the + // arithmetic reads the one in force. quiet draws only INFO, which is + // shorter than the longest severity realistic can draw, so its floor + // has to be lower. Without this the whole test above would still pass + // on a build where every mix was realistic. + q, r := minimum(shape, "quiet"), minimum(shape, "realistic") + if q >= r { + t.Errorf("%s: the quiet floor is %d B and the realistic one %d B. quiet draws only INFO, "+ + "which is shorter than ERROR, so a floor that did not move was measured against "+ + "every severity this format knows rather than against the mix that was chosen.", shape, q, r) + } + } + + // And the shapes with no severity keep refusing a mix that was really + // chosen, so the guard cannot pass by accepting everything. + for _, shape := range flat { + if _, err := d.Generator.Plan(format.Request{Bytes: 4096, Seed: 7741, Label: true, + Properties: map[string]string{"entry_format": shape, "level_mix": "quiet"}}); err == nil { + t.Errorf("%s carries no severity and took level_mix anyway, so the setting does nothing there", shape) + } + } +} diff --git a/internal/guard/parity_test.go b/internal/guard/parity_test.go index 54da9d3..73e39f3 100644 --- a/internal/guard/parity_test.go +++ b/internal/guard/parity_test.go @@ -115,6 +115,7 @@ var reachableFromTheWindow = []string{ "property:jpg.width", "property:log.entry_format", "property:log.ip_version", + "property:log.level_mix", "property:log.line_ending", "property:log.methods", "property:log.rate", diff --git a/web/public/formats/index.html b/web/public/formats/index.html index 08ed11d..01013f4 100644 --- a/web/public/formats/index.html +++ b/web/public/formats/index.html @@ -430,6 +430,11 @@

Settings each format accepts

status_mix client-errors, realistic, server-errors, success + + + level_mix + debug, errors, quiet, realistic + ip_version diff --git a/web/public/pl/formaty/index.html b/web/public/pl/formaty/index.html index 5477955..ce10c68 100644 --- a/web/public/pl/formaty/index.html +++ b/web/public/pl/formaty/index.html @@ -430,6 +430,11 @@

Ustawienia, które przyjmuje każdy format

status_mix client-errors, realistic, server-errors, success + + + level_mix + debug, errors, quiet, realistic + ip_version