From 1d800dc14b95c24d122977cb54612dbc36625d5e Mon Sep 17 00:00:00 2001 From: Etienne Perot Date: Mon, 13 May 2024 18:04:20 -0700 Subject: [PATCH] Set default test container log config to allow higher logging volume. This is part of a series of changes to add metric charts in performance benchmarks. This is intended to increase the reliability of logs-based profiling metrics by ensuring that Docker keeps enough of them around during long tests, or tests where there are a lot of metrics being profiled, or tests with a very fast profiling rate, or all of the above. This also calls `sync` on the underlying logging file descriptor if possible. Give a more helpful error messages if a log buffer overrun does occur. PiperOrigin-RevId: 633389921 --- pkg/metric/profiling_metric.go | 5 +++++ pkg/test/dockerutil/container.go | 15 +++++++++++++++ test/metricsviz/metricsviz.go | 4 ++-- 3 files changed, 22 insertions(+), 2 deletions(-) diff --git a/pkg/metric/profiling_metric.go b/pkg/metric/profiling_metric.go index 5b717a60e..33878e9d2 100644 --- a/pkg/metric/profiling_metric.go +++ b/pkg/metric/profiling_metric.go @@ -21,6 +21,7 @@ import ( "hash" "hash/adler32" "io" + "os" "strings" "time" @@ -376,6 +377,10 @@ func (w *lossyBufferedWriter[T]) Flush() { // have clean line endings a the time we print this. w.flushBuf.WriteString("\n") w.underlying.WriteString(w.flushBuf.String()) + if f, isFile := any(w.underlying).(*os.File); isFile { + // If we're dealing with a file, also call `sync(2)`. + f.Sync() + } w.flushBuf.Reset() w.flushBuf.WriteString("\n") w.lines = 0 diff --git a/pkg/test/dockerutil/container.go b/pkg/test/dockerutil/container.go index e49e0297a..9bc3d5ae2 100644 --- a/pkg/test/dockerutil/container.go +++ b/pkg/test/dockerutil/container.go @@ -248,6 +248,21 @@ func (c *Container) create(ctx context.Context, profileImage string, conf *conta // unmodified "basic/alpine" image name. This should be easy to grok. c.profileInit(profileImage) } + if hostconf == nil || hostconf.LogConfig.Type == "" { + // If logging config is not explicitly specified, set it to a fairly + // generous default. This makes large volumes of log more reliably + // captured, which is useful for profiling metrics. + if hostconf == nil { + hostconf = &container.HostConfig{} + } + hostconf.LogConfig.Type = "local" + hostconf.LogConfig.Config = map[string]string{ + "mode": "blocking", + "max-size": "1g", + "max-file": "10", + "compress": "false", + } + } cont, err := c.client.ContainerCreate(ctx, conf, hostconf, nil, nil, c.Name) if err != nil { return err diff --git a/test/metricsviz/metricsviz.go b/test/metricsviz/metricsviz.go index fc6e049be..d1e837540 100644 --- a/test/metricsviz/metricsviz.go +++ b/test/metricsviz/metricsviz.go @@ -450,7 +450,7 @@ func Parse(logs string, hasPrefix bool) (*Data, error) { } wantHash := uint32(wantHashInt64) if gotHash := h.Sum32(); gotHash != wantHash { - return nil, fmt.Errorf("hash mismatch: computed 0x%x, logs said it should be 0x%x", gotHash, wantHash) + return nil, fmt.Errorf("checksum mismatch: computed 0x%x, logs said it should be 0x%x. This is likely due to a log buffer overrun or similar issue causing some lines to be omitted; please configure the container or the runtime to allow higher logging volume", gotHash, wantHash) } checkedHash = true continue @@ -517,7 +517,7 @@ func Parse(logs string, hasPrefix bool) (*Data, error) { // Regular lines. tabularData := strings.Split(lineData, "\t") if len(tabularData) != len(header)+1 { - return nil, fmt.Errorf("invalid data line: %q with %d components which does not match header %v which has %d components", line, len(tabularData), header, len(header)) + return nil, fmt.Errorf("invalid data line: %q with %d components which does not match header which has %d components. This is likely due to a log buffer overrun or similar issue causing the line to be cut off; please configure the container or the runtime to allow higher logging volume", line, len(tabularData), len(header)) } offsetNanos, err := strconv.ParseUint(tabularData[0], 10, 64) if err != nil {