diff --git a/e2e/app/rpc.go b/e2e/app/rpc.go index 8ae661f66..4feb5d4f3 100644 --- a/e2e/app/rpc.go +++ b/e2e/app/rpc.go @@ -107,7 +107,7 @@ func waitForNode(ctx context.Context, node *e2e.Node, height int64, timeout time defer timer.Stop() var lastHeight int64 - var lastErr error + lastErr := errors.New("no last error") lastChanged := time.Now() for { @@ -116,7 +116,7 @@ func waitForNode(ctx context.Context, node *e2e.Node, height int64, timeout time return nil, errors.Wrap(ctx.Err(), "context canceled") case <-timer.C: if time.Since(lastChanged) > timeout { - return nil, errors.New("timed out waiting for height", "name", node.Name, "height", height, "last_err", lastErr, "last_height", lastHeight) + return nil, errors.Wrap(lastErr, "timed out waiting for height", "name", node.Name, "height", height, "last_height", lastHeight) } status, err := client.Status(ctx) diff --git a/e2e/app/test.go b/e2e/app/test.go index 0a7bcb9e4..b53950cd7 100644 --- a/e2e/app/test.go +++ b/e2e/app/test.go @@ -5,6 +5,7 @@ import ( "encoding/json" "os" "path/filepath" + "strings" "github.com/omni-network/omni/lib/errors" "github.com/omni-network/omni/lib/log" @@ -74,11 +75,11 @@ func Test(ctx context.Context, def Definition, verbose bool) error { } log.Debug(ctx, "Env files", - EnvE2EManifest, manifestFile, - EnvInfraType, infd.Provider, - EnvInfraFile, infd.Path, - EnvE2EDeployInfo, deployInfoFile, - EnvE2ERPCEndpoints, endpointsFile, + strings.ToLower(EnvE2EManifest), manifestFile, + strings.ToLower(EnvInfraType), infd.Provider, + strings.ToLower(EnvInfraFile), infd.Path, + strings.ToLower(EnvE2EDeployInfo), deployInfoFile, + strings.ToLower(EnvE2ERPCEndpoints), endpointsFile, ) args := []string{"go", "test", "-timeout", "60s", "-count", "1"} diff --git a/halo/attest/keeper/keeper.go b/halo/attest/keeper/keeper.go index 167220816..85edfcc91 100644 --- a/halo/attest/keeper/keeper.go +++ b/halo/attest/keeper/keeper.go @@ -198,7 +198,7 @@ func (k *Keeper) addOne(ctx context.Context, agg *types.AggVote, valSetID uint64 } else if err != nil { return errors.Wrap(err, "by att unique key") } else if existing.GetFinalizedAttId() != 0 { - log.Debug(ctx, "Ignoring vote for attestation with finalized override", nil, + log.Debug(ctx, "Ignoring vote for attestation with finalized override", "agg_id", attID, "chain", k.namer(header.XChainVersion()), "attest_offset", header.AttestOffset, diff --git a/halo/evmstaking2/keeper/keeper.go b/halo/evmstaking2/keeper/keeper.go index c01e1d7ea..94b1ed7dc 100644 --- a/halo/evmstaking2/keeper/keeper.go +++ b/halo/evmstaking2/keeper/keeper.go @@ -177,7 +177,7 @@ func (k Keeper) processBufferedEvent(ctx context.Context, elog *evmenginetypes.E if err := catch(func() error { //nolint:contextcheck // False positive wrt ctx return k.parseAndDeliver(branchCtx, elog) }); err != nil { - log.Info(ctx, "Delivering EVM log event failed", "error", err, + log.InfoErr(ctx, "Delivering EVM log event failed", err, "name", k.Name(), "height", branchCtx.BlockHeight(), ) diff --git a/lib/contracts/feeoraclev1/feeparams.go b/lib/contracts/feeoraclev1/feeparams.go index eb4c77f8b..9474f4543 100644 --- a/lib/contracts/feeoraclev1/feeparams.go +++ b/lib/contracts/feeoraclev1/feeparams.go @@ -106,7 +106,7 @@ func conversionRate(ctx context.Context, pricer tokens.Pricer, from, to tokens.T prices, err := pricer.Price(ctx, from, to) if err != nil { - return 0, errors.Wrap(err, "get price", "ids", "from", from, "to", to) + return 0, errors.Wrap(err, "get price", "from", from, "to", to) } has := func(t tokens.Token) bool { diff --git a/lib/contracts/feeoraclev2/feeparams.go b/lib/contracts/feeoraclev2/feeparams.go index 0e90392b8..51dd4f681 100644 --- a/lib/contracts/feeoraclev2/feeparams.go +++ b/lib/contracts/feeoraclev2/feeparams.go @@ -105,7 +105,7 @@ func conversionRate(ctx context.Context, pricer tokens.Pricer, from, to tokens.T prices, err := pricer.Price(ctx, from, to) if err != nil { - return 0, errors.Wrap(err, "get price", "ids", "from", from, "to", to) + return 0, errors.Wrap(err, "get price", "from", from, "to", to) } has := func(t tokens.Token) bool { diff --git a/lib/log/log.go b/lib/log/log.go index 6b6d4dd6b..bfbade0bb 100644 --- a/lib/log/log.go +++ b/lib/log/log.go @@ -32,11 +32,33 @@ func Debug(ctx context.Context, msg string, attrs ...any) { log(ctx, slog.LevelDebug, msg, mergeAttrs(ctx, attrs)...) } +// DebugErr logs the message and error and attributes at debug level. +// If err is nil, it will not be logged, but rather use Debug in that case. +func DebugErr(ctx context.Context, msg string, err error, attrs ...any) { + if err != nil { + attrs = append(attrs, slog.String("err", err.Error())) + attrs = append(attrs, errAttrs(err)...) + } + + log(ctx, slog.LevelDebug, msg, mergeAttrs(ctx, attrs)...) +} + // Info logs the message and attributes at info level. func Info(ctx context.Context, msg string, attrs ...any) { log(ctx, slog.LevelInfo, msg, mergeAttrs(ctx, attrs)...) } +// InfoErr logs the message and error and attributes at info level. +// If err is nil, it will not be logged, but rather use Info in that case. +func InfoErr(ctx context.Context, msg string, err error, attrs ...any) { + if err != nil { + attrs = append(attrs, slog.String("err", err.Error())) + attrs = append(attrs, errAttrs(err)...) + } + + log(ctx, slog.LevelInfo, msg, mergeAttrs(ctx, attrs)...) +} + // Warn logs the message and error and attributes at warning level. // If err is nil, it will not be logged. func Warn(ctx context.Context, msg string, err error, attrs ...any) { diff --git a/lib/log/log_test.go b/lib/log/log_test.go index 6a058aa47..aecec90d3 100644 --- a/lib/log/log_test.go +++ b/lib/log/log_test.go @@ -46,6 +46,11 @@ func TestSimpleLogs(t *testing.T) { err = pkgerrors.Wrap(err, "pkg wrap") log.Warn(ctx, "Pkg wrapped error", err) } + { // InfoErr/DebugErr + err := errors.New("new", "new", "new") + log.DebugErr(ctx, "debug with error", err, "1", 1, "2", "two") + log.InfoErr(ctx, "info with error", err, "3", 3, "4", "four") + } }) } diff --git a/lib/log/testdata/TestSimpleLogs_cli.golden b/lib/log/testdata/TestSimpleLogs_cli.golden index 6f1d19dd0..530c2ff3b 100644 --- a/lib/log/testdata/TestSimpleLogs_cli.golden +++ b/lib/log/testdata/TestSimpleLogs_cli.golden @@ -7,3 +7,5 @@ err2 ctx debug message ctx_key1=ctx_value1 debug_key1=debug_value1 ctx info message ctx_key1=ctx_value1 ctx_key2=ctx_value2 info_key2=info_value2 Pkg wrapped error err="pkg wrap: omni wrap: new" wrap=wrap new=new +debug with error 1=1 2=two err=new new=new +info with error 3=3 4=four err=new new=new diff --git a/lib/log/testdata/TestSimpleLogs_console.golden b/lib/log/testdata/TestSimpleLogs_console.golden index 431139030..95ce4c1b3 100644 --- a/lib/log/testdata/TestSimpleLogs_console.golden +++ b/lib/log/testdata/TestSimpleLogs_console.golden @@ -7,3 +7,5 @@ 00-00-00 00:00:00 DEBU ctx debug message ctx_key1=ctx_value1 debug_key1=debug_value1 00-00-00 00:00:00 INFO ctx info message ctx_key1=ctx_value1 ctx_key2=ctx_value2 info_key2=info_value2 00-00-00 00:00:00 WARN Pkg wrapped error err="pkg wrap: omni wrap: new" wrap=wrap new=new stacktrace= +00-00-00 00:00:00 DEBU debug with error 1=1 2=two err=new new=new stacktrace= +00-00-00 00:00:00 INFO info with error 3=3 4=four err=new new=new stacktrace= diff --git a/lib/log/testdata/TestSimpleLogs_json.golden b/lib/log/testdata/TestSimpleLogs_json.golden index 259ced6e6..915a80a38 100644 --- a/lib/log/testdata/TestSimpleLogs_json.golden +++ b/lib/log/testdata/TestSimpleLogs_json.golden @@ -7,3 +7,5 @@ {"time":"00-00-00 00:00:00","level":"DEBUG","source":"","msg":"ctx debug message","ctx_key1":"ctx_value1","debug_key1":"debug_value1"} {"time":"00-00-00 00:00:00","level":"INFO","source":"","msg":"ctx info message","ctx_key1":"ctx_value1","ctx_key2":"ctx_value2","info_key2":"info_value2"} {"time":"00-00-00 00:00:00","level":"WARN","source":"","msg":"Pkg wrapped error","err":"pkg wrap: omni wrap: new","wrap":"wrap","new":"new","source":""} +{"time":"00-00-00 00:00:00","level":"DEBUG","source":"","msg":"debug with error","1":1,"2":"two","err":"new","new":"new","source":""} +{"time":"00-00-00 00:00:00","level":"INFO","source":"","msg":"info with error","3":3,"4":"four","err":"new","new":"new","source":""} diff --git a/lib/log/testdata/TestSimpleLogs_logfmt.golden b/lib/log/testdata/TestSimpleLogs_logfmt.golden index 608b0af23..38a6fe7d1 100644 --- a/lib/log/testdata/TestSimpleLogs_logfmt.golden +++ b/lib/log/testdata/TestSimpleLogs_logfmt.golden @@ -7,3 +7,5 @@ time="00-00-00 00:00:00" level=ERROR source= msg=err2 err="second: first time="00-00-00 00:00:00" level=DEBUG source= msg="ctx debug message" ctx_key1=ctx_value1 debug_key1=debug_value1 time="00-00-00 00:00:00" level=INFO source= msg="ctx info message" ctx_key1=ctx_value1 ctx_key2=ctx_value2 info_key2=info_value2 time="00-00-00 00:00:00" level=WARN source= msg="Pkg wrapped error" err="pkg wrap: omni wrap: new" wrap=wrap new=new source= +time="00-00-00 00:00:00" level=DEBUG source= msg="debug with error" 1=1 2=two err=new new=new source= +time="00-00-00 00:00:00" level=INFO source= msg="info with error" 3=3 4=four err=new new=new source= diff --git a/lib/netconf/provider.go b/lib/netconf/provider.go index 3bb426163..2318514b5 100644 --- a/lib/netconf/provider.go +++ b/lib/netconf/provider.go @@ -50,7 +50,7 @@ func AwaitOnExecutionChain(ctx context.Context, netID ID, portalRegistry *bindin } if !containsAll(network, expected) { - log.Info(ctx, "Execution registry doesn't contain all expected chains (will retry)", ""+ + log.Info(ctx, "Execution registry doesn't contain all expected chains (will retry)", "expected", expected, "actual", network.ChainNamesByIDs()) backoff() @@ -101,7 +101,7 @@ func AwaitOnConsensusChain(ctx context.Context, netID ID, cprov cchain.Provider, } if !containsAll(network, expected) { - log.Info(ctx, "Consensus registry doesn't contain all expected chains (will retry)", ""+ + log.Info(ctx, "Consensus registry doesn't contain all expected chains (will retry)", "expected", expected, "actual", network.ChainNamesByIDs()) backoff() diff --git a/lib/p2putil/disc_test.go b/lib/p2putil/disc_test.go index 8f9bfd895..9d0c1422f 100644 --- a/lib/p2putil/disc_test.go +++ b/lib/p2putil/disc_test.go @@ -66,7 +66,7 @@ func TestDiscv4(t *testing.T) { } } - log.Info("discovered nodes", "count", len(ips), "ips", ips) + t.Log("discovered nodes", "count", len(ips), "ips", ips) time.Sleep(time.Second * 2) } } diff --git a/lib/txmgr/config.go b/lib/txmgr/config.go index 814119f60..44a21fdc4 100644 --- a/lib/txmgr/config.go +++ b/lib/txmgr/config.go @@ -83,7 +83,7 @@ func (m CLIConfig) Check() error { } if m.MinBaseFeeGwei < m.MinTipCapGwei { return errors.New("minBaseFee smaller than minTipCap", - m.MinBaseFeeGwei, m.MinTipCapGwei) + "base", m.MinBaseFeeGwei, "min", m.MinTipCapGwei) } if m.ResubmissionTimeout == 0 { return errors.New("must provide ResubmissionTimeout") @@ -231,7 +231,7 @@ func NewConfig(cfg CLIConfig, privateKey *ecdsa.PrivateKey, client ethclient.Cli func newConfig(cfg CLIConfig, signer SignerFn, from common.Address, client ethclient.Client) (Config, error) { if err := cfg.Check(); err != nil { - return Config{}, errors.New("invalid config", err) + return Config{}, errors.Wrap(err, "invalid config") } feeLimitThreshold, err := GweiToWei(cfg.FeeLimitThresholdGwei) @@ -283,7 +283,7 @@ func (m Config) Check() error { } if m.MinBaseFee != nil && m.MinTipCap != nil && m.MinBaseFee.Cmp(m.MinTipCap) == -1 { return errors.New("minBaseFee smaller than minTipCap", - m.MinBaseFee, m.MinTipCap) + "base", m.MinBaseFee, "min", m.MinTipCap) } if m.ResubmissionTimeout == 0 { return errors.New("must provide ResubmissionTimeout") diff --git a/lib/txmgr/ether.go b/lib/txmgr/ether.go index 84df379e1..d5b32e7b7 100644 --- a/lib/txmgr/ether.go +++ b/lib/txmgr/ether.go @@ -13,7 +13,7 @@ import ( // GweiToWei converts a float64 GWei value into a big.Int Wei value. func GweiToWei(gwei float64) (*big.Int, error) { if math.IsNaN(gwei) || math.IsInf(gwei, 0) { - return nil, errors.New("invalid gwei value", gwei) + return nil, errors.New("invalid gwei value", "value", gwei) } // convert float GWei value into integer Wei value diff --git a/lib/txmgr/txmgr.go b/lib/txmgr/txmgr.go index 2ef9b8c5b..1906225f9 100644 --- a/lib/txmgr/txmgr.go +++ b/lib/txmgr/txmgr.go @@ -353,7 +353,7 @@ func (m *simple) publishTx(ctx context.Context, tx *types.Transaction, sendState if bumpFeesImmediately { newTx, err := m.increaseGasPrice(ctx, tx) if err != nil { - log.Info(ctx, "Unable to increase gas", err) + log.Warn(ctx, "Unable to increase gas", err) return tx, false } tx = newTx @@ -630,7 +630,7 @@ func (m *simple) checkLimits(tip, baseFee, bumpedTip, bumpedFee *big.Int) error } // if the value is over the max, add an error message if v.Cmp(max) > 0 { - errs = errors.New("bumped cap is over multiple of the suggested value", name, v, limit) + errs = errors.New("bumped cap is over multiple of the suggested value", name, v, "limit", limit) } } check(bumpedTip, maxTip, "tip") diff --git a/monitor/app/public_rpc.go b/monitor/app/public_rpc.go index 2382c8386..5ab0faebd 100644 --- a/monitor/app/public_rpc.go +++ b/monitor/app/public_rpc.go @@ -24,8 +24,6 @@ func monitorPublicRPCForever( return } - log.Info(ctx, "Setting up monitoring of a public RPC for %v", network.ID) - publicRPC, err := publicRPCEndpoint(network, omniChain, ethClients) if err != nil { log.Error(ctx, "Failed to dial into public RPC", err) @@ -34,6 +32,8 @@ func monitorPublicRPCForever( omniNodeRPC := ethClients[omniChain.ID] + log.Info(ctx, "Monitoring public RPC", "public", publicRPC, "local", omniNodeRPC) + ticker := time.NewTicker(time.Second * 30) defer ticker.Stop() diff --git a/monitor/routerecon/recon_internal_test.go b/monitor/routerecon/recon_internal_test.go index 153b456e1..17b0d87c0 100644 --- a/monitor/routerecon/recon_internal_test.go +++ b/monitor/routerecon/recon_internal_test.go @@ -112,7 +112,7 @@ func TestBasicHistorical(t *testing.T) { log.Info(ctx, "Max routescan offset", "stream", streamName, "offset", maxOffset, "src_timestamp", fmtTime(maxCrossTx.SrcTimestamp), "dst_timestamp", fmtTime(maxCrossTx.DstTimestamp)) sub, ok, err := conn.XProvider.GetSubmittedCursor(ctx, xchain.LatestRef, streamID) - log.Info(ctx, "Max onchain offset", "stream", streamName, "offset", sub.MsgOffset, "ok", ok, "err", err) + log.InfoErr(ctx, "Max onchain offset", err, "stream", streamName, "offset", sub.MsgOffset, "ok", ok) log.Info(ctx, "Missing routescan offsets", "stream", streamName, "indexed", len(offsets), "indexed_gaps", gaps, "unindexed", umath.SubtractOrZero(sub.MsgOffset, maxOffset)) } } diff --git a/relayer/app/worker.go b/relayer/app/worker.go index b09c8ac33..01dc86544 100644 --- a/relayer/app/worker.go +++ b/relayer/app/worker.go @@ -65,7 +65,7 @@ func (w *Worker) Run(ctx context.Context) { if ctx.Err() != nil { return } else if errors.Is(err, chaos.ErrChaos) { - log.Info(ctx, "Worker failed due to chaos testing, resetting", err) + log.InfoErr(ctx, "Worker failed due to chaos testing, resetting", err) } else { log.Warn(ctx, "Worker failed, resetting", err) } diff --git a/scripts/golint/logattrs.go b/scripts/golint/logattrs.go index 86a62ff64..8768f39d1 100644 --- a/scripts/golint/logattrs.go +++ b/scripts/golint/logattrs.go @@ -1,8 +1,12 @@ package main import ( + "bytes" "go/ast" + "go/constant" + "go/printer" "go/token" + "go/types" "regexp" "github.com/omni-network/omni/lib/errors" @@ -20,7 +24,7 @@ var logAttrsAnalyzer = &analysis.Analyzer{ if !ok { return nil, errors.New("analyzer is not of type *inspector.Inspector") } - diags, err := logAttrs(i) + diags, err := logAttrs(i, p.TypesInfo, p.Fset) if err != nil { return nil, errors.Wrap(err, "detect uint subtract") } @@ -34,7 +38,7 @@ var logAttrsAnalyzer = &analysis.Analyzer{ Requires: []*analysis.Analyzer{inspect.Analyzer}, } -func logAttrs(i *inspector.Inspector) ([]analysis.Diagnostic, error) { +func logAttrs(i *inspector.Inspector, info *types.Info, fset *token.FileSet) ([]analysis.Diagnostic, error) { var diags []analysis.Diagnostic var err error filter := []ast.Node{new(ast.CallExpr)} @@ -50,29 +54,55 @@ func logAttrs(i *inspector.Inspector) ([]analysis.Diagnostic, error) { return } - index, ok := attrIndex(selct, attrFuncs) + nonNil, ok := selectIndex(selct, noNilIndex) + if ok && isNil(call.Args[nonNil]) { + diags = append(diags, analysis.Diagnostic{ + Pos: call.Args[nonNil].Pos(), + Message: "info/debug-err called with nil error", + }) + } + + firstAttr, ok := selectIndex(selct, attrFuncs) if !ok { return } - for i := index; i < len(call.Args); i++ { + if call.Ellipsis != token.NoPos { + // Ignore attribute ellipses, since it is []any. + return + } + + for i := firstAttr; i < len(call.Args); i++ { arg := call.Args[i] - strLiteral, ok := arg.(*ast.BasicLit) + // Attribute keys must be either strings or slog.Attrs + stringVal, ok := getStringValue(arg, info) if !ok { + if !isStructType(arg, info, "log/slog", "Attr") { + diags = append(diags, analysis.Diagnostic{ + Pos: arg.Pos(), + Message: "bad log/error attribute key: " + format(fset, arg), + }) + } + continue } - if strLiteral.Kind != token.STRING { - return // Unexpected + + // Ensure next value isn't an error + if isError(call.Args, i+1, info) { + diags = append(diags, analysis.Diagnostic{ + Pos: arg.Pos(), + Message: "error attributes not allowed", + }) } // Skip next value i++ - if !isSnakeCase(strLiteral.Value) { + if !isSnakeCase(stringVal) { diags = append(diags, analysis.Diagnostic{ - Pos: strLiteral.Pos(), - Message: "log/error attribute key must be snake_case; not " + strLiteral.Value, + Pos: arg.Pos(), + Message: "log/error attribute key must be snake_case; not " + stringVal, }) } } @@ -81,13 +111,130 @@ func logAttrs(i *inspector.Inspector) ([]analysis.Diagnostic, error) { return diags, err } +// format returns the string representation of the expression. +func format(fset *token.FileSet, arg ast.Expr) string { + var out bytes.Buffer + _ = printer.Fprint(&out, fset, arg) + + return out.String() +} + +// getStringValue returns the quoted string value of the expression or false if not a string. +// It supports string literals and values declared in constant or variable specifications. +func getStringValue(expr ast.Expr, info *types.Info) (string, bool) { + const ignore = `"ignore"` // Dummy response to ignore some expressions + const typString = "string" + + switch v := expr.(type) { + case *ast.BasicLit: // Handle string literals + if v.Kind != token.STRING { + return "", false + } + + return v.Value, true + case *ast.Ident: // Handle identifiers (constants and variables) + typ, ok := info.Types[v] + if !ok { + return "", false + } + if typ.Value != nil && typ.Value.Kind() == constant.String { + return typ.Value.String(), true + } else if typ.Addressable() && typ.Type.String() == typString { + return ignore, true // Ignore string variables + } + case *ast.SelectorExpr: // Handle other package identifiers (constants and variables) + obj := info.ObjectOf(v.Sel) + if obj == nil { + return "", false + } + + typConst, ok := obj.(*types.Const) + if ok && typConst.Val().Kind() == constant.String { + return typConst.Val().String(), true + } + + typVar, ok := obj.(*types.Var) + if ok && typVar.Type().String() == typString { + return ignore, true // Ignore string variables + } + + return "", false + case *ast.CallExpr: + if info.TypeOf(expr).String() == typString { + return ignore, true // Ignore any string function call + } + } + + return "", false +} + +// isStructType returns true if the expression is a pkg.name struct type. +func isStructType(arg ast.Expr, info *types.Info, pkg string, name string) bool { + // Get the type of the expression from the type-checking information + typ := info.TypeOf(arg) + if typ == nil { + return false + } + + // Ensure the type is a named type (e.g., pkg.name) + named, ok := typ.(*types.Named) + if !ok { + return false + } + + // Check if the underlying type is a struct + _, ok = named.Underlying().(*types.Struct) + if !ok { + return false + } + + // Check the package path and type name + obj := named.Obj() + if obj == nil { + return false + } + + return obj.Pkg().Path() == pkg && obj.Name() == name +} + +// isError checks if the ith index expression in args implements the error interface. +func isError(args []ast.Expr, i int, info *types.Info) bool { + // Ensure the index is within bounds + if i >= len(args) { + return false + } + + // Get the type of the expression + expr := args[i] + typ := info.TypeOf(expr) + if typ == nil { + return false + } + + // Check if the type implements the error interface + errorType := types.Universe.Lookup("error").Type().Underlying().(*types.Interface) + + return types.Implements(typ, errorType) +} + +// isNil returns true if the expression is nil. +func isNil(expr ast.Expr) bool { + ident, ok := expr.(*ast.Ident) + if !ok { + return false + } + + return ident.Name == "nil" && ident.Obj == nil +} + var snakeRegex = regexp.MustCompile(`"[a-z0-9_]+"`) func isSnakeCase(value string) bool { return snakeRegex.MatchString(value) } -func attrIndex(selct *ast.SelectorExpr, selectors map[string]map[string]int) (int, bool) { +// selectIndex returns the selector index matching the provided select expr. +func selectIndex(selct *ast.SelectorExpr, selectors map[string]map[string]int) (int, bool) { funIdent, ok := selct.X.(*ast.Ident) if !ok { return 0, false @@ -103,12 +250,23 @@ func attrIndex(selct *ast.SelectorExpr, selectors map[string]map[string]int) (in return index, ok } +// noNilIndex is a map of package name to function name to the index that must not be nil. +var noNilIndex = map[string]map[string]int{ + "log": { + "DebugErr": 2, + "InfoErr": 2, + }, +} + +// attrFuncs is a map of package name to function name to the index of the first slog any attribute. var attrFuncs = map[string]map[string]int{ "log": { - "Debug": 2, - "Info": 2, - "Warn": 3, - "Error": 3, + "Debug": 2, + "DebugErr": 3, + "Info": 2, + "InfoErr": 3, + "Warn": 3, + "Error": 3, }, "errors": { "Wrap": 2, diff --git a/scripts/golint/logattrs_internal_test.go b/scripts/golint/logattrs_internal_test.go index d0f60c5ea..bc7bb92b6 100644 --- a/scripts/golint/logattrs_internal_test.go +++ b/scripts/golint/logattrs_internal_test.go @@ -15,10 +15,13 @@ import ( "context" "main/log" "main/errors" + "log/slog" + "strings" ) func main() { ctx := context.Background() + log.Debug(ctx, "Good, no attrs") log.Debug(ctx, "Good, valid attrs", "foo", "bar", "snake_case", "qux") log.Debug(ctx, "Bad, invalid attrs", "foo", "bar", "camelCase", "qux") // want "log/error attribute key must be snake_case" @@ -29,6 +32,32 @@ func main() { log.Warn(ctx, "no extra attrs", err) log.Warn(ctx, "good attrs", err, "foo", "bar", "snake_case", "Values don't matter'") log.Error(ctx, "bad attrs", err, "camelCase", "qux") // want "log/error attribute key must be snake_case" + + log.InfoErr(ctx, "Good, no attrs", err) + log.InfoErr(ctx, "Good, valid attrs", err, "foo", "bar", "snake_case", "qux") + log.DebugErr(ctx, "Bad, invalid attrs", err, "foo", "bar", "camelCase", "qux") // want "log/error attribute key must be snake_case" + log.DebugErr(ctx, "Bad, nil error", nil, "foo", "bar") // want "info/debug-err called with nil error" + log.InfoErr(ctx, "Bad, nil error", nil) // want "info/debug-err called with nil error" + + log.Debug(ctx, "Bad, err attr", "error", err) // want "error attributes not allowed" + log.Info(ctx, "Bad, err attr", "foo", "bar", "err", err) // want "error attributes not allowed" + log.Warn(ctx, "Bad, err attr", nil, "foo", "bar", "err", err) // want "error attributes not allowed" + err = errors.New("bad, err attr", "foo", "bar", "err", err) // want "error attributes not allowed" + + err = errors.Wrap(err, "wrap", nil) // want "bad log/error attribute key" + log.Debug(ctx, "Bad attr key", err) // want "bad log/error attribute key" + log.Info(ctx, "Bad attr key", "key", "value", -1) // want "bad log/error attribute key" + log.Warn(ctx, "Bad attr key", nil, struct{}{}) // want "bad log/error attribute key" + + + log.Debug(ctx, "slog attr ok", slog.String("notChecked", "")) + log.Info(ctx, "Ignore []any...", []any{1,2,"three"}...) + var key string + log.Info(ctx, "Ignore string vars", key, "value") + + tup := struct{ Key string }{""} + log.Info(ctx, "Ignore string fields", tup.Key, "value") + log.Info(ctx, "Ignore function calls", strings.ToUpper("ok"), "value") } ` @@ -39,7 +68,9 @@ import ( ) func Debug(context.Context, string, ...any) {} +func DebugErr(context.Context, string, error, ...any) {} func Info(context.Context, string, ...any) {} +func InfoErr(context.Context, string, error, ...any) {} func Warn(context.Context, string, error, ...any) {} func Error(context.Context, string, error, ...any) {} ` diff --git a/scripts/join/join_test.go b/scripts/join/join_test.go index 553f84f2a..bb3108c51 100644 --- a/scripts/join/join_test.go +++ b/scripts/join/join_test.go @@ -113,7 +113,7 @@ func TestJoinNetwork(t *testing.T) { case <-ctx.Done(): return nil case <-timeoutCtx.Done(): - return errors.New("timed out waiting for sync", "duration", "duration", time.Since(t0).Truncate(time.Second)) + return errors.New("timed out waiting for sync", "duration", time.Since(t0).Truncate(time.Second)) case <-ticker.C: haloStatus, err := retry(ctx, haloStatus) require.NoError(t, err)