🐛 --output json writes invalid JSON lines when events are logged concurrently
维护者通常 1 天内回复
评估
- 难度
- 2/5
- 预计耗时
- 1-3 小时
- 新手友好度
- 78/100
- Issue 类型
- 缺陷
- 描述清晰度
- 描述清楚
- 活跃度
- 活跃
- 技术栈
- go
调研方向
问题出在 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
- Run
cloudflared tunnel --no-autoupdate --loglevel info --output json run(remotely managed tunnel, token auth). - Generate bursts of concurrent errors, e.g. many proxied requests cancelled by clients at the same time (
Incoming request ended abruptly: context canceled). - 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/cloudflaredcontainer 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 模板
- 阅读贡献指南
从这里开始
- 先读完整个 Issue,再读项目的贡献指南。
- 在 Issue 下留言说明你要接手 —— 这能避免两个人做同样的事。
- Fork 仓库,在一个分支上完成修改。
- 提交 Pull Request,并在描述里引用这个 Issue 编号。
cloudflare/cloudflared 的其他 Issue
-
Priority: Normal Type: Bug
难度 2/5 1-3 小时 新手友好度 85/100
cloudflare/cloudflared#1777 ·
维护者通常 1 天内回复
-
🐛 cfRay is missing from proxied request logs (newHTTPLogger discards the zerolog context)可能已有人在做 @pankajc46 于 17 天前认领。 未关闭
难度 2/5 1-3 小时 新手友好度 82/100
cloudflare/cloudflared#1756 · 1 条评论 ·
维护者通常 1 天内回复
-
🐛 After SIGTERM, `cloudflared tunnel run` uses 100% of one CPU core for the whole graceful-shutdown period可能已有人在做 @cyphercodes 于 17 天前认领。 未关闭Priority: Normal Type: Bug
难度 1/5 1 小时以内 新手友好度 88/100
cloudflare/cloudflared#1753 · 3 条评论 ·
维护者通常 1 天内回复
-
tunnel route ip show: --filter-network-is-subset-of sends the superset filter可能已有人在做 @wangyusheng1985 于 17 天前认领。 未关闭
难度 2/5 1-3 小时 新手友好度 92/100
cloudflare/cloudflared#1750 ·
维护者通常 1 天内回复
-
🐛 QUIC Hijack() skips the status-written check that HTTP/2 enforces可能已有人在做 @dedsec-terminal 于 11 天前认领。 未关闭
难度 2/5 1-3 小时 新手友好度 78/100
cloudflare/cloudflared#1748 · 1 条评论 ·
维护者通常 1 天内回复
查看 cloudflare/cloudflared 的全部 Issue
相似的 Issue
-
难度 2/5 1-3 小时 新手友好度 75/100
github/github-mcp-server#3581 ·
维护者通常 2 天内回复
-
agent-review-finding chore
难度 1/5 1 小时以内 新手友好度 85/100
jordansmall/spindrift#6033 ·
维护者通常 1 天内回复
-
enhancement
难度 2/5 1-3 小时 新手友好度 75/100
hyperledger/fabric-x-common#230 ·
维护者通常 1 天内回复
-
bug
难度 2/5 半天 新手友好度 65/100
open-wanderer/wanderer#1443 · 3 条评论 ·
维护者通常 1 天内回复
-
难度 2/5 1-3 小时 新手友好度 75/100
维护者通常 1 天内回复