Skip to content

Commit 41b0d36

Browse files
committed
sink/clickhouse: detect silent-write-drop from CH summary
Live evidence from the deployed operator (pod adaptive-export-6cfb95b7-pbmxg, log line 2026-05-23T20:58:39Z): time="2026-05-23T20:58:39Z" level=info msg="sink: pixie write completed" body_bytes=2098817 rows_sent=1658 table=redis_events ch_summary="{ \"read_rows\":\"0\",\"read_bytes\":\"0\", \"written_rows\":\"0\",\"written_bytes\":\"0\", \"total_rows_to_read\":\"0\",\"result_rows\":\"0\", \"result_bytes\":\"0\",\"elapsed_ns\":\"23034181\" }" The operator sent 1658 rows (~2 MiB), ClickHouse returned 2xx, but its X-ClickHouse-Summary response header reports written_rows=0 — i.e. CH silently dropped every row. The current WritePixieRows treats the 2xx as durable success and logs "pixie write completed"; the analyst sees the gap days later. Fix: parse X-ClickHouse-Summary and return an error when written_rows < rows_sent. Header absence is tolerated (older CH versions / proxies strip it); only an EXPLICIT zero-of-non-zero (or partial-of-non-zero) is treated as data loss. The error message includes both rows_sent and the full summary so the next iteration can correlate the dropped batch with a request id. TDD: - TestWritePixieRows_DetectsSilentZeroWriteDrop — replays the live summary header verbatim; failed before the fix, green after. - TestWritePixieRows_DetectsPartialWriteDrop — same class, 100 of 200 written. - TestWritePixieRows_HappyPath — pins the contract: written_rows>=rows_sent → nil error. - TestWritePixieRows_NoSummaryHeaderIsTolerated — older CH won't send the header; no false positive. - TestWritePixieRows_EmptyBatchShortCircuits — len(rows)==0 path never hits HTTP. Doesn't address the root cause (why CH dropped those rows — likely a per-batch type-mismatch silently swallowed by JSONEachRow under input_format_skip_unknown_fields or a parse-error 2xx); that needs a separate investigation with the request id from the next caught event. The detection here at least stops us from reporting durable writes that never happened.
1 parent 62913e7 commit 41b0d36

2 files changed

Lines changed: 178 additions & 0 deletions

File tree

src/vizier/services/adaptive_export/internal/sink/clickhouse.go

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -211,9 +211,52 @@ func (s *ClickHouseHTTP) WritePixieRows(ctx context.Context, table string, rows
211211
"ch_summary": summary,
212212
"first_row_keys": strings.Join(firstRowKeys, ","),
213213
}).Info("sink: pixie write completed")
214+
// Detect the silent-drop class: CH returns 2xx but
215+
// X-ClickHouse-Summary.written_rows < len(rows). Observed live on
216+
// 2026-05-23T20:58Z (redis_events: rows_sent=1658, written_rows=0)
217+
// — the operator reported success and the analyst saw the gap days
218+
// later. Header absence is tolerated (older CH versions / proxies
219+
// strip it); only an EXPLICIT zero-of-non-zero counts.
220+
if writeMismatch := summaryWroteFewerThan(summary, len(rows)); writeMismatch != nil {
221+
return fmt.Errorf("sink: pixie write to %s reported %d rows_sent but CH summary written_rows=%d (silent drop): %s",
222+
table, len(rows), writeMismatch.writtenRows, summary)
223+
}
214224
return nil
215225
}
216226

