trace and qlog version selection / negotiation

qlog/event.go

@@ -83,6 +83,25 @@ func (e eventConnectionStarted) MarshalJSONObject(enc *gojay.Encoder) {
 	enc.StringKey("dst_cid", connectionID(e.DestConnectionID).String())
 }
 
+type eventVersionNegotiated struct {
+	clientVersions, serverVersions []versionNumber
+	chosenVersion                  versionNumber
+}
+
+func (e eventVersionNegotiated) Category() category { return categoryTransport }
+func (e eventVersionNegotiated) Name() string       { return "version_information" }
+func (e eventVersionNegotiated) IsNil() bool        { return false }
+
+func (e eventVersionNegotiated) MarshalJSONObject(enc *gojay.Encoder) {
+	if len(e.clientVersions) > 0 {
+		enc.ArrayKey("client_versions", versions(e.clientVersions))
+	}
+	if len(e.serverVersions) > 0 {
+		enc.ArrayKey("server_versions", versions(e.serverVersions))
+	}
+	enc.StringKey("chosen_version", e.chosenVersion.String())
+}
+
 type eventConnectionClosed struct {
 	Reason logging.CloseReason
 }

qlog/qlog.go

@@ -182,6 +182,29 @@ func (t *connectionTracer) StartedConnection(local, remote net.Addr, srcConnID,
 	t.mutex.Unlock()
 }
 
+func (t *connectionTracer) NegotiatedVersion(chosen logging.VersionNumber, client, server []logging.VersionNumber) {
+	var clientVersions, serverVersions []versionNumber
+	if len(client) > 0 {
+		clientVersions = make([]versionNumber, len(client))
+		for i, v := range client {
+			clientVersions[i] = versionNumber(v)
+		}
+	}
+	if len(server) > 0 {
+		serverVersions = make([]versionNumber, len(server))
+		for i, v := range server {
+			serverVersions[i] = versionNumber(v)
+		}
+	}
+	t.mutex.Lock()
+	t.recordEvent(time.Now(), &eventVersionNegotiated{
+		clientVersions: clientVersions,
+		serverVersions: serverVersions,
+		chosenVersion:  versionNumber(chosen),
+	})
+	t.mutex.Unlock()
+}
+
 func (t *connectionTracer) ClosedConnection(r logging.CloseReason) {
 	t.mutex.Lock()
 	t.recordEvent(time.Now(), &eventConnectionClosed{Reason: r})

qlog/qlog_test.go

@@ -169,6 +169,30 @@ var _ = Describe("Tracing", func() {
 				Expect(ev).To(HaveKeyWithValue("dst_cid", "05060708"))
 			})
 
+			It("records the version, if no version negotiation happened", func() {
+				tracer.NegotiatedVersion(0x1337, nil, nil)
+				entry := exportAndParseSingle()
+				Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
+				Expect(entry.Name).To(Equal("transport:version_information"))
+				ev := entry.Event
+				Expect(ev).To(HaveLen(1))
+				Expect(ev).To(HaveKeyWithValue("chosen_version", "1337"))
+			})
+
+			It("records the version, if version negotiation happened", func() {
+				tracer.NegotiatedVersion(0x1337, []logging.VersionNumber{1, 2, 3}, []logging.VersionNumber{4, 5, 6})
+				entry := exportAndParseSingle()
+				Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
+				Expect(entry.Name).To(Equal("transport:version_information"))
+				ev := entry.Event
+				Expect(ev).To(HaveLen(3))
+				Expect(ev).To(HaveKeyWithValue("chosen_version", "1337"))
+				Expect(ev).To(HaveKey("client_versions"))
+				Expect(ev["client_versions"].([]interface{})).To(Equal([]interface{}{"1", "2", "3"}))
+				Expect(ev).To(HaveKey("server_versions"))
+				Expect(ev["server_versions"].([]interface{})).To(Equal([]interface{}{"4", "5", "6"}))
+			})
+
 			It("records idle timeouts", func() {
 				tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonIdle))
 				entry := exportAndParseSingle()