From d1f9af4cc6b13c96dc302ac9ec5f061ed294d36b Mon Sep 17 00:00:00 2001
From: Marten Seemann <martenseemann@gmail.com>
Date: Sat, 3 Aug 2024 20:19:51 -0700
Subject: [PATCH] implement qlog JSONSEQ format, bump qlog version (#4609)

---
 .gitignore                             |  1 +
 integrationtests/self/qlog_dir_test.go |  3 ++-
 interop/utils/logging.go               |  2 +-
 qlog/connection_tracer_test.go         |  9 ++++-----
 qlog/qlog_dir.go                       |  6 +++---
 qlog/qlog_suite_test.go                |  7 +++++++
 qlog/trace.go                          |  4 ++--
 qlog/tracer_test.go                    |  7 +++----
 qlog/writer.go                         | 14 ++++++++++++++
 9 files changed, 37 insertions(+), 16 deletions(-)

diff --git a/.gitignore b/.gitignore
index 3cc06f240..b454729d5 100644
--- a/.gitignore
+++ b/.gitignore
@@ -4,6 +4,7 @@ main
 mockgen_tmp.go
 *.qtr
 *.qlog
+*.sqlog
 *.txt
 race.[0-9]*
 
diff --git a/integrationtests/self/qlog_dir_test.go b/integrationtests/self/qlog_dir_test.go
index b81366e53..2adedcba9 100644
--- a/integrationtests/self/qlog_dir_test.go
+++ b/integrationtests/self/qlog_dir_test.go
@@ -78,9 +78,10 @@ var _ = Describe("qlog dir tests", Serial, func() {
 		Expect(len(childs)).To(Equal(2))
 		odcids := make([]string, 0)
 		vantagePoints := make([]string, 0)
-		qlogFileNameRegexp := regexp.MustCompile(`^([0-f]+)_(client|server).qlog$`)
+		qlogFileNameRegexp := regexp.MustCompile(`^([0-f]+)_(client|server).sqlog$`)
 		for _, child := range childs {
 			matches := qlogFileNameRegexp.FindStringSubmatch(child.Name())
+			Expect(matches).To(HaveLen(3))
 			odcids = append(odcids, matches[1])
 			vantagePoints = append(vantagePoints, matches[2])
 		}
diff --git a/interop/utils/logging.go b/interop/utils/logging.go
index fa076ef47..7e718965e 100644
--- a/interop/utils/logging.go
+++ b/interop/utils/logging.go
@@ -39,7 +39,7 @@ func NewQLOGConnectionTracer(_ context.Context, p logging.Perspective, connID qu
 			log.Fatalf("failed to create qlog dir %s: %v", qlogDir, err)
 		}
 	}
-	path := fmt.Sprintf("%s/%s.qlog", strings.TrimRight(qlogDir, "/"), connID)
+	path := fmt.Sprintf("%s/%s.sqlog", strings.TrimRight(qlogDir, "/"), connID)
 	f, err := os.Create(path)
 	if err != nil {
 		log.Printf("Failed to create qlog file %s: %s", path, err.Error())
diff --git a/qlog/connection_tracer_test.go b/qlog/connection_tracer_test.go
index 3657b15f0..ef21904f2 100644
--- a/qlog/connection_tracer_test.go
+++ b/qlog/connection_tracer_test.go
@@ -2,7 +2,6 @@ package qlog
 
 import (
 	"bytes"
-	"encoding/json"
 	"io"
 	"net"
 	"net/netip"
@@ -36,7 +35,7 @@ func exportAndParse(buf *bytes.Buffer) []entry {
 	m := make(map[string]interface{})
 	line, err := buf.ReadBytes('\n')
 	Expect(err).ToNot(HaveOccurred())
-	Expect(json.Unmarshal(line, &m)).To(Succeed())
+	Expect(unmarshal(line, &m)).To(Succeed())
 	Expect(m).To(HaveKey("trace"))
 	var entries []entry
 	trace := m["trace"].(map[string]interface{})
@@ -50,7 +49,7 @@ func exportAndParse(buf *bytes.Buffer) []entry {
 		line, err := buf.ReadBytes('\n')
 		Expect(err).ToNot(HaveOccurred())
 		ev := make(map[string]interface{})
-		Expect(json.Unmarshal(line, &ev)).To(Succeed())
+		Expect(unmarshal(line, &ev)).To(Succeed())
 		Expect(ev).To(HaveLen(3))
 		Expect(ev).To(HaveKey("time"))
 		Expect(ev).To(HaveKey("name"))
@@ -89,8 +88,8 @@ var _ = Describe("Tracing", func() {
 		tracer.Close()
 
 		m := make(map[string]interface{})
-		Expect(json.Unmarshal(buf.Bytes(), &m)).To(Succeed())
-		Expect(m).To(HaveKeyWithValue("qlog_version", "draft-02"))
+		Expect(unmarshal(buf.Bytes(), &m)).To(Succeed())
+		Expect(m).To(HaveKeyWithValue("qlog_version", "0.3"))
 		Expect(m).To(HaveKey("title"))
 		Expect(m).To(HaveKey("trace"))
 		trace := m["trace"].(map[string]interface{})
diff --git a/qlog/qlog_dir.go b/qlog/qlog_dir.go
index 5ea5e3ae2..1c7e97fa6 100644
--- a/qlog/qlog_dir.go
+++ b/qlog/qlog_dir.go
@@ -19,7 +19,7 @@ func DefaultTracer(ctx context.Context, p logging.Perspective, connID logging.Co
 }
 
 // DefaultConnectionTracer creates a qlog file in the qlog directory specified by the QLOGDIR environment variable.
-// File names are <odcid>_<perspective>.qlog.
+// File names are <odcid>_<perspective>.sqlog.
 // Returns nil if QLOGDIR is not set.
 func DefaultConnectionTracer(_ context.Context, p logging.Perspective, connID logging.ConnectionID) *logging.ConnectionTracer {
 	var label string
@@ -33,7 +33,7 @@ func DefaultConnectionTracer(_ context.Context, p logging.Perspective, connID lo
 }
 
 // qlogDirTracer creates a qlog file in the qlog directory specified by the QLOGDIR environment variable.
-// File names are <odcid>_<label>.qlog.
+// File names are <odcid>_<label>.sqlog.
 // Returns nil if QLOGDIR is not set.
 func qlogDirTracer(p logging.Perspective, connID logging.ConnectionID, label string) *logging.ConnectionTracer {
 	qlogDir := os.Getenv("QLOGDIR")
@@ -45,7 +45,7 @@ func qlogDirTracer(p logging.Perspective, connID logging.ConnectionID, label str
 			log.Fatalf("failed to create qlog dir %s: %v", qlogDir, err)
 		}
 	}
-	path := fmt.Sprintf("%s/%s_%s.qlog", strings.TrimRight(qlogDir, "/"), connID, label)
+	path := fmt.Sprintf("%s/%s_%s.sqlog", strings.TrimRight(qlogDir, "/"), connID, label)
 	f, err := os.Create(path)
 	if err != nil {
 		log.Printf("Failed to create qlog file %s: %s", path, err.Error())
diff --git a/qlog/qlog_suite_test.go b/qlog/qlog_suite_test.go
index 53ebb3631..984211dae 100644
--- a/qlog/qlog_suite_test.go
+++ b/qlog/qlog_suite_test.go
@@ -26,6 +26,13 @@ func scaleDuration(t time.Duration) time.Duration {
 	return time.Duration(scaleFactor) * t
 }
 
+func unmarshal(data []byte, v interface{}) error {
+	if data[0] == recordSeparator {
+		data = data[1:]
+	}
+	return json.Unmarshal(data, v)
+}
+
 func checkEncoding(data []byte, expected map[string]interface{}) {
 	// unmarshal the data
 	m := make(map[string]interface{})
diff --git a/qlog/trace.go b/qlog/trace.go
index c183368d9..4c3d33c6f 100644
--- a/qlog/trace.go
+++ b/qlog/trace.go
@@ -43,8 +43,8 @@ type topLevel struct {
 
 func (topLevel) IsNil() bool { return false }
 func (l topLevel) MarshalJSONObject(enc *gojay.Encoder) {
-	enc.StringKey("qlog_format", "NDJSON")
-	enc.StringKey("qlog_version", "draft-02")
+	enc.StringKey("qlog_format", "JSON-SEQ")
+	enc.StringKey("qlog_version", "0.3")
 	enc.StringKeyOmitEmpty("title", "quic-go qlog")
 	enc.ObjectKey("configuration", configuration{Version: quicGoVersion})
 	enc.ObjectKey("trace", l.trace)
diff --git a/qlog/tracer_test.go b/qlog/tracer_test.go
index 8aa8faa5a..04e79b654 100644
--- a/qlog/tracer_test.go
+++ b/qlog/tracer_test.go
@@ -2,7 +2,6 @@ package qlog
 
 import (
 	"bytes"
-	"encoding/json"
 	"net"
 	"time"
 
@@ -28,12 +27,12 @@ var _ = Describe("Tracing", func() {
 		tracer.Close()
 
 		m := make(map[string]interface{})
-		Expect(json.Unmarshal(buf.Bytes(), &m)).To(Succeed())
-		Expect(m).To(HaveKeyWithValue("qlog_version", "draft-02"))
+		Expect(unmarshal(buf.Bytes(), &m)).To(Succeed())
+		Expect(m).To(HaveKeyWithValue("qlog_version", "0.3"))
 		Expect(m).To(HaveKey("title"))
 		Expect(m).To(HaveKey("trace"))
 		trace := m["trace"].(map[string]interface{})
-		Expect(trace).To(HaveKey(("common_fields")))
+		Expect(trace).To(HaveKey("common_fields"))
 		commonFields := trace["common_fields"].(map[string]interface{})
 		Expect(commonFields).ToNot(HaveKey("ODCID"))
 		Expect(commonFields).ToNot(HaveKey("group_id"))
diff --git a/qlog/writer.go b/qlog/writer.go
index 10cb64994..661c54e8b 100644
--- a/qlog/writer.go
+++ b/qlog/writer.go
@@ -12,6 +12,13 @@ import (
 
 const eventChanSize = 50
 
+const recordSeparator = 0x1e
+
+func writeRecordSeparator(w io.Writer) error {
+	_, err := w.Write([]byte{recordSeparator})
+	return err
+}
+
 type writer struct {
 	w io.WriteCloser
 
@@ -44,6 +51,9 @@ func (w *writer) Run() {
 	defer close(w.runStopped)
 	buf := &bytes.Buffer{}
 	enc := gojay.NewEncoder(buf)
+	if err := writeRecordSeparator(buf); err != nil {
+		panic(fmt.Sprintf("qlog encoding into a bytes.Buffer failed: %s", err))
+	}
 	if err := enc.Encode(&topLevel{trace: *w.tr}); err != nil {
 		panic(fmt.Sprintf("qlog encoding into a bytes.Buffer failed: %s", err))
 	}
@@ -58,6 +68,10 @@ func (w *writer) Run() {
 		if w.encodeErr != nil { // if encoding failed, just continue draining the event channel
 			continue
 		}
+		if err := writeRecordSeparator(w.w); err != nil {
+			w.encodeErr = err
+			continue
+		}
 		if err := enc.Encode(ev); err != nil {
 			w.encodeErr = err
 			continue