From 97f8ca13ff4ff8a4252d1afb3e85d131ea77be03 Mon Sep 17 00:00:00 2001 From: Javier de la Torre Date: Wed, 21 Oct 2026 17:00:33 -0400 Subject: [PATCH] s3tables, iceberg: log client refusals at V(1), not ERROR (#11896) * s3tables, iceberg: log client refusals at V(1), not ERROR Requests the S3 Tables and Iceberg REST APIs correctly refuse with a 4xx (access denied, not authorized, no such namespace, already exists, not empty, a commit conflict) were logged with glog.Errorf, so a client probing for what it may do, or retrying an optimistic commit, filled the ERROR log and hid real faults from anyone alerting on it. - s3tables: HandleRequest wraps the ResponseWriter in a statusRecorder (with Unwrap for http.ResponseController) and logs a handler error by the status it answered: 4xx at V(1) as " refused ()", 5xx or no status at ERROR as before. - s3tables: the "handleCreateNamespace called" trace moves from ERROR to V(3). - iceberg: writeManagerError's mapping is split into classifyManagerError, shared with a new logManagerError that logs 4xx-mapped errors at V(1) and everything else at ERROR; used by CreateNamespace, CommitTable and CommitTransaction. - storage: loading a remote-tier volume logged "readSuperBlock remote volume N: " at ERROR even when the read succeeded; it is now logged only when there is an error. Tests: TestRequestRefusedWith4xxIsNotLoggedAsError, TestLogRequestErrorByStatus, TestStatusRecorderKeepsTheFirstStatus, TestStatusRecorderUnwrapsForResponseController, TestNoTraceLoggedAtErrorLevel (fails on master on the CreateNamespace trace), TestLogManagerErrorRefusalsAreNotErrors, TestRemoteSuperBlockLogOnlyOnError. * s3tables: do not log a malformed CreateNamespace body at ERROR handleCreateNamespace logged a body it could not decode at ERROR before answering 400; the dispatcher already logs that refusal once at V(1). Also drop statusRecorder.Flush: it made the recorder an http.Flusher even over a writer that cannot flush, so http.NewResponseController reported success instead of ErrNotSupported. Unwrap already lets the controller reach the wrapped writer. * iceberg: require exactly one log line per classified manager error The test accepted a refusal that produced no log, or both logs. Require one V(1) refusal and no ERROR for a 4xx, and the reverse for a fault. --------- Co-authored-by: Javier de la Torre --- weed/s3api/iceberg/handlers_commit.go | 2 +- weed/s3api/iceberg/handlers_namespace.go | 2 +- weed/s3api/iceberg/handlers_transaction.go | 2 +- weed/s3api/iceberg/log_manager_error_test.go | 36 +++++ weed/s3api/iceberg/utils.go | 51 +++++--- weed/s3api/s3tables/handler.go | 47 ++++++- weed/s3api/s3tables/handler_log_level_test.go | 123 ++++++++++++++++++ weed/s3api/s3tables/handler_namespace.go | 3 +- .../s3tables/handler_no_trace_errorf_test.go | 39 ++++++ weed/storage/volume_loading.go | 10 +- .../volume_remote_superblock_log_test.go | 21 +++ 11 files changed, 313 insertions(+), 23 deletions(-) create mode 100644 weed/s3api/iceberg/log_manager_error_test.go create mode 100644 weed/s3api/s3tables/handler_log_level_test.go create mode 100644 weed/s3api/s3tables/handler_no_trace_errorf_test.go create mode 100644 weed/storage/volume_remote_superblock_log_test.go diff --git a/weed/s3api/iceberg/handlers_commit.go b/weed/s3api/iceberg/handlers_commit.go index 0f194e4d53..c40ee6b9e7 100644 --- a/weed/s3api/iceberg/handlers_commit.go +++ b/weed/s3api/iceberg/handlers_commit.go @@ -397,7 +397,7 @@ func (s *Server) handleUpdateTable(w http.ResponseWriter, r *http.Request) { if cleanupErr := s.deleteMetadataFile(r.Context(), metadataBucket, metadataPath, metadataFileName); cleanupErr != nil { glog.V(1).Infof("Iceberg: failed to cleanup metadata file %s after update failure: %v", newMetadataLocation, cleanupErr) } - glog.Errorf("Iceberg: CommitTable UpdateTable error: %v", err) + logManagerError("CommitTable UpdateTable", err) writeManagerError(w, err) return } diff --git a/weed/s3api/iceberg/handlers_namespace.go b/weed/s3api/iceberg/handlers_namespace.go index 1cfdf856d1..00dd4700dd 100644 --- a/weed/s3api/iceberg/handlers_namespace.go +++ b/weed/s3api/iceberg/handlers_namespace.go @@ -140,7 +140,7 @@ func (s *Server) handleCreateNamespace(w http.ResponseWriter, r *http.Request) { writeError(w, http.StatusConflict, "AlreadyExistsException", err.Error()) return } - glog.Errorf("Iceberg: CreateNamespace error: %v", err) + logManagerError("CreateNamespace", err) writeManagerError(w, err) return } diff --git a/weed/s3api/iceberg/handlers_transaction.go b/weed/s3api/iceberg/handlers_transaction.go index c455d79da1..5eed534a87 100644 --- a/weed/s3api/iceberg/handlers_transaction.go +++ b/weed/s3api/iceberg/handlers_transaction.go @@ -109,7 +109,7 @@ func (s *Server) handleCommitTransaction(w http.ResponseWriter, r *http.Request) writeError(w, http.StatusConflict, "CommitFailedException", "Version token mismatch") return } - glog.Errorf("Iceberg: CommitTransaction UpdateTable error: %v", err) + logManagerError("CommitTransaction UpdateTable", err) writeManagerError(w, err) return } diff --git a/weed/s3api/iceberg/log_manager_error_test.go b/weed/s3api/iceberg/log_manager_error_test.go new file mode 100644 index 0000000000..ff52da322b --- /dev/null +++ b/weed/s3api/iceberg/log_manager_error_test.go @@ -0,0 +1,36 @@ +package iceberg + +import ( + "errors" + "fmt" + "testing" + + "github.com/seaweedfs/seaweedfs/weed/s3api/s3tables" +) + +func TestLogManagerErrorRefusalsAreNotErrors(t *testing.T) { + var refusals, faults []string + oldR, oldF := logManagerRefusal, logManagerFault + logManagerRefusal = func(f string, a ...interface{}) { refusals = append(refusals, fmt.Sprintf(f, a...)) } + logManagerFault = func(f string, a ...interface{}) { faults = append(faults, fmt.Sprintf(f, a...)) } + defer func() { logManagerRefusal, logManagerFault = oldR, oldF }() + for _, c := range []struct { + err error + fault bool + }{ + {&s3tables.S3TablesError{Type: s3tables.ErrCodeAccessDenied, Message: "not authorized to create namespace in this bucket"}, false}, + {&s3tables.S3TablesError{Type: s3tables.ErrCodeNoSuchNamespace, Message: "no such namespace"}, false}, + {&s3tables.S3TablesError{Type: s3tables.ErrCodeNamespaceAlreadyExists, Message: "exists"}, false}, + {errors.New("filer: connection refused"), true}, // positive control: a real fault stays at ERROR + } { + refusals, faults = nil, nil + logManagerError("CreateNamespace", c.err) + wantFaults, wantRefusals := 0, 1 + if c.fault { + wantFaults, wantRefusals = 1, 0 + } + if len(faults) != wantFaults || len(refusals) != wantRefusals { + t.Errorf("%v: %d ERROR and %d refusal log(s), want %d and %d (refusals %v, faults %v)", c.err, len(faults), len(refusals), wantFaults, wantRefusals, refusals, faults) + } + } +} diff --git a/weed/s3api/iceberg/utils.go b/weed/s3api/iceberg/utils.go index 3014a8ac33..40bab282be 100644 --- a/weed/s3api/iceberg/utils.go +++ b/weed/s3api/iceberg/utils.go @@ -158,7 +158,9 @@ func nameValidationError(err error) bool { // errors (400) and must carry the reason -- a variant field without // format-version 3 otherwise reads as a bare 500 with "variant is not supported // until v3" only in the log. Anything else is a server fault (500). -func writeManagerError(w http.ResponseWriter, err error) { +// classifyManagerError maps a storage-layer error to the HTTP status, the +// Iceberg error type and the message the catalog answers with. +func classifyManagerError(err error) (int, string, string) { switch { case nameValidationError(err), errors.Is(err, iceberg.ErrInvalidSchema), @@ -166,8 +168,7 @@ func writeManagerError(w http.ResponseWriter, err error) { errors.Is(err, iceberg.ErrInvalidTypeString), errors.Is(err, iceberg.ErrInvalidTransform), errors.Is(err, iceberg.ErrInvalidArgument): - writeError(w, http.StatusBadRequest, "BadRequestException", err.Error()) - return + return http.StatusBadRequest, "BadRequestException", err.Error() } // Storage-layer failures are mostly the client's, not the server's. Reporting // a missing namespace or a name conflict as a 500 makes the catalog look @@ -179,31 +180,49 @@ func writeManagerError(w http.ResponseWriter, err error) { // The storage-layer message names the resolved bucket, which for a // client that sent no warehouse at all is the default one it never // asked for, so say how to select a real table bucket. - writeError(w, http.StatusNotFound, "NoSuchNamespaceException", - fmt.Sprintf("%s: each table bucket is a separate catalog, select one with warehouse=s3:/// or /v1//", tableErr.Message)) + return http.StatusNotFound, "NoSuchNamespaceException", + fmt.Sprintf("%s: each table bucket is a separate catalog, select one with warehouse=s3:/// or /v1//", tableErr.Message) case s3tables.ErrCodeNoSuchNamespace: - writeError(w, http.StatusNotFound, "NoSuchNamespaceException", tableErr.Message) + return http.StatusNotFound, "NoSuchNamespaceException", tableErr.Message case s3tables.ErrCodeNoSuchTable: - writeError(w, http.StatusNotFound, "NoSuchTableException", tableErr.Message) + return http.StatusNotFound, "NoSuchTableException", tableErr.Message case s3tables.ErrCodeNoSuchView: - writeError(w, http.StatusNotFound, "NoSuchViewException", tableErr.Message) + return http.StatusNotFound, "NoSuchViewException", tableErr.Message case s3tables.ErrCodeNamespaceAlreadyExists, s3tables.ErrCodeBucketAlreadyExists, s3tables.ErrCodeTableAlreadyExists, s3tables.ErrCodeViewAlreadyExists: - writeError(w, http.StatusConflict, "AlreadyExistsException", tableErr.Message) + return http.StatusConflict, "AlreadyExistsException", tableErr.Message case s3tables.ErrCodeNamespaceNotEmpty, s3tables.ErrCodeBucketNotEmpty: - writeError(w, http.StatusConflict, "AlreadyExistsException", tableErr.Message) + return http.StatusConflict, "AlreadyExistsException", tableErr.Message case s3tables.ErrCodeConflict: - writeError(w, http.StatusConflict, "CommitFailedException", tableErr.Message) + return http.StatusConflict, "CommitFailedException", tableErr.Message case s3tables.ErrCodeAccessDenied: - writeError(w, http.StatusForbidden, "ForbiddenException", tableErr.Message) + return http.StatusForbidden, "ForbiddenException", tableErr.Message case s3tables.ErrCodeInvalidRequest, s3tables.ErrCodeInvalidIcebergLayout: - writeError(w, http.StatusBadRequest, "BadRequestException", tableErr.Message) - default: - writeError(w, http.StatusInternalServerError, "InternalServerError", err.Error()) + return http.StatusBadRequest, "BadRequestException", tableErr.Message } + } + return http.StatusInternalServerError, "InternalServerError", err.Error() +} + +func writeManagerError(w http.ResponseWriter, err error) { + status, typ, msg := classifyManagerError(err) + writeError(w, status, typ, msg) +} + +// A storage-layer error the catalog answers with a 4xx (access denied, not +// found, already exists, not empty, a conflict) is the API refusing a request +// as intended, not a server fault; it is logged at V(1). A 5xx stays at ERROR. +var ( + logManagerRefusal = func(format string, args ...interface{}) { glog.V(1).Infof(format, args...) } + logManagerFault = glog.Errorf +) + +func logManagerError(op string, err error) { + if status, _, _ := classifyManagerError(err); status >= 400 && status < 500 { + logManagerRefusal("Iceberg: %s refused (%d): %v", op, status, err) return } - writeError(w, http.StatusInternalServerError, "InternalServerError", err.Error()) + logManagerFault("Iceberg: %s error: %v", op, err) } // resolveWarehouseBucket maps a client-supplied warehouse value to a table diff --git a/weed/s3api/s3tables/handler.go b/weed/s3api/s3tables/handler.go index 69e8c4f9a8..4bf960ca4f 100644 --- a/weed/s3api/s3tables/handler.go +++ b/weed/s3api/s3tables/handler.go @@ -127,6 +127,10 @@ func (h *S3TablesHandler) HandleRequest(w http.ResponseWriter, r *http.Request, glog.V(3).Infof("S3Tables: handling operation %s", operation) + // the status the handler answers decides how its error is logged (logRequestError) + sw := &statusRecorder{ResponseWriter: w} + w = sw + var err error switch operation { // Table Bucket operations @@ -223,10 +227,51 @@ func (h *S3TablesHandler) HandleRequest(w http.ResponseWriter, r *http.Request, } if err != nil { - glog.Errorf("S3Tables: error handling %s: %v", operation, err) + logRequestError(operation, sw.status, err) } } +// A refusal the handler answered with a 4xx (access denied, not authorized, +// not found, already exists, not empty) is the API working as intended, not a +// server fault; it is logged at V(1). A 5xx, or an error returned without any +// status written, stays at ERROR. +var ( + logClientRefusal = func(format string, args ...interface{}) { glog.V(1).Infof(format, args...) } + logServerError = glog.Errorf +) + +func logRequestError(operation string, status int, err error) { + if status >= 400 && status < 500 { + logClientRefusal("S3Tables: %s refused (%d): %v", operation, status, err) + return + } + logServerError("S3Tables: error handling %s: %v", operation, err) +} + +// statusRecorder remembers the first status written through it. +type statusRecorder struct { + http.ResponseWriter + status int +} + +func (s *statusRecorder) WriteHeader(code int) { + if s.status == 0 { + s.status = code + } + s.ResponseWriter.WriteHeader(code) +} + +func (s *statusRecorder) Write(b []byte) (int, error) { + if s.status == 0 { + s.status = http.StatusOK + } + return s.ResponseWriter.Write(b) +} + +// Unwrap lets http.NewResponseController reach the underlying writer, so it +// flushes (or reports ErrNotSupported) exactly as that writer does. +func (s *statusRecorder) Unwrap() http.ResponseWriter { return s.ResponseWriter } + // Principal/authorization helpers // getAccountID returns a stable caller identifier for ownership and permission checks. diff --git a/weed/s3api/s3tables/handler_log_level_test.go b/weed/s3api/s3tables/handler_log_level_test.go new file mode 100644 index 0000000000..8efc3bd3cd --- /dev/null +++ b/weed/s3api/s3tables/handler_log_level_test.go @@ -0,0 +1,123 @@ +package s3tables + +import ( + "errors" + "fmt" + "net/http" + "net/http/httptest" + "strings" + "testing" + + "github.com/seaweedfs/seaweedfs/weed/glog" +) + +// captureLogs swaps the two log sinks for recorders and restores them when the test ends. +func captureLogs(t *testing.T) (refusals, serverErrors *[]string) { + t.Helper() + var r, s []string + oldR, oldS := logClientRefusal, logServerError + logClientRefusal = func(f string, a ...interface{}) { r = append(r, fmt.Sprintf(f, a...)) } + logServerError = func(f string, a ...interface{}) { s = append(s, fmt.Sprintf(f, a...)) } + t.Cleanup(func() { logClientRefusal, logServerError = oldR, oldS }) + return &r, &s +} + +// A refusal the API answers with a 4xx is not a server error. +func TestRequestRefusedWith4xxIsNotLoggedAsError(t *testing.T) { + refusals, serverErrors := captureLogs(t) + h := NewS3TablesHandler() + req := httptest.NewRequest(http.MethodPost, "/", strings.NewReader("not json")) + req.Header.Set("X-Amz-Target", "S3Tables.ListNamespaces") + rec := httptest.NewRecorder() + h.HandleRequest(rec, req, nil) + if rec.Code < 400 || rec.Code >= 500 { + t.Fatalf("the probe request must be refused with a 4xx for this test to mean anything, got %d", rec.Code) // positive control + } + if len(*serverErrors) != 0 { + t.Fatalf("a %d refusal was logged at ERROR: %v", rec.Code, *serverErrors) + } + if len(*refusals) != 1 || !strings.Contains((*refusals)[0], "ListNamespaces refused") { + t.Fatalf("the refusal must still be logged once (at V(1)), got %v", *refusals) + } +} + +func TestLogRequestErrorByStatus(t *testing.T) { + for _, c := range []struct { + status int + wantError bool + }{{http.StatusForbidden, false}, {http.StatusNotFound, false}, {http.StatusConflict, false}, + {http.StatusInternalServerError, true}, {http.StatusServiceUnavailable, true}, {0, true}} { + refusals, serverErrors := captureLogs(t) + logRequestError("Op", c.status, errors.New("boom")) + if gotError := len(*serverErrors) == 1 && len(*refusals) == 0; gotError != c.wantError { + t.Errorf("status %d: ERROR=%v, want %v (refusals %v, errors %v)", c.status, gotError, c.wantError, *refusals, *serverErrors) + } + } +} + +func TestStatusRecorderKeepsTheFirstStatus(t *testing.T) { + rec := httptest.NewRecorder() + sw := &statusRecorder{ResponseWriter: rec} + _, _ = sw.Write([]byte("x")) + sw.WriteHeader(http.StatusInternalServerError) + if sw.status != http.StatusOK { + t.Fatalf("an implicit 200 by Write must win, got %d", sw.status) + } + sw2 := &statusRecorder{ResponseWriter: httptest.NewRecorder()} + sw2.WriteHeader(http.StatusForbidden) + if sw2.status != http.StatusForbidden { + t.Fatalf("got %d", sw2.status) + } +} + +func TestStatusRecorderUnwrapsForResponseController(t *testing.T) { + sw := &statusRecorder{ResponseWriter: httptest.NewRecorder()} + if err := http.NewResponseController(sw).Flush(); err != nil { + t.Fatalf("ResponseController through the recorder: %v", err) + } + if sw.Unwrap() == nil { + t.Fatal("Unwrap must return the wrapped writer") + } +} + +// A malformed CreateNamespace body is answered with a 400; neither the +// dispatcher nor the handler itself may log it at ERROR. +func TestMalformedCreateNamespaceIsNotLoggedAsError(t *testing.T) { + refusals, serverErrors := captureLogs(t) + + before := glog.Stats.Error.Lines() + glog.Errorf("S3Tables test: positive control for the ERROR line counter") + if glog.Stats.Error.Lines() != before+1 { + t.Fatal("the ERROR line counter did not see a direct glog.Errorf") // positive control + } + + h := NewS3TablesHandler() + req := httptest.NewRequest(http.MethodPost, "/", strings.NewReader("not json")) + req.Header.Set("X-Amz-Target", "S3Tables.CreateNamespace") + rec := httptest.NewRecorder() + before = glog.Stats.Error.Lines() + h.HandleRequest(rec, req, nil) + errorLines := glog.Stats.Error.Lines() - before + if rec.Code != http.StatusBadRequest { + t.Fatalf("a malformed body must be refused with 400, got %d", rec.Code) + } + if errorLines != 0 || len(*serverErrors) != 0 { + t.Fatalf("a 400 refusal was logged at ERROR: %d direct line(s), dispatcher %v", errorLines, *serverErrors) + } + if len(*refusals) != 1 || !strings.Contains((*refusals)[0], "CreateNamespace refused") { + t.Fatalf("the refusal must still be logged once (at V(1)), got %v", *refusals) + } +} + +// The recorder must not claim to flush a writer that cannot. +func TestStatusRecorderFlushFollowsTheWrappedWriter(t *testing.T) { + type plainWriter struct{ http.ResponseWriter } + sw := &statusRecorder{ResponseWriter: plainWriter{httptest.NewRecorder()}} + if err := http.NewResponseController(sw).Flush(); !errors.Is(err, http.ErrNotSupported) { + t.Fatalf("Flush through a recorder over a non-flushing writer: %v, want ErrNotSupported", err) + } + rec := httptest.NewRecorder() + if err := http.NewResponseController(&statusRecorder{ResponseWriter: rec}).Flush(); err != nil || !rec.Flushed { + t.Fatalf("Flush through a recorder over a flushing writer: err=%v flushed=%v", err, rec.Flushed) // positive control + } +} diff --git a/weed/s3api/s3tables/handler_namespace.go b/weed/s3api/s3tables/handler_namespace.go index 613a85045d..7aceece5ca 100644 --- a/weed/s3api/s3tables/handler_namespace.go +++ b/weed/s3api/s3tables/handler_namespace.go @@ -36,10 +36,9 @@ func (h *S3TablesHandler) mayRepairOwnerlessBucket(r *http.Request) bool { // handleCreateNamespace creates a new namespace in a table bucket func (h *S3TablesHandler) handleCreateNamespace(w http.ResponseWriter, r *http.Request, filerClient FilerClient) error { - glog.Errorf("S3Tables: handleCreateNamespace called") + glog.V(3).Infof("S3Tables: handleCreateNamespace called") var req CreateNamespaceRequest if err := h.readRequestBody(r, &req); err != nil { - glog.Errorf("S3Tables: handleCreateNamespace failed to read request body: %v", err) h.writeError(w, http.StatusBadRequest, ErrCodeInvalidRequest, err.Error()) return err } diff --git a/weed/s3api/s3tables/handler_no_trace_errorf_test.go b/weed/s3api/s3tables/handler_no_trace_errorf_test.go new file mode 100644 index 0000000000..3f4f34bb2b --- /dev/null +++ b/weed/s3api/s3tables/handler_no_trace_errorf_test.go @@ -0,0 +1,39 @@ +package s3tables + +import ( + "os" + "path/filepath" + "regexp" + "strings" + "testing" +) + +// glog.Errorf with a constant message and no format verb is a trace, not an +// error report: every CreateNamespace call logged +// "S3Tables: handleCreateNamespace called" at ERROR. +func TestNoTraceLoggedAtErrorLevel(t *testing.T) { + files, err := filepath.Glob("*.go") + if err != nil || len(files) == 0 { + t.Fatalf("no sources found (%v)", err) // positive control: the scan must see the package + } + re := regexp.MustCompile(`glog\.Errorf\("([^"]*)"\)`) + scanned := 0 + for _, f := range files { + if strings.HasSuffix(f, "_test.go") { + continue + } + b, err := os.ReadFile(f) + if err != nil { + t.Fatal(err) + } + scanned++ + for _, m := range re.FindAllStringSubmatch(string(b), -1) { + if !strings.Contains(m[1], "%") { + t.Errorf("%s: glog.Errorf(%q) logs a constant trace at ERROR; use glog.V(n).Infof", f, m[1]) + } + } + } + if scanned < 5 { + t.Fatalf("scanned only %d source files", scanned) + } +} diff --git a/weed/storage/volume_loading.go b/weed/storage/volume_loading.go index e87782feba..f237d33836 100644 --- a/weed/storage/volume_loading.go +++ b/weed/storage/volume_loading.go @@ -238,7 +238,7 @@ func (v *Volume) load(alsoLoadIndex bool, createDatIfMissing bool, needleMapKind glog.V(2).Infof("readSuperBlock volume %d version %v", v.Id, v.SuperBlock.Version) if v.HasRemoteFile() { // maybe temporary network problem - glog.Errorf("readSuperBlock remote volume %d: %v", v.Id, err) + logRemoteSuperBlockErr(v.Id, err) err = nil } } else { @@ -434,3 +434,11 @@ func datFileLoadError(fileName string, err error) error { } return fmt.Errorf("cannot load volume data %s: %v", fileName, err) } + +var logRemoteSuperBlockFault = glog.Errorf + +func logRemoteSuperBlockErr(id needle.VolumeId, err error) { + if err != nil { + logRemoteSuperBlockFault("readSuperBlock remote volume %d: %v", id, err) + } +} diff --git a/weed/storage/volume_remote_superblock_log_test.go b/weed/storage/volume_remote_superblock_log_test.go new file mode 100644 index 0000000000..365241188b --- /dev/null +++ b/weed/storage/volume_remote_superblock_log_test.go @@ -0,0 +1,21 @@ +package storage + +import ( + "errors" + "testing" +) + +func TestRemoteSuperBlockLogOnlyOnError(t *testing.T) { + var logged int + old := logRemoteSuperBlockFault + logRemoteSuperBlockFault = func(string, ...interface{}) { logged++ } + defer func() { logRemoteSuperBlockFault = old }() + logRemoteSuperBlockErr(219, nil) + if logged != 0 { + t.Fatalf("a nil error was logged at ERROR (the \"readSuperBlock remote volume 219: \" line)") + } + logRemoteSuperBlockErr(219, errors.New("timeout")) // positive control + if logged != 1 { + t.Fatalf("a real error must still be logged, got %d", logged) + } +}