diff --git a/cmd/ipfs/kubo/start.go b/cmd/ipfs/kubo/start.go index 19a88f37c..4a8709cc6 100644 --- a/cmd/ipfs/kubo/start.go +++ b/cmd/ipfs/kubo/start.go @@ -214,8 +214,8 @@ func insideGUI() bool { func checkDebug(req *cmds.Request) { // check if user wants to debug. option OR env var. debug, _ := req.Options["debug"].(bool) - ipfsLogLevel, _ := logging.LevelFromString(os.Getenv("IPFS_LOGGING")) // IPFS_LOGGING is deprecated - goLogLevel, _ := logging.LevelFromString(os.Getenv("GOLOG_LOG_LEVEL")) + ipfsLogLevel, _ := logging.Parse(os.Getenv("IPFS_LOGGING")) // IPFS_LOGGING is deprecated + goLogLevel, _ := logging.Parse(os.Getenv("GOLOG_LOG_LEVEL")) if debug || goLogLevel == logging.LevelDebug || ipfsLogLevel == logging.LevelDebug { u.Debug = true diff --git a/core/commands/log.go b/core/commands/log.go index 81427aa13..0ebb1ac43 100644 --- a/core/commands/log.go +++ b/core/commands/log.go @@ -3,16 +3,37 @@ package commands import ( "fmt" "io" + "slices" cmds "github.com/ipfs/go-ipfs-cmds" logging "github.com/ipfs/go-log/v2" ) -// Golang os.Args overrides * and replaces the character argument with -// an array which includes every file in the user's CWD. As a -// workaround, we use 'all' instead. The util library still uses * so -// we convert it at this step. -var logAllKeyword = "all" +const ( + // allLogSubsystems is used to specify all log subsystems when setting the + // log level. + allLogSubsystems = "*" + // allLogSubsystemsAlias is a convenience alias for allLogSubsystems that + // doesn't require shell escaping. + allLogSubsystemsAlias = "all" + // defaultLogLevel is used to request and to identify the default log + // level. + defaultLogLevel = "default" + // defaultSubsystemKey is the subsystem name that is used to denote the + // default log level. We use parentheses for UI clarity to distinguish it + // from regular subsystem names. + defaultSubsystemKey = "(default)" + // logLevelOption is an option for the tail subcommand to select the log + // level to output. + logLevelOption = "log-level" + // noSubsystemSpecified is used when no subsystem argument is provided + noSubsystemSpecified = "" +) + +type logLevelOutput struct { + Levels map[string]string `json:",omitempty"` + Message string `json:",omitempty"` +} var LogCmd = &cmds.Command{ Helptext: cmds.HelpText{ @@ -39,46 +60,161 @@ system (not just for the daemon logs, but all commands): var logLevelCmd = &cmds.Command{ Helptext: cmds.HelpText{ - Tagline: "Change the logging level.", + Tagline: "Change or get the logging level.", ShortDescription: ` -Change the verbosity of one or all subsystems log output. This does not affect -the event log. +Get or change the logging level of one or all logging subsystems. + +This command provides a runtime alternative to the GOLOG_LOG_LEVEL +environment variable for debugging and troubleshooting. + +UNDERSTANDING DEFAULT vs '*': + +The "default" level is the fallback used by unconfigured subsystems. +You cannot set the default level directly - it only changes when you use '*'. + +The '*' wildcard represents ALL subsystems including the default level. +Setting '*' changes everything at once, including the default. + +EXAMPLES - Getting levels: + + ipfs log level # Show only the default fallback level + ipfs log level all # Show all subsystem levels (100+ lines) + ipfs log level core # Show level for 'core' subsystem only + +EXAMPLES - Setting levels: + + ipfs log level core debug # Set 'core' to 'debug' (default unchanged) + ipfs log level all info # Set ALL to 'info' (including default) + ipfs log level core default # Reset 'core' to use current default level + +WILDCARD OPTIONS: + +Use 'all' (convenient) or '*' (requires escaping) to affect all subsystems: + ipfs log level all debug # Convenient - no shell escaping needed + ipfs log level '*' debug # Equivalent but needs quotes: '*' or "*" or \* + +BEHAVIOR EXAMPLES: + +Initial state (all using default 'error'): + $ ipfs log level => error + $ ipfs log level core => error + +After setting one subsystem: + $ ipfs log level core debug + $ ipfs log level => error (default unchanged!) + $ ipfs log level core => debug (explicitly set) + $ ipfs log level dht => error (still uses default) + +After setting everything with 'all': + $ ipfs log level all info + $ ipfs log level => info (default changed!) + $ ipfs log level core => info (all changed) + $ ipfs log level dht => info (all changed) + +The 'default' keyword always refers to the current default level: + $ ipfs log level => error + $ ipfs log level core default # Sets core to 'error' + $ ipfs log level all info # Changes default to 'info' + $ ipfs log level core default # Now sets core to 'info' `, }, Arguments: []cmds.Argument{ - // TODO use a different keyword for 'all' because all can theoretically - // clash with a subsystem name - cmds.StringArg("subsystem", true, false, fmt.Sprintf("The subsystem logging identifier. Use '%s' for all subsystems.", logAllKeyword)), - cmds.StringArg("level", true, false, `The log level, with 'debug' the most verbose and 'fatal' the least verbose. - One of: debug, info, warn, error, dpanic, panic, fatal. - `), + cmds.StringArg("subsystem", false, false, fmt.Sprintf("The subsystem logging identifier. Use '%s' or '%s' to get or set the log level of all subsystems including the default. If not specified, only show the default log level.", allLogSubsystemsAlias, allLogSubsystems)), + cmds.StringArg("level", false, false, fmt.Sprintf("The log level, with 'debug' as the most verbose and 'fatal' the least verbose. Use '%s' to set to the current default level. One of: debug, info, warn, error, dpanic, panic, fatal, %s", defaultLogLevel, defaultLogLevel)), }, NoLocal: true, Run: func(req *cmds.Request, res cmds.ResponseEmitter, env cmds.Environment) error { - args := req.Arguments - subsystem, level := args[0], args[1] + var level, subsystem string - if subsystem == logAllKeyword { - subsystem = "*" + if len(req.Arguments) > 0 { + subsystem = req.Arguments[0] + if len(req.Arguments) > 1 { + level = req.Arguments[1] + } + + // Normalize aliases to the canonical "*" form + if subsystem == allLogSubsystems || subsystem == allLogSubsystemsAlias { + subsystem = "*" + } } - if err := logging.SetLogLevel(subsystem, level); err != nil { - return err + // If a level is specified, then set the log level. + if level != "" { + if level == defaultLogLevel { + level = logging.DefaultLevel().String() + } + + if err := logging.SetLogLevel(subsystem, level); err != nil { + return err + } + + s := fmt.Sprintf("Changed log level of '%s' to '%s'\n", subsystem, level) + log.Info(s) + + return cmds.EmitOnce(res, &logLevelOutput{Message: s}) } - s := fmt.Sprintf("Changed log level of '%s' to '%s'\n", subsystem, level) - log.Info(s) + // Get the level for the requested subsystem. + switch subsystem { + case noSubsystemSpecified: + // Return the default log level + levelMap := map[string]string{logging.DefaultName: logging.DefaultLevel().String()} + return cmds.EmitOnce(res, &logLevelOutput{Levels: levelMap}) + case allLogSubsystems, allLogSubsystemsAlias: + // Return levels for all subsystems (default behavior) + levels := logging.SubsystemLevelNames() + + // Replace default subsystem key with defaultSubsystemKey. + levels[defaultSubsystemKey] = levels[logging.DefaultName] + delete(levels, logging.DefaultName) + return cmds.EmitOnce(res, &logLevelOutput{Levels: levels}) + default: + // Return level for a specific subsystem. + level, err := logging.SubsystemLevelName(subsystem) + if err != nil { + return err + } + levelMap := map[string]string{subsystem: level} + return cmds.EmitOnce(res, &logLevelOutput{Levels: levelMap}) + } - return cmds.EmitOnce(res, &MessageOutput{s}) }, Encoders: cmds.EncoderMap{ - cmds.Text: cmds.MakeTypedEncoder(func(req *cmds.Request, w io.Writer, out *MessageOutput) error { - fmt.Fprint(w, out.Message) + cmds.Text: cmds.MakeTypedEncoder(func(req *cmds.Request, w io.Writer, out *logLevelOutput) error { + if out.Message != "" { + fmt.Fprint(w, out.Message) + return nil + } + + // Check if this is an RPC call by looking for the encoding option + encoding, _ := req.Options["encoding"].(string) + isRPC := encoding == "json" + + // Determine whether to show subsystem names in output. + // Show subsystem names when: + // 1. It's an RPC call (needs JSON structure with named fields) + // 2. Multiple subsystems are displayed (for clarity when showing many levels) + showNames := isRPC || len(out.Levels) > 1 + + levelNames := make([]string, 0, len(out.Levels)) + for subsystem, level := range out.Levels { + if showNames { + // Show subsystem name when it's RPC or when showing multiple subsystems + levelNames = append(levelNames, fmt.Sprintf("%s: %s", subsystem, level)) + } else { + // For CLI calls with single subsystem, only show the level + levelNames = append(levelNames, level) + } + } + slices.Sort(levelNames) + for _, ln := range levelNames { + fmt.Fprintln(w, ln) + } return nil }), }, - Type: MessageOutput{}, + Type: logLevelOutput{}, } var logLsCmd = &cmds.Command{ @@ -103,12 +239,10 @@ subsystems of a running daemon. Type: stringList{}, } -const logLevelOption = "log-level" - var logTailCmd = &cmds.Command{ Status: cmds.Experimental, Helptext: cmds.HelpText{ - Tagline: "Read and outpt log messages.", + Tagline: "Read and output log messages.", ShortDescription: ` Outputs log messages as they are generated. @@ -130,7 +264,7 @@ This will only return 'info' logs from bitswap and skip 'debug'. var pipeReader *logging.PipeReader logLevelString, _ := req.Options[logLevelOption].(string) if logLevelString != "" { - logLevel, err := logging.LevelFromString(logLevelString) + logLevel, err := logging.Parse(logLevelString) if err != nil { return fmt.Errorf("setting log level %s: %w", logLevelString, err) } diff --git a/docs/changelogs/v0.37.md b/docs/changelogs/v0.37.md index b9c20500c..802772eed 100644 --- a/docs/changelogs/v0.37.md +++ b/docs/changelogs/v0.37.md @@ -11,7 +11,8 @@ This release was brought to you by the [Shipyard](https://ipshipyard.com/) team. - [Overview](#overview) - [๐Ÿ”ฆ Highlights](#-highlights) - [Clear provide queue when reprovide strategy changes](#clear-provide-queue-when-reprovide-strategy-changes) - - [Named pins in `ipfs add` command](#-named-pins-in-ipfs-add-command) + - [๐Ÿชต Revamped `ipfs log level` command](#-revamped-ipfs-log-level-command) + - [๐Ÿ“Œ Named pins in `ipfs add` command](#-named-pins-in-ipfs-add-command) - [โš™๏ธ `Reprovider.Strategy` is now consistently respected](#-reprovider-strategy-is-now-consistently-respected) - [Removed unnecessary dependencies](#removed-unnecessary-dependencies) - [Deprecated `ipfs stats reprovide`](#deprecated-ipfs-stats-reprovide) @@ -34,6 +35,26 @@ A new `ipfs provide clear` command also allows manual queue clearing for debuggi > [!NOTE] > Upgrading to Kubo 0.37 will automatically clear any preexisting provide queue. The next time `Reprovider.Interval` hits, `Reprovider.Strategy` will be executed on a clean slate, ensuring consistent behavior with your current configuration. +#### ๐Ÿชต Revamped `ipfs log level` command + +The `ipfs log level` command has been completely revamped to support both getting and setting log levels with a unified interface. + +**New: Getting log levels** + +- `ipfs log level` - Shows default level only +- `ipfs log level all` - Shows log level for every subsystem, including default level +- `ipfs log level foo` - Shows log level for a specific subsystem only +- Kubo RPC API: `POST /api/v0/log/level?arg=` + +**Enhanced: Setting log levels** + +- `ipfs log level foo debug` - Sets "foo" subsystem to "debug" level +- `ipfs log level all info` - Sets all subsystems to "info" level (convenient, no escaping) +- `ipfs log level '*' info` - Equivalent to above but requires shell escaping +- `ipfs log level foo default` - Sets "foo" subsystem to current default level + +The command now provides full visibility into your current logging configuration while maintaining full backward compatibility. Both `all` and `*` work for specifying all subsystems, with `all` being more convenient since it doesn't require shell escaping. + #### ๐Ÿงท Named pins in `ipfs add` command Added `--pin-name` flag to `ipfs add` for assigning names to pins. diff --git a/docs/examples/kubo-as-a-library/go.mod b/docs/examples/kubo-as-a-library/go.mod index 6eb207e06..62a426a24 100644 --- a/docs/examples/kubo-as-a-library/go.mod +++ b/docs/examples/kubo-as-a-library/go.mod @@ -90,7 +90,7 @@ require ( github.com/ipfs/go-ipld-format v0.6.2 // indirect github.com/ipfs/go-ipld-git v0.1.1 // indirect github.com/ipfs/go-ipld-legacy v0.2.2 // indirect - github.com/ipfs/go-log/v2 v2.6.0 // indirect + github.com/ipfs/go-log/v2 v2.8.0 // indirect github.com/ipfs/go-metrics-interface v0.3.0 // indirect github.com/ipfs/go-peertaskqueue v0.8.2 // indirect github.com/ipfs/go-unixfsnode v1.10.1 // indirect diff --git a/docs/examples/kubo-as-a-library/go.sum b/docs/examples/kubo-as-a-library/go.sum index 2e1ffc0a9..dd36ec029 100644 --- a/docs/examples/kubo-as-a-library/go.sum +++ b/docs/examples/kubo-as-a-library/go.sum @@ -345,8 +345,8 @@ github.com/ipfs/go-ipld-legacy v0.2.2/go.mod h1:hhkj+b3kG9b2BcUNw8IFYAsfeNo8E3U7 github.com/ipfs/go-log v0.0.1/go.mod h1:kL1d2/hzSpI0thNYjiKfjanbVNU+IIGA/WnNESY9leM= github.com/ipfs/go-log v1.0.5 h1:2dOuUCB1Z7uoczMWgAyDck5JLb72zHzrMnGnCNNbvY8= github.com/ipfs/go-log v1.0.5/go.mod h1:j0b8ZoR+7+R99LD9jZ6+AJsrzkPbSXbZfGakb5JPtIo= -github.com/ipfs/go-log/v2 v2.6.0 h1:2Nu1KKQQ2ayonKp4MPo6pXCjqw1ULc9iohRqWV5EYqg= -github.com/ipfs/go-log/v2 v2.6.0/go.mod h1:p+Efr3qaY5YXpx9TX7MoLCSEZX5boSWj9wh86P5HJa8= +github.com/ipfs/go-log/v2 v2.8.0 h1:SptNTPJQV3s5EF4FdrTu/yVdOKfGbDgn1EBZx4til2o= +github.com/ipfs/go-log/v2 v2.8.0/go.mod h1:2LEEhdv8BGubPeSFTyzbqhCqrwqxCbuTNTLWqgNAipo= github.com/ipfs/go-metrics-interface v0.3.0 h1:YwG7/Cy4R94mYDUuwsBfeziJCVm9pBMJ6q/JR9V40TU= github.com/ipfs/go-metrics-interface v0.3.0/go.mod h1:OxxQjZDGocXVdyTPocns6cOLwHieqej/jos7H4POwoY= github.com/ipfs/go-peertaskqueue v0.8.2 h1:PaHFRaVFdxQk1Qo3OKiHPYjmmusQy7gKQUaL8JDszAU= diff --git a/go.mod b/go.mod index f58ade570..ea43881ea 100644 --- a/go.mod +++ b/go.mod @@ -39,7 +39,7 @@ require ( github.com/ipfs/go-ipld-format v0.6.2 github.com/ipfs/go-ipld-git v0.1.1 github.com/ipfs/go-ipld-legacy v0.2.2 - github.com/ipfs/go-log/v2 v2.6.0 + github.com/ipfs/go-log/v2 v2.8.0 github.com/ipfs/go-metrics-interface v0.3.0 github.com/ipfs/go-metrics-prometheus v0.1.0 github.com/ipfs/go-test v0.2.2 diff --git a/go.sum b/go.sum index 5f217d258..b2e033f9d 100644 --- a/go.sum +++ b/go.sum @@ -414,8 +414,8 @@ github.com/ipfs/go-ipld-legacy v0.2.2/go.mod h1:hhkj+b3kG9b2BcUNw8IFYAsfeNo8E3U7 github.com/ipfs/go-log v0.0.1/go.mod h1:kL1d2/hzSpI0thNYjiKfjanbVNU+IIGA/WnNESY9leM= github.com/ipfs/go-log v1.0.5 h1:2dOuUCB1Z7uoczMWgAyDck5JLb72zHzrMnGnCNNbvY8= github.com/ipfs/go-log v1.0.5/go.mod h1:j0b8ZoR+7+R99LD9jZ6+AJsrzkPbSXbZfGakb5JPtIo= -github.com/ipfs/go-log/v2 v2.6.0 h1:2Nu1KKQQ2ayonKp4MPo6pXCjqw1ULc9iohRqWV5EYqg= -github.com/ipfs/go-log/v2 v2.6.0/go.mod h1:p+Efr3qaY5YXpx9TX7MoLCSEZX5boSWj9wh86P5HJa8= +github.com/ipfs/go-log/v2 v2.8.0 h1:SptNTPJQV3s5EF4FdrTu/yVdOKfGbDgn1EBZx4til2o= +github.com/ipfs/go-log/v2 v2.8.0/go.mod h1:2LEEhdv8BGubPeSFTyzbqhCqrwqxCbuTNTLWqgNAipo= github.com/ipfs/go-metrics-interface v0.3.0 h1:YwG7/Cy4R94mYDUuwsBfeziJCVm9pBMJ6q/JR9V40TU= github.com/ipfs/go-metrics-interface v0.3.0/go.mod h1:OxxQjZDGocXVdyTPocns6cOLwHieqej/jos7H4POwoY= github.com/ipfs/go-metrics-prometheus v0.1.0 h1:bApWOHkrH3VTBHzTHrZSfq4n4weOZDzZFxUXv+HyKcA= diff --git a/test/cli/log_level_test.go b/test/cli/log_level_test.go new file mode 100644 index 000000000..e5c9eb8f8 --- /dev/null +++ b/test/cli/log_level_test.go @@ -0,0 +1,663 @@ +package cli + +import ( + "encoding/json" + "fmt" + "net/http" + "strings" + "testing" + + "github.com/ipfs/kubo/test/cli/harness" + . "github.com/ipfs/kubo/test/cli/testutils" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestLogLevel(t *testing.T) { + + t.Run("CLI", func(t *testing.T) { + t.Run("level '*' shows all subsystems", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + expectedSubsystems := getExpectedSubsystems(t, node) + + res := node.IPFS("log", "level", "*") + assert.NoError(t, res.Err) + assert.Empty(t, res.Stderr.Lines()) + + actualSubsystems := parseCLIOutput(t, res.Stdout.String()) + + // Should show all subsystems plus the (default) entry + assert.GreaterOrEqual(t, len(actualSubsystems), len(expectedSubsystems)) + + validateAllSubsystemsPresentCLI(t, expectedSubsystems, actualSubsystems, "CLI output") + + // Should have the (default) entry + _, hasDefault := actualSubsystems["(default)"] + assert.True(t, hasDefault, "Should have '(default)' entry") + }) + + t.Run("level 'all' shows all subsystems (alias for '*')", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + expectedSubsystems := getExpectedSubsystems(t, node) + + res := node.IPFS("log", "level", "all") + assert.NoError(t, res.Err) + assert.Empty(t, res.Stderr.Lines()) + + actualSubsystems := parseCLIOutput(t, res.Stdout.String()) + + // Should show all subsystems plus the (default) entry + assert.GreaterOrEqual(t, len(actualSubsystems), len(expectedSubsystems)) + + validateAllSubsystemsPresentCLI(t, expectedSubsystems, actualSubsystems, "CLI output") + + // Should have the (default) entry + _, hasDefault := actualSubsystems["(default)"] + assert.True(t, hasDefault, "Should have '(default)' entry") + }) + + t.Run("get level for specific subsystem", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + node.IPFS("log", "level", "core", "debug") + res := node.IPFS("log", "level", "core") + assert.NoError(t, res.Err) + assert.Empty(t, res.Stderr.Lines()) + + output := res.Stdout.String() + lines := SplitLines(output) + + assert.Equal(t, 1, len(lines)) + + line := strings.TrimSpace(lines[0]) + assert.Equal(t, "debug", line) + }) + + t.Run("get level with no args returns default level", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + res1 := node.IPFS("log", "level", "*", "fatal") + assert.NoError(t, res1.Err) + assert.Empty(t, res1.Stderr.Lines()) + + res := node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, 0, len(res.Stderr.Lines())) + + output := res.Stdout.String() + lines := SplitLines(output) + + assert.Equal(t, 1, len(lines)) + + line := strings.TrimSpace(lines[0]) + assert.Equal(t, "fatal", line) + }) + + t.Run("get level reflects runtime log level changes", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon("--offline") + defer node.StopDaemon() + + node.IPFS("log", "level", "core", "debug") + res := node.IPFS("log", "level", "core") + assert.NoError(t, res.Err) + + output := res.Stdout.String() + lines := SplitLines(output) + + assert.Equal(t, 1, len(lines)) + + line := strings.TrimSpace(lines[0]) + assert.Equal(t, "debug", line) + }) + + t.Run("get level with non-existent subsystem returns error", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + res := node.RunIPFS("log", "level", "non-existent-subsystem") + assert.Error(t, res.Err) + assert.NotEqual(t, 0, len(res.Stderr.Lines())) + }) + + t.Run("set level to 'default' keyword", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // First set a specific subsystem to a different level + res1 := node.IPFS("log", "level", "core", "debug") + assert.NoError(t, res1.Err) + assert.Contains(t, res1.Stdout.String(), "Changed log level of 'core' to 'debug'") + + // Verify it was set to debug + res2 := node.IPFS("log", "level", "core") + assert.NoError(t, res2.Err) + assert.Equal(t, "debug", strings.TrimSpace(res2.Stdout.String())) + + // Get the current default level (should be 'error' since unchanged) + res3 := node.IPFS("log", "level") + assert.NoError(t, res3.Err) + defaultLevel := strings.TrimSpace(res3.Stdout.String()) + assert.Equal(t, "error", defaultLevel, "Default level should be 'error' when unchanged") + + // Now set the subsystem back to default + res4 := node.IPFS("log", "level", "core", "default") + assert.NoError(t, res4.Err) + assert.Contains(t, res4.Stdout.String(), "Changed log level of 'core' to") + + // Verify it's now at the default level (should be 'error') + res5 := node.IPFS("log", "level", "core") + assert.NoError(t, res5.Err) + assert.Equal(t, "error", strings.TrimSpace(res5.Stdout.String())) + }) + + t.Run("set all subsystems with 'all' changes default (alias for '*')", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Initial state - default should be 'error' + res := node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, "error", strings.TrimSpace(res.Stdout.String())) + + // Set one subsystem to a different level + res = node.IPFS("log", "level", "core", "debug") + assert.NoError(t, res.Err) + + // Default should still be 'error' + res = node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, "error", strings.TrimSpace(res.Stdout.String())) + + // Now use 'all' to set everything to 'info' + res = node.IPFS("log", "level", "all", "info") + assert.NoError(t, res.Err) + assert.Contains(t, res.Stdout.String(), "Changed log level of '*' to 'info'") + + // Default should now be 'info' + res = node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, "info", strings.TrimSpace(res.Stdout.String())) + + // Core should also be 'info' (overwritten by 'all') + res = node.IPFS("log", "level", "core") + assert.NoError(t, res.Err) + assert.Equal(t, "info", strings.TrimSpace(res.Stdout.String())) + + // Any other subsystem should also be 'info' + res = node.IPFS("log", "level", "dht") + assert.NoError(t, res.Err) + assert.Equal(t, "info", strings.TrimSpace(res.Stdout.String())) + }) + + t.Run("set all subsystems with '*' changes default", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Initial state - default should be 'error' + res := node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, "error", strings.TrimSpace(res.Stdout.String())) + + // Set one subsystem to a different level + res = node.IPFS("log", "level", "core", "debug") + assert.NoError(t, res.Err) + + // Default should still be 'error' + res = node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, "error", strings.TrimSpace(res.Stdout.String())) + + // Now use '*' to set everything to 'info' + res = node.IPFS("log", "level", "*", "info") + assert.NoError(t, res.Err) + assert.Contains(t, res.Stdout.String(), "Changed log level of '*' to 'info'") + + // Default should now be 'info' + res = node.IPFS("log", "level") + assert.NoError(t, res.Err) + assert.Equal(t, "info", strings.TrimSpace(res.Stdout.String())) + + // Core should also be 'info' (overwritten by '*') + res = node.IPFS("log", "level", "core") + assert.NoError(t, res.Err) + assert.Equal(t, "info", strings.TrimSpace(res.Stdout.String())) + + // Any other subsystem should also be 'info' + res = node.IPFS("log", "level", "dht") + assert.NoError(t, res.Err) + assert.Equal(t, "info", strings.TrimSpace(res.Stdout.String())) + }) + + t.Run("'all' in get mode shows (default) entry (alias for '*')", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Get all levels with 'all' + res := node.IPFS("log", "level", "all") + assert.NoError(t, res.Err) + + output := res.Stdout.String() + + // Should contain "(default): error" entry + assert.Contains(t, output, "(default): error", "Should show default level with (default) key") + + // Should also contain various subsystems + assert.Contains(t, output, "core: error") + assert.Contains(t, output, "dht: error") + }) + + t.Run("'*' in get mode shows (default) entry", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Get all levels with '*' + res := node.IPFS("log", "level", "*") + assert.NoError(t, res.Err) + + output := res.Stdout.String() + + // Should contain "(default): error" entry + assert.Contains(t, output, "(default): error", "Should show default level with (default) key") + + // Should also contain various subsystems + assert.Contains(t, output, "core: error") + assert.Contains(t, output, "dht: error") + }) + + t.Run("set all subsystems to 'default' using 'all' (alias for '*')", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Get the original default level (just for reference, it should be "error") + res0 := node.IPFS("log", "level") + assert.NoError(t, res0.Err) + assert.Equal(t, "error", strings.TrimSpace(res0.Stdout.String())) + + // First set all subsystems to debug using 'all' + res1 := node.IPFS("log", "level", "all", "debug") + assert.NoError(t, res1.Err) + assert.Contains(t, res1.Stdout.String(), "Changed log level of '*' to 'debug'") + + // Verify a specific subsystem is at debug + res2 := node.IPFS("log", "level", "core") + assert.NoError(t, res2.Err) + assert.Equal(t, "debug", strings.TrimSpace(res2.Stdout.String())) + + // Verify the default level is now debug + res3 := node.IPFS("log", "level") + assert.NoError(t, res3.Err) + assert.Equal(t, "debug", strings.TrimSpace(res3.Stdout.String())) + + // Now set all subsystems back to default (which is now "debug") using 'all' + res4 := node.IPFS("log", "level", "all", "default") + assert.NoError(t, res4.Err) + assert.Contains(t, res4.Stdout.String(), "Changed log level of '*' to") + + // The subsystem should still be at debug (because that's what default is now) + res5 := node.IPFS("log", "level", "core") + assert.NoError(t, res5.Err) + assert.Equal(t, "debug", strings.TrimSpace(res5.Stdout.String())) + + // The behavior is correct: "default" uses the current default level, + // which was changed to "debug" when we set "all" to "debug" + }) + + t.Run("set all subsystems to 'default' keyword", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Get the original default level (just for reference, it should be "error") + res0 := node.IPFS("log", "level") + assert.NoError(t, res0.Err) + // originalDefault := strings.TrimSpace(res0.Stdout.String()) + assert.Equal(t, "error", strings.TrimSpace(res0.Stdout.String())) + + // First set all subsystems to debug + res1 := node.IPFS("log", "level", "*", "debug") + assert.NoError(t, res1.Err) + assert.Contains(t, res1.Stdout.String(), "Changed log level of '*' to 'debug'") + + // Verify a specific subsystem is at debug + res2 := node.IPFS("log", "level", "core") + assert.NoError(t, res2.Err) + assert.Equal(t, "debug", strings.TrimSpace(res2.Stdout.String())) + + // Verify the default level is now debug + res3 := node.IPFS("log", "level") + assert.NoError(t, res3.Err) + assert.Equal(t, "debug", strings.TrimSpace(res3.Stdout.String())) + + // Now set all subsystems back to default (which is now "debug") + res4 := node.IPFS("log", "level", "*", "default") + assert.NoError(t, res4.Err) + assert.Contains(t, res4.Stdout.String(), "Changed log level of '*' to") + + // The subsystem should still be at debug (because that's what default is now) + res5 := node.IPFS("log", "level", "core") + assert.NoError(t, res5.Err) + assert.Equal(t, "debug", strings.TrimSpace(res5.Stdout.String())) + + // The behavior is correct: "default" uses the current default level, + // which was changed to "debug" when we set "*" to "debug" + }) + + t.Run("shell escaping variants for '*' wildcard", func(t *testing.T) { + t.Parallel() + h := harness.NewT(t) + node := h.NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Test different shell escaping methods work for '*' + // This tests the behavior documented in help text: '*' or "*" or \* + + // Test 1: Single quotes '*' (should work) + cmd1 := fmt.Sprintf("IPFS_PATH='%s' %s --api='%s' log level '*' info", + node.Dir, node.IPFSBin, node.APIAddr()) + res1 := h.Sh(cmd1) + assert.NoError(t, res1.Err) + assert.Contains(t, res1.Stdout.String(), "Changed log level of '*' to 'info'") + + // Test 2: Double quotes "*" (should work) + cmd2 := fmt.Sprintf("IPFS_PATH='%s' %s --api='%s' log level \"*\" debug", + node.Dir, node.IPFSBin, node.APIAddr()) + res2 := h.Sh(cmd2) + assert.NoError(t, res2.Err) + assert.Contains(t, res2.Stdout.String(), "Changed log level of '*' to 'debug'") + + // Test 3: Backslash escape \* (should work) + cmd3 := fmt.Sprintf("IPFS_PATH='%s' %s --api='%s' log level \\* warn", + node.Dir, node.IPFSBin, node.APIAddr()) + res3 := h.Sh(cmd3) + assert.NoError(t, res3.Err) + assert.Contains(t, res3.Stdout.String(), "Changed log level of '*' to 'warn'") + + // Test 4: Verify the final state - should show 'warn' as default + res4 := node.IPFS("log", "level") + assert.NoError(t, res4.Err) + assert.Equal(t, "warn", strings.TrimSpace(res4.Stdout.String())) + + // Test 5: Get all levels using escaped '*' to verify it shows all subsystems + cmd5 := fmt.Sprintf("IPFS_PATH='%s' %s --api='%s' log level \\*", + node.Dir, node.IPFSBin, node.APIAddr()) + res5 := h.Sh(cmd5) + assert.NoError(t, res5.Err) + output := res5.Stdout.String() + assert.Contains(t, output, "(default): warn", "Should show updated default level") + assert.Contains(t, output, "core: warn", "Should show core subsystem at warn level") + }) + }) + + t.Run("HTTP RPC", func(t *testing.T) { + t.Run("get default level returns JSON", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Make HTTP request to get default log level + resp, err := http.Post(node.APIURL()+"/api/v0/log/level", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + // Parse JSON response + var result map[string]interface{} + err = json.NewDecoder(resp.Body).Decode(&result) + require.NoError(t, err) + + // Check that we have the Levels field + levels, ok := result["Levels"].(map[string]interface{}) + require.True(t, ok, "Response should have 'Levels' field") + + // Should have exactly one entry for the default level + assert.Equal(t, 1, len(levels)) + + // The default level should be present + defaultLevel, ok := levels[""] + require.True(t, ok, "Should have empty string key for default level") + assert.Equal(t, "error", defaultLevel, "Default level should be 'error'") + }) + + t.Run("get all levels using 'all' returns JSON (alias for '*')", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + expectedSubsystems := getExpectedSubsystems(t, node) + + // Make HTTP request to get all log levels using 'all' + resp, err := http.Post(node.APIURL()+"/api/v0/log/level?arg=all", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + levels := parseHTTPResponse(t, resp) + validateAllSubsystemsPresent(t, expectedSubsystems, levels, "JSON response") + + // Should have the (default) entry + defaultLevel, ok := levels["(default)"] + require.True(t, ok, "Should have '(default)' key") + assert.Equal(t, "error", defaultLevel, "Default level should be 'error'") + }) + + t.Run("get all levels returns JSON", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + expectedSubsystems := getExpectedSubsystems(t, node) + + // Make HTTP request to get all log levels + resp, err := http.Post(node.APIURL()+"/api/v0/log/level?arg=*", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + levels := parseHTTPResponse(t, resp) + validateAllSubsystemsPresent(t, expectedSubsystems, levels, "JSON response") + + // Should have the (default) entry + defaultLevel, ok := levels["(default)"] + require.True(t, ok, "Should have '(default)' key") + assert.Equal(t, "error", defaultLevel, "Default level should be 'error'") + }) + + t.Run("get specific subsystem level returns JSON", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // First set a specific level for a subsystem + resp, err := http.Post(node.APIURL()+"/api/v0/log/level?arg=core&arg=debug", "", nil) + require.NoError(t, err) + resp.Body.Close() + + // Now get the level for that subsystem + resp, err = http.Post(node.APIURL()+"/api/v0/log/level?arg=core", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + // Parse JSON response + var result map[string]interface{} + err = json.NewDecoder(resp.Body).Decode(&result) + require.NoError(t, err) + + // Check that we have the Levels field + levels, ok := result["Levels"].(map[string]interface{}) + require.True(t, ok, "Response should have 'Levels' field") + + // Should have exactly one entry + assert.Equal(t, 1, len(levels)) + + // Check the level for 'core' subsystem + coreLevel, ok := levels["core"] + require.True(t, ok, "Should have 'core' key") + assert.Equal(t, "debug", coreLevel, "Core level should be 'debug'") + }) + + t.Run("set level using 'all' returns JSON message (alias for '*')", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Set a log level using 'all' + resp, err := http.Post(node.APIURL()+"/api/v0/log/level?arg=all&arg=info", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + // Parse JSON response + var result map[string]interface{} + err = json.NewDecoder(resp.Body).Decode(&result) + require.NoError(t, err) + + // Check that we have the Message field + message, ok := result["Message"].(string) + require.True(t, ok, "Response should have 'Message' field") + + // Check the message content (should show '*' in message even when 'all' was used) + assert.Contains(t, message, "Changed log level of '*' to 'info'") + }) + + t.Run("set level returns JSON message", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // Set a log level + resp, err := http.Post(node.APIURL()+"/api/v0/log/level?arg=core&arg=info", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + // Parse JSON response + var result map[string]interface{} + err = json.NewDecoder(resp.Body).Decode(&result) + require.NoError(t, err) + + // Check that we have the Message field + message, ok := result["Message"].(string) + require.True(t, ok, "Response should have 'Message' field") + + // Check the message content + assert.Contains(t, message, "Changed log level of 'core' to 'info'") + }) + + t.Run("set level to 'default' keyword", func(t *testing.T) { + t.Parallel() + node := harness.NewT(t).NewNode().Init().StartDaemon() + defer node.StopDaemon() + + // First set a subsystem to debug + resp, err := http.Post(node.APIURL()+"/api/v0/log/level?arg=core&arg=debug", "", nil) + require.NoError(t, err) + resp.Body.Close() + + // Now set it back to default + resp, err = http.Post(node.APIURL()+"/api/v0/log/level?arg=core&arg=default", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + // Parse JSON response + var result map[string]interface{} + err = json.NewDecoder(resp.Body).Decode(&result) + require.NoError(t, err) + + // Check that we have the Message field + message, ok := result["Message"].(string) + require.True(t, ok, "Response should have 'Message' field") + + // The message should indicate the change + assert.True(t, strings.Contains(message, "Changed log level of 'core' to"), + "Message should indicate level change") + + // Verify the level is back to error (default) + resp, err = http.Post(node.APIURL()+"/api/v0/log/level?arg=core", "", nil) + require.NoError(t, err) + defer resp.Body.Close() + + var getResult map[string]interface{} + err = json.NewDecoder(resp.Body).Decode(&getResult) + require.NoError(t, err) + + levels, _ := getResult["Levels"].(map[string]interface{}) + coreLevel, _ := levels["core"].(string) + assert.Equal(t, "error", coreLevel, "Core level should be back to 'error' (default)") + }) + }) + +} + +func getExpectedSubsystems(t *testing.T, node *harness.Node) []string { + t.Helper() + lsRes := node.IPFS("log", "ls") + require.NoError(t, lsRes.Err) + expectedSubsystems := SplitLines(lsRes.Stdout.String()) + assert.Greater(t, len(expectedSubsystems), 10, "Should have many subsystems") + return expectedSubsystems +} + +func parseCLIOutput(t *testing.T, output string) map[string]string { + t.Helper() + lines := SplitLines(output) + actualSubsystems := make(map[string]string) + for _, line := range lines { + if strings.TrimSpace(line) == "" { + continue + } + parts := strings.Split(line, ": ") + assert.Equal(t, 2, len(parts), "Line should have format 'subsystem: level', got: %s", line) + assert.NotEmpty(t, parts[0], "Subsystem should not be empty") + assert.NotEmpty(t, parts[1], "Level should not be empty") + actualSubsystems[parts[0]] = parts[1] + } + return actualSubsystems +} + +func parseHTTPResponse(t *testing.T, resp *http.Response) map[string]interface{} { + t.Helper() + var result map[string]interface{} + err := json.NewDecoder(resp.Body).Decode(&result) + require.NoError(t, err) + levels, ok := result["Levels"].(map[string]interface{}) + require.True(t, ok, "Response should have 'Levels' field") + assert.Greater(t, len(levels), 10, "Should have many subsystems") + return levels +} + +func validateAllSubsystemsPresent(t *testing.T, expectedSubsystems []string, actualLevels map[string]interface{}, context string) { + t.Helper() + for _, expectedSub := range expectedSubsystems { + expectedSub = strings.TrimSpace(expectedSub) + if expectedSub == "" { + continue + } + _, found := actualLevels[expectedSub] + assert.True(t, found, "Expected subsystem '%s' should be present in %s", expectedSub, context) + } +} + +func validateAllSubsystemsPresentCLI(t *testing.T, expectedSubsystems []string, actualLevels map[string]string, context string) { + t.Helper() + for _, expectedSub := range expectedSubsystems { + expectedSub = strings.TrimSpace(expectedSub) + if expectedSub == "" { + continue + } + _, found := actualLevels[expectedSub] + assert.True(t, found, "Expected subsystem '%s' should be present in %s", expectedSub, context) + } +} diff --git a/test/dependencies/go.mod b/test/dependencies/go.mod index 4cdae1c8a..16fade132 100644 --- a/test/dependencies/go.mod +++ b/test/dependencies/go.mod @@ -8,7 +8,7 @@ require ( github.com/Kubuxu/gocovmerge v0.0.0-20161216165753-7ecaa51963cd github.com/golangci/golangci-lint v1.60.2 github.com/ipfs/go-cidutil v0.1.0 - github.com/ipfs/go-log/v2 v2.6.0 + github.com/ipfs/go-log/v2 v2.8.0 github.com/ipfs/go-test v0.2.2 github.com/ipfs/hang-fds v0.1.0 github.com/ipfs/iptb v1.4.1 diff --git a/test/dependencies/go.sum b/test/dependencies/go.sum index 5e5428ac8..30c4d1fd5 100644 --- a/test/dependencies/go.sum +++ b/test/dependencies/go.sum @@ -343,8 +343,8 @@ github.com/ipfs/go-ipld-format v0.6.2 h1:bPZQ+A05ol0b3lsJSl0bLvwbuQ+HQbSsdGTy4xt github.com/ipfs/go-ipld-format v0.6.2/go.mod h1:nni2xFdHKx5lxvXJ6brt/pndtGxKAE+FPR1rg4jTkyk= github.com/ipfs/go-ipld-legacy v0.2.2 h1:DThbqCPVLpWBcGtU23KDLiY2YRZZnTkXQyfz8aOfBkQ= github.com/ipfs/go-ipld-legacy v0.2.2/go.mod h1:hhkj+b3kG9b2BcUNw8IFYAsfeNo8E3U7eYlWeAOPyDU= -github.com/ipfs/go-log/v2 v2.6.0 h1:2Nu1KKQQ2ayonKp4MPo6pXCjqw1ULc9iohRqWV5EYqg= -github.com/ipfs/go-log/v2 v2.6.0/go.mod h1:p+Efr3qaY5YXpx9TX7MoLCSEZX5boSWj9wh86P5HJa8= +github.com/ipfs/go-log/v2 v2.8.0 h1:SptNTPJQV3s5EF4FdrTu/yVdOKfGbDgn1EBZx4til2o= +github.com/ipfs/go-log/v2 v2.8.0/go.mod h1:2LEEhdv8BGubPeSFTyzbqhCqrwqxCbuTNTLWqgNAipo= github.com/ipfs/go-metrics-interface v0.3.0 h1:YwG7/Cy4R94mYDUuwsBfeziJCVm9pBMJ6q/JR9V40TU= github.com/ipfs/go-metrics-interface v0.3.0/go.mod h1:OxxQjZDGocXVdyTPocns6cOLwHieqej/jos7H4POwoY= github.com/ipfs/go-peertaskqueue v0.8.2 h1:PaHFRaVFdxQk1Qo3OKiHPYjmmusQy7gKQUaL8JDszAU=