Skip to content

proposal: log/slog: option to print msg key last #69620

@ekkagra

Description

@ekkagra

Proposal Details

Consider the output of slog Text or JSON handler log outputs for below code

	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
	logger.Info("hello", "count", 3)

	logger2 := logger.With("app", "alpha")
	logger3 := logger.With("app", "beta ")
	loggerGrp := logger3.WithGroup("grp1")

	logger2.Info("short msg", "id", 1)
	logger3.Info("long long long long abc def abc msg", "count", 100)
	loggerGrp.Info("asd asd asd asd asd", "code", "ok")
	loggerGrp.Warn("not found", "id", 1000)
	logger2.Info("short msg", "id", 1)
	logger3.Info("long long long long abc def abc msg", "count", 100)
	loggerGrp.Info("asd asd asd asd asd", "code", "ok")
	loggerGrp.Warn("not found", "id", 1000)

Output - JSONHandler

{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"hello","count":3}
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"short msg","app":"alpha","id":1}
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"long long long long abc def abc msg","app":"beta ","count":100}
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"asd asd asd asd asd","app":"beta ","grp1":{"code":"ok"}}
{"time":"2009-11-10T23:00:00Z","level":"WARN","msg":"not found","app":"beta ","grp1":{"id":1000}}
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"short msg","app":"alpha","id":1}
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"long long long long abc def abc msg","app":"beta ","count":100}
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"asd asd asd asd asd","app":"beta ","grp1":{"code":"ok"}}
{"time":"2009-11-10T23:00:00Z","level":"WARN","msg":"not found","app":"beta ","grp1":{"id":1000}}

Although, this is easily machine parsable, but this doesn't look very human readable from one aspect.
When reading logs, the Attr added using With or WithGroup are added in end. This makes it difficult to navigate and find next line of interest.
The value for msg key is variable in length. As humans normally read from left to right, it takes effort to find the next common key attribute. E.g. in above case, the common key attribute is app which could be either alpha or beta.

If msg is added last, all Attr added via With and WithGroup will be better visually aligned. It will be easy to jump to next log for say "app": "alpha".

{"time":"2009-11-10T23:00:00Z","level":"INFO","count":3,"msg":"hello"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","count":3,"msg":"hello"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","app":"alpha","id":1,"msg":"short msg"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","app":"beta ","count":100,"msg":"long long long long abc def abc msg"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","app":"beta ","grp1":{"code":"ok"},"msg":"asd asd asd asd asd"}
{"time":"2009-11-10T23:00:00Z","level":"WARN","app":"beta ","grp1":{"id":1000},"msg":"not found"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","app":"alpha","id":1,"msg":"short msg"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","app":"beta ","count":100,"msg":"long long long long abc def abc msg"}
{"time":"2009-11-10T23:00:00Z","level":"INFO","app":"beta ","grp1":{"code":"ok"},"msg":"asd asd asd asd asd"}
{"time":"2009-11-10T23:00:00Z","level":"WARN","app":"beta ","grp1":{"id":1000},"msg":"not found"}

If some flag in HandlerOptions is added like AddMsgInLast, it will make reading logs easier for cases like

  1. loggers grouped into some heirarchy using With/WithGroup
  2. multiple go programs running in same container but having common key attributes like "app": "alpha", "app": "beta " for differentiation.

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions