From aca987eac9b0265cb5c9729e4893c46e2db75c87 Mon Sep 17 00:00:00 2001
From: Marten Seemann <martenseemann@gmail.com>
Date: Fri, 10 Apr 2020 16:27:18 +0700
Subject: [PATCH] fix decoding of timestamps and durations in qlog tests

---
 qlog/event.go     |  6 +++---
 qlog/qlog_test.go | 17 ++++++++++++-----
 2 files changed, 15 insertions(+), 8 deletions(-)

diff --git a/qlog/event.go b/qlog/event.go
index 27ebf702b..17eb7d24e 100644
--- a/qlog/event.go
+++ b/qlog/event.go
@@ -10,6 +10,8 @@ import (
 	"github.com/francoispqt/gojay"
 )
 
+func milliseconds(dur time.Duration) float64 { return float64(dur.Nanoseconds()) / 1e6 }
+
 var eventFields = [4]string{"relative_time", "category", "event", "data"}
 
 type events []event
@@ -39,7 +41,7 @@ var _ gojay.MarshalerJSONArray = event{}
 
 func (e event) IsNil() bool { return false }
 func (e event) MarshalJSONArray(enc *gojay.Encoder) {
-	enc.Float64(float64(e.RelativeTime.Nanoseconds()) / 1e6)
+	enc.Float64(milliseconds(e.RelativeTime))
 	enc.String(e.Category().String())
 	enc.String(e.Name())
 	enc.Object(e.eventDetails)
@@ -180,8 +182,6 @@ func (e eventPacketDropped) MarshalJSONObject(enc *gojay.Encoder) {
 	enc.StringKey("trigger", e.Trigger.String())
 }
 
-func milliseconds(dur time.Duration) float64 { return float64(dur.Nanoseconds()) / 1e6 }
-
 type metrics struct {
 	MinRTT      time.Duration
 	SmoothedRTT time.Duration
diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go
index 8acd37298..2a7a49320 100644
--- a/qlog/qlog_test.go
+++ b/qlog/qlog_test.go
@@ -76,6 +76,9 @@ var _ = Describe("Tracer", func() {
 		commonFields := trace["common_fields"].(map[string]interface{})
 		Expect(commonFields).To(HaveKeyWithValue("ODCID", "deadbeef"))
 		Expect(commonFields).To(HaveKeyWithValue("group_id", "deadbeef"))
+		Expect(commonFields).To(HaveKey("reference_time"))
+		referenceTime := time.Unix(0, int64(commonFields["reference_time"].(float64)*1e6))
+		Expect(referenceTime).To(BeTemporally("~", time.Now(), 10*time.Millisecond))
 		Expect(trace).To(HaveKey("event_fields"))
 		for i, ef := range trace["event_fields"].([]interface{}) {
 			Expect(ef.(string)).To(Equal(eventFields[i]))
@@ -108,12 +111,16 @@ var _ = Describe("Tracer", func() {
 			traces := m["traces"].([]interface{})
 			Expect(traces).To(HaveLen(1))
 			trace := traces[0].(map[string]interface{})
+			Expect(trace).To(HaveKey("common_fields"))
+			commonFields := trace["common_fields"].(map[string]interface{})
+			Expect(commonFields).To(HaveKey("reference_time"))
+			referenceTime := time.Unix(0, int64(commonFields["reference_time"].(float64)*1e6))
 			Expect(trace).To(HaveKey("events"))
 			for _, e := range trace["events"].([]interface{}) {
 				ev := e.([]interface{})
 				Expect(ev).To(HaveLen(4))
 				entries = append(entries, entry{
-					Time:     time.Now().Add(time.Duration(ev[0].(float64)) * time.Millisecond),
+					Time:     referenceTime.Add(time.Duration(ev[0].(float64)*1e6) * time.Nanosecond),
 					Category: ev[1].(string),
 					Name:     ev[2].(string),
 					Event:    ev[3].(map[string]interface{}),
@@ -499,8 +506,8 @@ var _ = Describe("Tracer", func() {
 		})
 
 		It("records when the timer is set", func() {
-			t := time.Now().Add(1337 * time.Millisecond)
-			tracer.SetLossTimer(TimerTypePTO, protocol.EncryptionHandshake, t)
+			timeout := time.Now().Add(137 * time.Millisecond)
+			tracer.SetLossTimer(TimerTypePTO, protocol.EncryptionHandshake, timeout)
 			entry := exportAndParseSingle()
 			Expect(entry.Time).To(BeTemporally("~", time.Now(), 10*time.Millisecond))
 			Expect(entry.Category).To(Equal("recovery"))
@@ -511,8 +518,8 @@ var _ = Describe("Tracer", func() {
 			Expect(ev).To(HaveKeyWithValue("timer_type", "pto"))
 			Expect(ev).To(HaveKeyWithValue("packet_number_space", "handshake"))
 			Expect(ev).To(HaveKey("delta"))
-			delta := time.Duration(ev["delta"].(float64)) * time.Millisecond
-			Expect(entry.Time.Add(delta)).To(BeTemporally("~", t, 2*time.Millisecond))
+			delta := time.Duration(ev["delta"].(float64)*1e6) * time.Nanosecond
+			Expect(entry.Time.Add(delta)).To(BeTemporally("~", timeout, 10*time.Microsecond))
 		})
 
 		It("records when the loss timer expires", func() {