Hacktoberfest 2026:维护者为十月标记出来的 issue,仍然开放、适合新手。 浏览 Hacktoberfest issue

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

未关闭 适合新手
#1,761 5 条评论 0 个 reaction 已指派 0 人 在 GitHub 查看

维护者通常 1 天内回复

@theolujay 已经在做这个了。

开始于 2026年10月10日。

  • #1763 来自 @theolujay —— 未关闭

评估

难度
2/5
预计耗时
1-3 小时
新手友好度
78/100
Issue 类型
缺陷
描述清晰度
描述清楚
活跃度
活跃
技术栈
go
领域
observability

调研方向

问题出在 logger/console.go 中的 consoleWriter.Write,它将每个事件直接编码到 c.out,因此会为每个 JSON 字段执行一次写入。请先阅读该函数,然后使用 issue 中的独立复现代码,或使用名为 TestConsoleLoggerSingleWritePerEvent 的计数写入器测试进行复现。完成的标准是:编码器写入 bytes.Buffer,该缓冲区只写入一次,并且 go test ./logger/ 通过。

由索引模型根据 Issue 内容生成。

描述

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.

主要语言
Go
星标
16.2k
派生
1.5k
PR 合并指标
30 天内没有已合并 PR

环境准备

  • 提供 Dockerfile 或 Docker Compose 文件
  • 没有 Pull Request 模板
  • 阅读贡献指南

从这里开始

  1. 先读完整个 Issue,再读项目的贡献指南。
  2. 在 Issue 下留言说明你要接手 —— 这能避免两个人做同样的事。
  3. Fork 仓库,在一个分支上完成修改。
  4. 提交 Pull Request,并在描述里引用这个 Issue 编号。

cloudflare/cloudflared 的其他 Issue

查看 cloudflare/cloudflared 的全部 Issue

相似的 Issue

更多 Go Issue

把新 issue 发到你的邮箱

精选适合新手参与的 GitHub issue 摘要。