Skip to content

🐛 --output json writes invalid JSON lines when events are logged concurrently #1761

Description

@Sirz3chs

Describe the bug
With --output json, cloudflared sometimes writes invalid JSON log lines: one event is cut in pieces and another event, logged at the same time from another goroutine, is written in the middle of it.

The cause is in logger/console.go. consoleWriter.Write re-encodes the event with jsoniter.ConfigCompatibleWithStandardLibrary.NewEncoder(c.out) directly into os.Stderr. That config sorts map keys, and sortKeysMapEncoder calls stream.Write for each key. In json-iterator v1.1.12, Stream.Write writes straight through to the underlying writer. So one log event becomes one write(2) per field, plus a final one for }\n, with no lock between them. Events logged concurrently interleave at field boundaries.

strace of a single event:

write(2, "{\"connIndex\":7", 14) = 14
write(2, ",\"dest\":\"https://example.com/api"..., 51) = 51
write(2, ",\"error\":\"Incoming request ended"..., 60) = 60
write(2, ",\"event\":0", 10)     = 10
write(2, ",\"level\":\"error\"", 16) = 16
write(2, ",\"message\":\"Request failed\"", 27) = 27
write(2, ",\"time\":\"2026-10-09T07:19:55Z\"", 35) = 35
write(2, ",\"type\":\"http\"", 14) = 14
write(2, "}\n", 2)               = 2

The text output (zerolog.ConsoleWriter) is not affected: it builds the whole line in a buffer and writes it once.

To Reproduce

  1. Run cloudflared tunnel --no-autoupdate --loglevel info --output json run (remotely managed tunnel, token auth).
  2. Generate bursts of concurrent errors, e.g. many proxied requests cancelled by clients at the same time (Incoming request ended abruptly: context canceled).
  3. Parse stderr line by line as JSON: some lines are invalid.

If it's an issue with Cloudflare Tunnel:
4. Tunnel ID: not relevant, the bug is in the logger and reproduces without a tunnel (see below)
5. cloudflared config: no config file, only the command-line flags above

Standalone repro: https://github.com/Sirz3chs/cloudflared-json-log-interleave (runnable with ./check.sh, results also visible in its CI). It uses a verbatim copy of consoleWriter, with json-iterator v1.1.12 and zerolog v1.20.0 as in go.mod:

package main

import (
	"bytes"
	"fmt"
	"io"
	"os"
	"sync"

	jsoniter "github.com/json-iterator/go"
	"github.com/rs/zerolog"
)

var json = jsoniter.ConfigCompatibleWithStandardLibrary

// Verbatim copy of logger/console.go consoleWriter.
type consoleWriter struct{ out io.Writer }

func (c *consoleWriter) Write(p []byte) (n int, err error) {
	var evt map[string]any
	d := json.NewDecoder(bytes.NewReader(p))
	d.UseNumber()
	if err = d.Decode(&evt); err != nil {
		return n, fmt.Errorf("cannot decode event: %s", err)
	}
	e := json.NewEncoder(c.out)
	return len(p), e.Encode(evt)
}

func main() {
	log := zerolog.New(&consoleWriter{out: os.Stderr}).With().Timestamp().Logger()
	var wg sync.WaitGroup
	for g := 0; g < 8; g++ {
		wg.Add(1)
		go func(g int) {
			defer wg.Done()
			for i := 0; i < 5000; i++ {
				log.Error().Int("connIndex", g).Int("event", 0).Str("dest", "https://example.com/api/x").
					Str("error", "Incoming request ended abruptly: context canceled").Str("type", "http").Msg("Request failed")
			}
		}(g)
	}
	wg.Wait()
}
$ ./repro 2>&1 >/dev/null | jq -R 'fromjson? // "BAD"' | grep -c '^"BAD"$'
10169        # out of 40000 lines

Expected behavior
Each log event is written as one complete JSON line, whatever the concurrency.

Proposed fix
Encode into a buffer and write once. With this change the repro gives 0 invalid lines and 1 write(2) per event instead of 9. go test ./logger/ passes.

--- a/logger/console.go
+++ b/logger/console.go
@@ -32,6 +36,10 @@ func (c *consoleWriter) Write(p []byte) (n int, err error) {
 		return n, fmt.Errorf("cannot decode event: %s", err)
 	}
-	e := json.NewEncoder(c.out)
-	return len(p), e.Encode(evt)
+	var buf bytes.Buffer
+	if err = json.NewEncoder(&buf).Encode(evt); err != nil {
+		return n, err
+	}
+	_, err = c.out.Write(buf.Bytes())
+	return len(p), err
 }

A regression test that asserts a single Write per event (it fails on current master with got 7):

type countingWriter struct {
	bytes.Buffer
	writes int
}

func (c *countingWriter) Write(p []byte) (int, error) {
	c.writes++
	return c.Buffer.Write(p)
}

func TestConsoleLoggerSingleWritePerEvent(t *testing.T) {
	w := &countingWriter{}
	logger := zerolog.New(&consoleWriter{out: w}).With().Timestamp().Logger()
	logger.Error().Int("connIndex", 3).Str("error", "context canceled").Str("type", "http").Msg("Request failed")

	if w.writes != 1 {
		t.Errorf("expected 1 write for the log event, got %d: %s", w.writes, w.String())
	}
}

Environment and versions

  • OS: Linux, official cloudflare/cloudflared container image on Kubernetes (EKS, containerd)
  • Architecture: not architecture specific (reproduced on amd64 with the repro above)
  • Version: 2026.10.0, and the code is unchanged on master since TUN-9371 (2025.6)

Logs and errors
Raw container log (CRI file read by kubectl logs --timestamps), URLs redacted. Line 1 is cut before its last }, an entire second event is written inside it, and the orphan } comes next:

2026-10-09T03:03:26.001181426Z {"connIndex":3,"error":"Incoming request ended abruptly: context canceled","event":1,"ingressRule":6,"level":"error","originService":"http://origin.internal","time":"2026-10-09T03:03:26Z"{"connIndex":3,"dest":"https://example.com/api/cart/…","error":"Incoming request ended abruptly: context canceled","event":0,"ip":"198.41.192.167","level":"error","message":"Request failed","time":"2026-10-09T03:03:26Z","type":"http"}
2026-10-09T03:03:26.001206366Z }

Another shape, where the remaining fields of the first event come out on their own line:

{"connIndex":2,"error":"context canceled","event":0,"ip":"198.41.192.77","level":"error"{"connIndex":3,…full event…}
,"message":"failed to run the datagram handler","time":"…"}

Additional context
In production we see 93 invalid lines in 72 h across 2 tunnels, always during bursts of concurrent errors. Log pipelines that parse JSON end up with unparseable fragments, and the original events can't be fully reconstructed.

Activity

  1. akasakariko commented on Oct 10, 2026

    @akasakariko

    I'd like to work on this

  2. theolujay commented on Oct 10, 2026

    @theolujay

    Adding a buffer does resolve this. I made a PR. I found the repro repo very useful. @Sirz3chs

    Just curious, as I'm new around here: is there a reason you didn't make a PR, considering the level of detail you provided? This was a learning experience for me anyway.

  3. akasakariko commented on Oct 10, 2026

    @akasakariko

    Stepping back — #1763 already covers this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions