Hacktoberfest 2026: những issue maintainer đã đánh dấu cho tháng Mười, đang mở và phù hợp người mới. Xem issue Hacktoberfest

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

Đang mở Phù hợp với người mới
  • Có gì không ổn?
#1,761 5 bình luận 0 reaction 0 người được giao Xem trên GitHub

Maintainer thường phản hồi trong vòng 1 ngày

@theolujay đang làm issue này rồi.

Từ ngày 10/10/2026.

  • #1763 của @theolujay — đang mở

Đánh giá

Độ khó
2/5
Thời gian dự kiến
1-3 giờ
Mức phù hợp với người mới
78/100
Loại issue
Lỗi
Độ rõ ràng
Đặc tả rõ ràng
Mức độ hoạt động
Sôi nổi
Công nghệ
go
Lĩnh vực
observability

Hướng nghiên cứu

Lỗi nằm ở consoleWriter.Write trong logger/console.go, hàm này mã hóa từng sự kiện trực tiếp vào c.out nên phát sinh một lần ghi cho mỗi trường JSON. Hãy đọc hàm đó, sau đó tái hiện lỗi bằng đoạn repro độc lập trong issue hoặc bằng bài kiểm thử writer đếm số lần ghi tên là TestConsoleLoggerSingleWritePerEvent. Hoàn thành khi bộ mã hóa ghi vào một bytes.Buffer, bộ đệm đó được ghi đúng một lần và go test ./logger/ vượt qua.

Do mô hình lập chỉ mục viết ra từ nội dung của issue.

Mô tả

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.

Ngôn ngữ chính
Go
Star
16.2k
Fork
1.5k
Không có pull request nào được merge trong 30 ngày

Chuẩn bị môi trường

Bắt đầu từ đâu

  1. Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
  2. Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
  3. Fork repository và làm thay đổi trên một nhánh.
  4. Mở pull request có tham chiếu số hiệu của issue.

Issue khác của cloudflare/cloudflared

Tất cả issue của cloudflare/cloudflared

Issue tương tự

Thêm issue về Go

Nhận issue mới trong hộp thư của bạn

Bản tóm tắt ngắn những issue GitHub phù hợp với người mới.