Proposal: advanced logging using slog

[timrulebosch]

Description

We would like to enhance Task logger to provide more debugging support when developing Taskfiles. In particular gaining additional information on Task processing logic (generates, for, sources ...) and variable values (where/how they are arrived at). The reason for this is that we would like to be able to fix issues with a Taskfile, or its usage, based on the collected log and hopefully without any additional debugging efforts.

The suggestion would be along these lines:

• Add the Go log/slog package to the logging subsystem.
• Refactor the existing logging to overlay onto the log/slog system. No change in behaviour.
• Extend/add to the CLI flags with additional log filtering capabilities.

Log levels of log/slog might map into the existing Task logging, such as:

• 0 = silent (only console and errors)
• 1 = normal
• 2 = verbose
• 3 = debug log ( info about processing logic, variable values etc.)
• 4 = trace (very low level logging, code path tracing)

The CLI support could extended any number of ways. This would be sufficient for our case:

task // uses level 1
task --silent // uses level 0
task --verbose // uses level 2
task --verbose 3 // uses level 3 for all tasks
task --verbose 3:taskfoo // uses level 3/debug for task "taskfoo", 2/verbose for other tasks
task --verbose 0:*,4:taskfoo // uses level 4/tarce for task "taskfoo" and 0/silent for other tasks.

Of course that hijacks the --verbose flag ... one could also add a new flag (--log for instance).

[timrulebosch]

@pd93 @andreynering Hello, do you have any plans in this direction - frameworks, preferences? Or happy for a PR.

[andreynering]

Hi @timrulebosch,

In the way you visualize this change, do you think the logs will be shown to the users in a different format by default?

Not sure if you intent to change then in the terminal output or add a log file to be structured...

[timrulebosch]

Hi, I think the existing output/behaviour is unchanged, and the new logging would be in a similar format but most likely timestamped. It is possible to have other formats, but in the case of Task its probably better if the logs are not so different. It could be, for instance, when logging is set to "debug" or "trace", that all logs get a timestamp prefix - because that would be useful.

Probably sent to STDERR. But writing to a file is also possible.

I don't have any particular objective beyond getting some debug/trace logging for smoothing operations (when it comes to Task). However its possible to do more with log/slog (log streaming, aggregation etc).

[pd93]

I certainly don't have an objection to adding more debug logs to Task. This is something we should definitely put more time into.

It would be helpful if you could provide examples of the specific things you think are missing/should be added. i.e. What are you not able to discern from the current logging? My assumption here is that your main concern is running Task in --watch mode as this is the only time a timestamp would really be useful. I think this is something that can be addressed separately to slog. They are different requests.

As for slog. I don't have a fundamental objection - I use it in other projects. However, our current logger is quite deeply integrated into how Task works, unfurling it in a non-breaking way could be quite a bit of work. We'd have to ensure that when running in "normal" mode (not debug), everything works as it does now.

I've recently been trying to be careful that we are not passing the logger into the package API. We shouldn't dictate how users of the package API handle their logs. Instead, we now provide closure functions in some places (like in the taskfile.Reader). However, slog provides slog.Handler which could be a fantastic alternative way of dealing with this within the std lib.

Its context loggers are also a very convenient way of logging request-scoped values (e.g. a Task's name), without having to pass it around.

[timrulebosch]

I may start with adding log/slog to internal/logger, providing a feature set for debug/trace logging with grouping/scoping. From there it should be apparent how the existing logging could be overlayed. And also if the mechanism is useful.

@pd93 For the package API, it might/should be possible to install a handler so that consumers of that API can have logging how they want it, or no logging at all.

As for the use-case; we (in particular) need lower level information (e.g. values of env, vars) and would like to get that without needing to add "echo" to Taskfiles, or printf's in the code. I don't think that is possible at the moment, or I did not notice it.