From 33af12712e7f7570f01ab3c65724da51f394b0f7 Mon Sep 17 00:00:00 2001 From: Marten Seemann Date: Wed, 8 Oct 2025 22:21:35 +0800 Subject: [PATCH] qlogwriter: implement the draft-12 trace header (#5360) --- qlogwriter/trace.go | 145 ++++++++++++++------------------------- qlogwriter/trace_test.go | 94 ++++++++++++------------- qlogwriter/writer.go | 14 ++-- 3 files changed, 98 insertions(+), 155 deletions(-) diff --git a/qlogwriter/trace.go b/qlogwriter/trace.go index d7b2bef9..cba8b298 100644 --- a/qlogwriter/trace.go +++ b/qlogwriter/trace.go @@ -38,108 +38,65 @@ func init() { } } -type topLevel struct { - trace trace +type traceHeader struct { + VantagePointType string + GroupID *ConnectionID + ReferenceTime time.Time } -func (l topLevel) Encode(enc *jsontext.Encoder) error { +func (l traceHeader) Encode(enc *jsontext.Encoder) error { h := encoderHelper{enc: enc} h.WriteToken(jsontext.BeginObject) + h.WriteToken(jsontext.String("file_schema")) + h.WriteToken(jsontext.String("urn:ietf:params:qlog:file:sequential")) + h.WriteToken(jsontext.String("serialization_format")) + h.WriteToken(jsontext.String("application/qlog+json-seq")) + h.WriteToken(jsontext.String("title")) + h.WriteToken(jsontext.String("quic-go qlog")) + h.WriteToken(jsontext.String("code_version")) + h.WriteToken(jsontext.String(quicGoVersion)) + + h.WriteToken(jsontext.String("trace")) + // trace + h.WriteToken(jsontext.BeginObject) + h.WriteToken(jsontext.String("vantage_point")) + // -- vantage_point + h.WriteToken(jsontext.BeginObject) + h.WriteToken(jsontext.String("type")) + h.WriteToken(jsontext.String(l.VantagePointType)) + // -- end vantage_point + h.WriteToken(jsontext.EndObject) + + h.WriteToken(jsontext.String("common_fields")) + // -- common_fields + h.WriteToken(jsontext.BeginObject) + if l.GroupID != nil { + h.WriteToken(jsontext.String("group_id")) + h.WriteToken(jsontext.String(l.GroupID.String())) + } + h.WriteToken(jsontext.String("reference_time")) + // ---- reference_time + h.WriteToken(jsontext.BeginObject) + h.WriteToken(jsontext.String("clock_type")) + h.WriteToken(jsontext.String("monotonic")) + h.WriteToken(jsontext.String("epoch")) + h.WriteToken(jsontext.String("unknown")) + h.WriteToken(jsontext.String("wall_clock_time")) + h.WriteToken(jsontext.String(l.ReferenceTime.Format(time.RFC3339Nano))) + // ---- end reference_time + h.WriteToken(jsontext.EndObject) + // -- end common_fields + h.WriteToken(jsontext.EndObject) + // end trace + h.WriteToken(jsontext.EndObject) + + // The following fields are not required by the qlog draft anymore, + // but qvis still requires them to be present. h.WriteToken(jsontext.String("qlog_format")) h.WriteToken(jsontext.String("JSON-SEQ")) h.WriteToken(jsontext.String("qlog_version")) h.WriteToken(jsontext.String("0.3")) - h.WriteToken(jsontext.String("title")) - h.WriteToken(jsontext.String("quic-go qlog")) - h.WriteToken(jsontext.String("configuration")) - if err := (configuration{Version: quicGoVersion}).Encode(enc); err != nil { - return err - } - h.WriteToken(jsontext.String("trace")) - if err := l.trace.Encode(enc); err != nil { - return err - } - h.WriteToken(jsontext.EndObject) - return h.err -} - -type configuration struct { - Version string -} - -func (c configuration) Encode(enc *jsontext.Encoder) error { - h := encoderHelper{enc: enc} - h.WriteToken(jsontext.BeginObject) - h.WriteToken(jsontext.String("code_version")) - h.WriteToken(jsontext.String(c.Version)) - h.WriteToken(jsontext.EndObject) - return h.err -} - -type vantagePoint struct { - Name string - Type string -} - -func (p vantagePoint) Encode(enc *jsontext.Encoder) error { - h := encoderHelper{enc: enc} - h.WriteToken(jsontext.BeginObject) - if p.Name != "" { - h.WriteToken(jsontext.String("name")) - h.WriteToken(jsontext.String(p.Name)) - } - if p.Type != "" { - h.WriteToken(jsontext.String("type")) - h.WriteToken(jsontext.String(p.Type)) - } - h.WriteToken(jsontext.EndObject) - return h.err -} - -type commonFields struct { - ODCID *ConnectionID - GroupID *ConnectionID - ProtocolType string - ReferenceTime time.Time -} - -func (f commonFields) Encode(enc *jsontext.Encoder) error { - h := encoderHelper{enc: enc} - h.WriteToken(jsontext.BeginObject) - if f.ODCID != nil { - h.WriteToken(jsontext.String("ODCID")) - h.WriteToken(jsontext.String(f.ODCID.String())) - h.WriteToken(jsontext.String("group_id")) - h.WriteToken(jsontext.String(f.ODCID.String())) - } - if f.ProtocolType != "" { - h.WriteToken(jsontext.String("protocol_type")) - h.WriteToken(jsontext.String(f.ProtocolType)) - } - h.WriteToken(jsontext.String("reference_time")) - h.WriteToken(jsontext.Float(float64(f.ReferenceTime.UnixNano()) / 1e6)) - h.WriteToken(jsontext.String("time_format")) - h.WriteToken(jsontext.String("relative")) - h.WriteToken(jsontext.EndObject) - return h.err -} - -type trace struct { - VantagePoint vantagePoint - CommonFields commonFields -} - -func (t trace) Encode(enc *jsontext.Encoder) error { - h := encoderHelper{enc: enc} - h.WriteToken(jsontext.BeginObject) - h.WriteToken(jsontext.String("vantage_point")) - if err := t.VantagePoint.Encode(enc); err != nil { - return err - } - h.WriteToken(jsontext.String("common_fields")) - if err := t.CommonFields.Encode(enc); err != nil { - return err - } + h.WriteToken(jsontext.EndObject) return h.err } diff --git a/qlogwriter/trace_test.go b/qlogwriter/trace_test.go index 575e69f1..b55e141f 100644 --- a/qlogwriter/trace_test.go +++ b/qlogwriter/trace_test.go @@ -40,18 +40,33 @@ func unmarshal(data []byte, v any) error { return json.Unmarshal(data, v) } -func newTracer() (Trace, *bytes.Buffer) { - buf := &bytes.Buffer{} - trace := NewFileSeq(nopWriteCloser(buf)) - go trace.Run() - return trace, buf +func TestTraceMetadata(t *testing.T) { + t.Run("non-connection trace", func(t *testing.T) { + buf := &bytes.Buffer{} + trace := NewFileSeq(nopWriteCloser(buf)) + go trace.Run() + producer := trace.AddProducer() + producer.Close() + + testTraceMetadata(t, buf, "transport", "") + }) + + t.Run("connection trace", func(t *testing.T) { + buf := &bytes.Buffer{} + trace := NewConnectionFileSeq( + nopWriteCloser(buf), + false, + protocol.ParseConnectionID([]byte{0xde, 0xad, 0xbe, 0xef}), + ) + go trace.Run() + producer := trace.AddProducer() + producer.Close() + + testTraceMetadata(t, buf, "server", "deadbeef") + }) } -func TestTraceMetadata(t *testing.T) { - trace, buf := newTracer() - producer := trace.AddProducer() - producer.Close() - +func testTraceMetadata(t *testing.T, buf *bytes.Buffer, expectedVantagePoint, expectedGroupID string) { var m map[string]any require.NoError(t, unmarshal(buf.Bytes(), &m)) require.Equal(t, "0.3", m["qlog_version"]) @@ -60,49 +75,24 @@ func TestTraceMetadata(t *testing.T) { tr := m["trace"].(map[string]any) require.Contains(t, tr, "common_fields") commonFields := tr["common_fields"].(map[string]any) - require.NotContains(t, commonFields, "ODCID") - require.NotContains(t, commonFields, "group_id") + if expectedGroupID != "" { + require.Contains(t, commonFields, "group_id") + require.Equal(t, expectedGroupID, commonFields["group_id"]) + } else { + require.NotContains(t, commonFields, "group_id") + } require.Contains(t, commonFields, "reference_time") - referenceTime := time.Unix(0, int64(commonFields["reference_time"].(float64)*1e6)) - require.WithinDuration(t, time.Now(), referenceTime, scaleDuration(10*time.Millisecond)) - require.Equal(t, "relative", commonFields["time_format"]) + referenceTimeMap := commonFields["reference_time"].(map[string]any) + require.Contains(t, referenceTimeMap, "clock_type") + require.Equal(t, "monotonic", referenceTimeMap["clock_type"]) + require.Contains(t, referenceTimeMap, "epoch") + require.Equal(t, "unknown", referenceTimeMap["epoch"]) + require.Contains(t, referenceTimeMap, "wall_clock_time") + wallClockTimeStr := referenceTimeMap["wall_clock_time"].(string) + wallClockTime, err := time.Parse(time.RFC3339Nano, wallClockTimeStr) + require.NoError(t, err) + require.WithinDuration(t, time.Now(), wallClockTime, scaleDuration(10*time.Millisecond)) require.Contains(t, tr, "vantage_point") vantagePoint := tr["vantage_point"].(map[string]any) - require.Equal(t, "transport", vantagePoint["type"]) -} - -func newConnectionTracer(t *testing.T) (Recorder, *bytes.Buffer) { - buf := &bytes.Buffer{} - trace := NewConnectionFileSeq( - nopWriteCloser(buf), - false, - protocol.ParseConnectionID([]byte{0xde, 0xad, 0xbe, 0xef}), - ) - go trace.Run() - recorder := trace.AddProducer() - t.Cleanup(func() { recorder.Close() }) - return recorder, buf -} - -func TestConnectionTraceMetadata(t *testing.T) { - tracer, buf := newConnectionTracer(t) - tracer.Close() - - m := make(map[string]any) - require.NoError(t, unmarshal(buf.Bytes(), &m)) - require.Equal(t, "0.3", m["qlog_version"]) - require.Contains(t, m, "title") - require.Contains(t, m, "trace") - trace := m["trace"].(map[string]any) - require.Contains(t, trace, "common_fields") - commonFields := trace["common_fields"].(map[string]any) - require.Equal(t, "deadbeef", commonFields["ODCID"]) - require.Equal(t, "deadbeef", commonFields["group_id"]) - require.Contains(t, commonFields, "reference_time") - referenceTime := time.Unix(0, int64(commonFields["reference_time"].(float64)*1e6)) - require.WithinDuration(t, time.Now(), referenceTime, scaleDuration(10*time.Millisecond)) - require.Equal(t, "relative", commonFields["time_format"]) - require.Contains(t, trace, "vantage_point") - vantagePoint := trace["vantage_point"].(map[string]any) - require.Equal(t, "server", vantagePoint["type"]) + require.Equal(t, expectedVantagePoint, vantagePoint["type"]) } diff --git a/qlogwriter/writer.go b/qlogwriter/writer.go index 0421aa6a..19cfde12 100644 --- a/qlogwriter/writer.go +++ b/qlogwriter/writer.go @@ -70,20 +70,16 @@ func NewConnectionFileSeq(w io.WriteCloser, isClient bool, odcid ConnectionID) * func newFileSeq(w io.WriteCloser, pers string, odcid *ConnectionID) *FileSeq { now := time.Now() - tr := &trace{ - VantagePoint: vantagePoint{Type: pers}, - CommonFields: commonFields{ - ODCID: odcid, - GroupID: odcid, - ReferenceTime: now, - }, - } buf := &bytes.Buffer{} enc := jsontext.NewEncoder(buf) if _, err := buf.Write(recordSeparator); err != nil { panic(fmt.Sprintf("qlog encoding into a bytes.Buffer failed: %s", err)) } - if err := (&topLevel{trace: *tr}).Encode(enc); err != nil { + if err := (&traceHeader{ + VantagePointType: pers, + GroupID: odcid, + ReferenceTime: now, + }).Encode(enc); err != nil { panic(fmt.Sprintf("qlog encoding into a bytes.Buffer failed: %s", err)) } _, encodeErr := w.Write(buf.Bytes())