227+
// summaryDelta carries the parsed write counters from CH's
228+
// X-ClickHouse-Summary response header.
229+
type summaryDelta struct {
230+
writtenRows int64
231+
}
232+
233+
// summaryWroteFewerThan returns non-nil when the X-ClickHouse-Summary
234+
// header is present, parseable, and reports written_rows < rowsSent.
235+
// Returns nil when the header is missing, unparseable, or the count
236+
// matches/exceeds rowsSent — those are not data-loss signals.
237+
func summaryWroteFewerThan(summary string, rowsSent int) *summaryDelta {
238+
if summary == "" {
239+
return nil
240+
}
241+
var parsed struct {
242+
WrittenRows json.Number `json:"written_rows"`
243+
}
244+
if err := json.Unmarshal([]byte(summary), &parsed); err != nil {
245+
return nil
246+
}
247+
if parsed.WrittenRows == "" {
248+
return nil
249+
}
250+
wrote, err := parsed.WrittenRows.Int64()
251+
if err != nil {
252+
return nil
253+
}
254+
if wrote >= int64(rowsSent) {
255+
return nil
256+
}
257+
return &summaryDelta{writtenRows: wrote}
258+
}
259+
217260
// normalisePixieValue coerces pxapi-emitted Go values into JSON-friendly
218261
// shapes ClickHouse parses cleanly. time.Time → "YYYY-MM-DD HH:MM:SS.NNN…"
219262
// (CH's DateTime64 input format); []byte → string; everything else → as-is.

src/vizier/services/adaptive_export/internal/sink/clickhouse_test.go

