Terminal control characters are not always escaped safely

[mafredri]

Not sure whether or not this is considered a feature or a bug, but in certain scenarios, terminal escape chars are interpreted as-is, and in other they're escaped into string form.

package main

import (
	"context"
	"os"

	"cdr.dev/slog"
	"cdr.dev/slog/sloggers/sloghuman"
)

func main() {
	ctx := context.Background()
	log := slog.Make(sloghuman.Sink(os.Stderr))
	log.Info(ctx, "test1\r\nw\reird\a")
	log.Info(ctx, "test2", slog.F("boop", "hello\r\nb\rell\a"))
	log.Info(ctx, "test3\r\nt\rest", slog.F("boop", "hello\r\nb\rell\a"))
	log.Info(ctx, "test4", slog.F("clipboard", "\033]52;c;surprise!\a"))
}

// Output:
2022-11-10 18:10:11.256 [INFO]	<main.go:18>	main	...
  "msg": test1
eird     w
2022-11-10 18:10:11.256 [INFO]	<main.go:19>	main	test2 ...
  "boop": hello
ell       b
2022-11-10 18:10:11.256 [INFO]	<main.go:20>	main	...	{"boop": "hello\r\nb\rell\u0007"}
  "msg": test3
est      t
2022-11-10 18:10:11.257 [INFO]	<main.go:21>	main	test4	{"clipboard": "\u001b]52;c;surprise!\u0007"}

Pretty printing \r\n seems intended and like a nice feature (since it's aligned), but stray \r and also \a are interpreted as-is. The latter (\a) will also ring the terminal bell which I would venture is never the expectation.

Out of these 4 cases, only the clipboard case behaved as I would expect.

[nhooyr]

This is working as intended. sloghuman prints the msg directly to the terminal without any encoding. The fields are JSON encoded.

This means you can put your own colors in the msg or you can add newlines and have multiline messages.

And if a field is multiline but the msg is not, then that field is printed directly to the terminal too. This is how stacktraces in from the xerrors package are printed.

I think it'd be ok if we add another rule here where if a given msg/field contains any undisplayable character, then it is printed via strconv.Quote instead.

[mafredri]

Thanks for clarifying @nhooyr. I can definitely understand the use-case for allowing colors in the terminal and I can totally relate to wanting to keep the logic of sloghuman simple.

If we focus on just the message part, I still see the following discrepancy in the behavior:

log.Info(ctx, "test1 \x1b[38;5;204mRed\x1b[0m")
log.Info(ctx, "test2 \x1b[38;5;204mRed\x1b[0m\r\n")
log.Info(ctx, "test3 \x1b[38;5;204mRed\x1b[0m\r\nhello")

Both test1 and test2 don't allow for the color to propagate and in test2 we also lost the newline (for better or worse). If the idea is to support colors, I think it should apply to test1 and test2 as well.

With regards to fields, there I can see a use-case for pretty printing the newlines, but I feel like all control characters should be encoded because a user could easily be logging data from any kind of source.

Let's take the following silly example:

log.Info(ctx, "important1")
log.Info(ctx, "important2", slog.F("malicious content", "erase\n\x1b[2K\x1b[1A\x1b[2K\x1b[1A\x1b[2K\x1b[1A"))
log.Info(ctx, "not important")

// Output:
❯ go run main.go 2>&1 | tail -f
2022-11-11 16:01:44.342 [INFO]	<main.go:36>	main	important1
2022-11-11 16:01:44.342 [INFO]	<main.go:38>	main	not important

The malicious content managed to hide itself from the logs when viewed by an unaware admin. Obviously the data is still in the log, but easily missed by common viewing strategies.

Likewise, we could use this trick to put a dangerous command in the users clipboard (this will even work over SSH as long as the terminal allows OSC 52):

// $(echo echo rm -rf / | base64)
log.Info(ctx, "hello", slog.F("clipboard", "innocent\n\x1b[1A\x1b]52;c;ZWNobyBybSAtcmYgLwo=\a"))
// clipboard now contains "echo rm -rf /\n"

I think it'd be normal for a user to expect that potentially "dangerous" inputs are encoded, especially when they're only occasionally interpreted as-is.

[nhooyr]

Good examples! I'm actually not sure why your test2 example there didn't print directly. It should have with the newline. Super weird, must be a bug for sure.