rs / zerolog

Zero Allocation JSON Logger
MIT License
10.39k stars 566 forks source link

prettylog only displays the first line of the output #628

Closed freak12techno closed 7 months ago

freak12techno commented 8 months ago

I have a service that uses zerolog and outputs logs in json. When I try to pipe its output to prettylog, it's only displaying its first line and then silently exits:

$ journalctl -u cosmovisor -f --output=cat -n 100 | prettylog
2:03AM INF Replay: Vote blockID={"hash":"","parts":{"hash":"","total":0}} height=18396932 module=consensus peer=72829b78b38408b03793ed389b9f16596b82c306 round=0 type=1
$

This makes it kinda useless for piping.

Adding a for { } or select { } after this line https://github.com/rs/zerolog/blob/master/cmd/prettylog/prettylog.go#L22 would likely fix that, as it seems like it creates a Writer and just exits. (I tested the for {} approach and it seems to work, but not sure if it's the optimal solution). This way it outputs data unless the process is killed by Ctrl+C:

$ journalctl -u cosmovisor -f --output=cat -n 100 | go run prettylog.go
2:04AM INF Ensure peers module=pex numDialing=1 numInPeers=0 numOutPeers=2 numToDial=7
2:04AM INF Timed out dur=4767.27112 height=18396945 module=consensus round=0 step=1
2:04AM INF finalizing commit of block hash={} height=18396945 module=consensus num_txs=4 root=65DB37F7DA3CC476BFDFBB34018E8B68CC9C15028509013C14038CE479100A4C
2:04AM INF Error reconnecting to peer. Trying again addr={"id":"538ebe0086f0f5e9ca922dae0462cc87e22f0a50","ip":"34.122.34.67","port":26656} err="dial tcp 34.122.34.67:26656: i/o timeout" module=p2p tries=10
2:04AM INF Error reconnecting to peer. Trying again addr={"id":"585794737e6b318957088e645e17c0669f3b11fc","ip":"54.160.123.34","port":26656} err="dial tcp 54.160.123.34:26656: i/o timeout" module=p2p tries=9
2:04AM INF Error reconnecting to peer. Trying again addr={"id":"5b4ed476e01c49b23851258d867cc0cfc0c10e58","ip":"206.189.4.227","port":26656} err="dial tcp 206.189.4.227:26656: i/o timeout" module=p2p tries=10
^Csignal: interrupt

$
freak12techno commented 8 months ago

UPD: I decided to investigate this further and apparently it's not case I've described above, it's something with the decoding. Changing the binary to adding the following debug info:

    if isInputFromPipe() {
        written, err := io.Copy(writer, os.Stdin)
        fmt.Printf("written %d\n", written)
        fmt.Printf("err %s\n", err)

produces the following result:

2:25AM INF packet received dst_channel=channel-141 dst_port=transfer module=x/ibc/channel sequence=2384493 src_channel=channel-0 src_port=transfer
written 8192
err cannot decode event: json: cannot unmarshal string into Go value of type map[string]interface {}

After further investigation I am pretty sure journalctl outputs data partially, not line by line and ConsoleWriter#Write receives a bunch of bytes that are not valid JSON. Not sure if there's something that can be done easy with that though.