Lines changed: 135 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -451,3 +451,138 @@ func TestParseActiveRows_RoundTripFromBytes(t *testing.T) {
451451
t.Fatalf("round-trip mismatch: %+v", rows)
452452
}
453453
}
454+
455+
// pixieRow returns a minimal-but-valid map shaped like a pxapi row.
456+
func pixieRow() map[string]any {
457+
return map[string]any{
458+
"time_": time.Unix(0, 1700000000000000000).UTC(),
459+
"upid": "1234:5678:9",
460+
"namespace": "redis",
461+
"pod": "redis/redis-1",
462+
"req_cmd": "GET",
463+
"resp": "OK",
464+
"latency": int64(123456),
465+
"remote_addr": "10.0.0.1",
466+
"remote_port": int64(6379),
467+
"local_addr": "10.0.0.2",
468+
"local_port": int64(34567),
469+
"trace_role": int64(2),
470+
"encrypted": false,
471+
"px_info_": "",
472+
"req_args": "",
473+
}
474+
}
475+
476+
// TestWritePixieRows_HappyPath — happy path: CH returns 200 with a
477+
// non-zero `written_rows` in X-ClickHouse-Summary; WritePixieRows
478+
// returns nil. Pins the contract the regression test below inverts.
479+
func TestWritePixieRows_HappyPath(t *testing.T) {
480+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
481+
w.Header().Set("X-ClickHouse-Summary",
482+
`{"read_rows":"1","read_bytes":"100","written_rows":"1","written_bytes":"100",`+
483+
`"total_rows_to_read":"0","result_rows":"1","result_bytes":"100","elapsed_ns":"1000000"}`)
484+
w.WriteHeader(200)
485+
}))
486+
defer srv.Close()
487+
s, err := New(Config{Endpoint: srv.URL})
488+
if err != nil {
489+
t.Fatalf("New: %v", err)
490+
}
491+
if err := s.WritePixieRows(context.Background(), "redis_events", []map[string]any{pixieRow()}); err != nil {
492+
t.Fatalf("WritePixieRows: %v", err)
493+
}
494+
}
495+
496+
// TestWritePixieRows_DetectsSilentZeroWriteDrop — regression for the
497+
// silent-data-loss bug observed on the live operator:
498+
//
499+
// sink: pixie write completed
500+
// rows_sent=1658
501+
// body_bytes=2098817
502+
// ch_summary="{...,"written_rows":"0",...}"
503+
// table=redis_events
504+
//
505+
// CH returned 2xx but `X-ClickHouse-Summary.written_rows` was zero
506+
// for a 1658-row payload — i.e. CH silently dropped every row. The
507+
// operator must NOT report success in that case; otherwise the
508+
// caller treats the batch as durably persisted and we lose data.
509+
func TestWritePixieRows_DetectsSilentZeroWriteDrop(t *testing.T) {
510+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
511+
// Real CH summary header from the operator-pod log on
512+
// 2026-05-23T20:58:39Z, table=redis_events.
513+
w.Header().Set("X-ClickHouse-Summary",
514+
`{"read_rows":"0","read_bytes":"0","written_rows":"0","written_bytes":"0",`+
515+
`"total_rows_to_read":"0","result_rows":"0","result_bytes":"0","elapsed_ns":"23034181"}`)
516+
w.WriteHeader(200)
517+
}))
518+
defer srv.Close()
519+
s, err := New(Config{Endpoint: srv.URL})
520+
if err != nil {
521+
t.Fatalf("New: %v", err)
522+
}
523+
// Send a real (non-zero) batch — a zero-input batch short-circuits
524+
// before the HTTP call so the assertion would never fire.
525+
batch := make([]map[string]any, 1658)
526+
for i := range batch {
527+
batch[i] = pixieRow()
528+
}
529+
err = s.WritePixieRows(context.Background(), "redis_events", batch)
530+
if err == nil {
531+
t.Fatalf("expected error from silent-drop (rows_sent=%d, written_rows=0), got nil", len(batch))
532+
}
533+
if !strings.Contains(err.Error(), "0") || !strings.Contains(err.Error(), "1658") {
534+
t.Fatalf("error should mention both written_rows=0 and rows_sent=1658 for diagnosis; got: %v", err)
535+
}
536+
}
537+
538+
// TestWritePixieRows_DetectsPartialWriteDrop — CH wrote SOME rows
539+
// but not all. Same data-loss class as the zero-write case; reject.
540+
func TestWritePixieRows_DetectsPartialWriteDrop(t *testing.T) {
541+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
542+
w.Header().Set("X-ClickHouse-Summary",
543+
`{"read_rows":"100","read_bytes":"10000","written_rows":"100","written_bytes":"10000",`+
544+
`"total_rows_to_read":"0","result_rows":"100","result_bytes":"10000","elapsed_ns":"1000000"}`)
545+
w.WriteHeader(200)
546+
}))
547+
defer srv.Close()
548+
s, _ := New(Config{Endpoint: srv.URL})
549+
batch := make([]map[string]any, 200) // sent 200, CH says wrote 100
550+
for i := range batch {
551+
batch[i] = pixieRow()
552+
}
553+
err := s.WritePixieRows(context.Background(), "redis_events", batch)
554+
if err == nil {
555+
t.Fatalf("expected error on partial write (sent=200, written=100); got nil")
556+
}
557+
}
558+
559+
// TestWritePixieRows_NoSummaryHeaderIsTolerated — older CH versions
560+
// (or proxies) may strip the X-ClickHouse-Summary header. Absence is
561+
// NOT a failure signal — only an explicit zero-of-non-zero is.
562+
func TestWritePixieRows_NoSummaryHeaderIsTolerated(t *testing.T) {
563+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
564+
w.WriteHeader(200) // no summary header at all
565+
}))
566+
defer srv.Close()
567+
s, _ := New(Config{Endpoint: srv.URL})
568+
if err := s.WritePixieRows(context.Background(), "redis_events", []map[string]any{pixieRow()}); err != nil {
569+
t.Fatalf("missing summary header must not error; got: %v", err)
570+
}
571+
}
572+
573+
// TestWritePixieRows_EmptyBatchShortCircuits — zero-row input never
574+
// hits HTTP and never produces a "silent drop" false positive.
575+
func TestWritePixieRows_EmptyBatchShortCircuits(t *testing.T) {
576+
called := false
577+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
578+
called = true
579+
}))
580+
defer srv.Close()
581+
s, _ := New(Config{Endpoint: srv.URL})
582+
if err := s.WritePixieRows(context.Background(), "redis_events", nil); err != nil {
583+
t.Fatalf("empty WritePixieRows: %v", err)
584+
}
585+
if called {
586+
t.Fatalf("empty batch made an HTTP call")
587+
}
588+
}

0 commit comments

Comments
 (0)