From d3b229562c9298123a3536ab6a34ff3dfaead302 Mon Sep 17 00:00:00 2001 From: Bakhtiyar Neyman Date: Wed, 21 Jan 2026 16:48:06 -0800 Subject: [PATCH] zfscmd: avoid word "error" in info-level log lines (#873) A number of tools including `lnav` do a crude string matching against the word "error". For zrepl this results in benign lines being colored red. It would be better if the logged message was something like "command ran successfully". refs - #872 --------- Co-authored-by: Christian Schwarz --- .../zfscmd/zfscmd-logging-scraper/zfscmd_logging_scraper.go | 2 +- .../zfscmd-logging-scraper/zfscmd_logging_scrapter_test.go | 4 ++-- internal/zfs/zfscmd/zfscmd_logging.go | 2 +- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scraper.go b/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scraper.go index 4642f92..7489643 100644 --- a/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scraper.go +++ b/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scraper.go @@ -23,7 +23,7 @@ type RuntimeLine struct { Error string } -var humanFormatterLineRE = regexp.MustCompile(`^(\[[^\]]+\]){2}\[zfs.cmd\]\[[^\]]+\]:\s+command\s+exited\s+(with|without)\s+error\s+(.+)`) +var humanFormatterLineRE = regexp.MustCompile(`^(\[[^\]]+\]){2}\[zfs.cmd\]\[[^\]]+\]:\s+command\s+exited\s+with\s+(success|error)\s+(.+)`) func parseSecs(s string) (time.Duration, error) { d, err := time.ParseDuration(s + "s") diff --git a/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scrapter_test.go b/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scrapter_test.go index 2d43b38..18c6d53 100644 --- a/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scrapter_test.go +++ b/internal/zfs/zfscmd/zfscmd-logging-scraper/zfscmd_logging_scrapter_test.go @@ -30,7 +30,7 @@ func TestParseHumanFormatter(t *testing.T) { tcs := []testCase{ { Name: "human-formatter-noerror", - Input: `2020-04-04T00:00:05+02:00 [DEBG][jobname][zfs.cmd][task$stack$span.stack]: command exited without error usertime_s="0.008445" cmd="zfs list -H -p -o name -r -t filesystem,volume" systemtime_s="0.033783" invocation="84" total_time_s="0.037828619"`, + Input: `2020-04-04T00:00:05+02:00 [DEBG][jobname][zfs.cmd][task$stack$span.stack]: command exited with success usertime_s="0.008445" cmd="zfs list -H -p -o name -r -t filesystem,volume" systemtime_s="0.033783" invocation="84" total_time_s="0.037828619"`, Expect: &RuntimeLine{ Cmd: "zfs list -H -p -o name -r -t filesystem,volume", TotalTime: secs("0.037828619"), @@ -54,7 +54,7 @@ func TestParseHumanFormatter(t *testing.T) { }, { Name: "from graylog", - Input: `2020-04-04T00:00:05+02:00 [DEBG][csnas][zfs.cmd][task$stack$span.stack]: command exited without error usertime_s="0" cmd="zfs send -i zroot/ezjail/synapse-12@zrepl_20200329_095518_000 zroot/ezjail/synapse-12@zrepl_20200329_102454_000" total_time_s="0.101598591" invocation="85" systemtime_s="0.041581"`, + Input: `2020-04-04T00:00:05+02:00 [DEBG][csnas][zfs.cmd][task$stack$span.stack]: command exited with success usertime_s="0" cmd="zfs send -i zroot/ezjail/synapse-12@zrepl_20200329_095518_000 zroot/ezjail/synapse-12@zrepl_20200329_102454_000" total_time_s="0.101598591" invocation="85" systemtime_s="0.041581"`, Expect: &RuntimeLine{ Cmd: "zfs send -i zroot/ezjail/synapse-12@zrepl_20200329_095518_000 zroot/ezjail/synapse-12@zrepl_20200329_102454_000", TotalTime: secs("0.101598591"), diff --git a/internal/zfs/zfscmd/zfscmd_logging.go b/internal/zfs/zfscmd/zfscmd_logging.go index 0c65a05..01df34e 100644 --- a/internal/zfs/zfscmd/zfscmd_logging.go +++ b/internal/zfs/zfscmd/zfscmd_logging.go @@ -35,7 +35,7 @@ func waitPostLogging(c *Cmd, u usage, err error, now time.Time) { WithField("usertime_s", u.user_secs) if err == nil { - log.Info("command exited without error") + log.Info("command exited with success") } else { log.WithError(err).Info("command exited with error") }