From 2bf6c6aea4d1b1486a6dff53092f5082fb9f32a6 Mon Sep 17 00:00:00 2001 From: Marten Seemann Date: Tue, 1 Dec 2020 13:39:25 +0700 Subject: [PATCH] add support for the connection_closed qlog event --- qlog/event.go | 47 ++++++++++++++++++++++++++++++----------------- qlog/qlog.go | 14 +++----------- qlog/qlog_test.go | 47 ++++++++++++++++++++++++++++++++++++++++++----- 3 files changed, 75 insertions(+), 33 deletions(-) diff --git a/qlog/event.go b/qlog/event.go index 53288d74..71880ed5 100644 --- a/qlog/event.go +++ b/qlog/event.go @@ -77,16 +77,42 @@ func (e eventConnectionStarted) MarshalJSONObject(enc *gojay.Encoder) { } type eventConnectionClosed struct { - Reason timeoutReason + Reason logging.CloseReason } func (e eventConnectionClosed) Category() category { return categoryTransport } -func (e eventConnectionClosed) Name() string { return "connection_state_updated" } +func (e eventConnectionClosed) Name() string { return "connection_closed" } func (e eventConnectionClosed) IsNil() bool { return false } func (e eventConnectionClosed) MarshalJSONObject(enc *gojay.Encoder) { - enc.StringKey("new", "closed") - enc.StringKey("trigger", e.Reason.String()) + // TODO: add version mismatch + if token, ok := e.Reason.StatelessReset(); ok { + enc.StringKey("owner", ownerRemote.String()) + enc.StringKey("trigger", "stateless_reset") + enc.StringKey("stateless_reset_token", fmt.Sprintf("%x", token)) + return + } + if timeout, ok := e.Reason.Timeout(); ok { + enc.StringKey("owner", ownerLocal.String()) + enc.StringKey("trigger", timeoutReason(timeout).String()) + return + } + if code, remote, ok := e.Reason.ApplicationError(); ok { + owner := ownerLocal + if remote { + owner = ownerRemote + } + enc.StringKey("owner", owner.String()) + enc.Uint64Key("application_code", uint64(code)) + } + if code, remote, ok := e.Reason.TransportError(); ok { + owner := ownerLocal + if remote { + owner = ownerRemote + } + enc.StringKey("owner", owner.String()) + enc.StringKey("connection_code", transportError(code).String()) + } } type eventPacketSent struct { @@ -155,19 +181,6 @@ func (e eventVersionNegotiationReceived) MarshalJSONObject(enc *gojay.Encoder) { enc.ArrayKey("supported_versions", versions(e.SupportedVersions)) } -type eventStatelessResetReceived struct { - Token protocol.StatelessResetToken -} - -func (e eventStatelessResetReceived) Category() category { return categoryTransport } -func (e eventStatelessResetReceived) Name() string { return "packet_received" } -func (e eventStatelessResetReceived) IsNil() bool { return false } - -func (e eventStatelessResetReceived) MarshalJSONObject(enc *gojay.Encoder) { - enc.StringKey("packet_type", packetType(logging.PacketTypeStatelessReset).String()) - enc.StringKey("stateless_reset_token", fmt.Sprintf("%x", e.Token)) -} - type eventPacketBuffered struct { PacketType packetType } diff --git a/qlog/qlog.go b/qlog/qlog.go index a3ebfbcc..5e38af48 100644 --- a/qlog/qlog.go +++ b/qlog/qlog.go @@ -9,9 +9,8 @@ import ( "sync" "time" - "github.com/lucas-clemente/quic-go/internal/utils" - "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/utils" "github.com/lucas-clemente/quic-go/internal/wire" "github.com/lucas-clemente/quic-go/logging" @@ -157,15 +156,8 @@ func (t *connectionTracer) StartedConnection(local, remote net.Addr, version pro func (t *connectionTracer) ClosedConnection(r logging.CloseReason) { t.mutex.Lock() - defer t.mutex.Unlock() - - if reason, ok := r.Timeout(); ok { - t.recordEvent(time.Now(), &eventConnectionClosed{Reason: timeoutReason(reason)}) - } else if token, ok := r.StatelessReset(); ok { - t.recordEvent(time.Now(), &eventStatelessResetReceived{ - Token: token, - }) - } + t.recordEvent(time.Now(), &eventConnectionClosed{Reason: r}) + t.mutex.Unlock() } func (t *connectionTracer) SentTransportParameters(tp *wire.TransportParameters) { diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go index 671ec211..52b9eb76 100644 --- a/qlog/qlog_test.go +++ b/qlog/qlog_test.go @@ -11,6 +11,7 @@ import ( "time" "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/qerr" "github.com/lucas-clemente/quic-go/internal/utils" "github.com/lucas-clemente/quic-go/logging" @@ -169,26 +170,62 @@ var _ = Describe("Tracing", func() { Expect(ev).To(HaveKeyWithValue("dst_cid", "05060708")) }) - It("records connection closes", func() { + It("records idle timeouts", func() { tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonIdle)) entry := exportAndParseSingle() Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) - Expect(entry.Name).To(Equal("transport:connection_state_updated")) + Expect(entry.Name).To(Equal("transport:connection_closed")) ev := entry.Event - Expect(ev).To(HaveKeyWithValue("new", "closed")) + Expect(ev).To(HaveLen(2)) + Expect(ev).To(HaveKeyWithValue("owner", "local")) Expect(ev).To(HaveKeyWithValue("trigger", "idle_timeout")) }) + It("records handshake timeouts", func() { + tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonHandshake)) + entry := exportAndParseSingle() + Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) + Expect(entry.Name).To(Equal("transport:connection_closed")) + ev := entry.Event + Expect(ev).To(HaveLen(2)) + Expect(ev).To(HaveKeyWithValue("owner", "local")) + Expect(ev).To(HaveKeyWithValue("trigger", "handshake_timeout")) + }) + It("records a received stateless reset packet", func() { tracer.ClosedConnection(logging.NewStatelessResetCloseReason(logging.StatelessResetToken{0x00, 0x11, 0x22, 0x33, 0x44, 0x55, 0x66, 0x77, 0x88, 0x99, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff})) entry := exportAndParseSingle() Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) - Expect(entry.Name).To(Equal("transport:packet_received")) + Expect(entry.Name).To(Equal("transport:connection_closed")) ev := entry.Event - Expect(ev).To(HaveKeyWithValue("packet_type", "stateless_reset")) + Expect(ev).To(HaveLen(3)) + Expect(ev).To(HaveKeyWithValue("owner", "remote")) + Expect(ev).To(HaveKeyWithValue("trigger", "stateless_reset")) Expect(ev).To(HaveKeyWithValue("stateless_reset_token", "00112233445566778899aabbccddeeff")) }) + It("records application errors", func() { + tracer.ClosedConnection(logging.NewApplicationCloseReason(1337, true)) + entry := exportAndParseSingle() + Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) + Expect(entry.Name).To(Equal("transport:connection_closed")) + ev := entry.Event + Expect(ev).To(HaveLen(2)) + Expect(ev).To(HaveKeyWithValue("owner", "remote")) + Expect(ev).To(HaveKeyWithValue("application_code", float64(1337))) + }) + + It("records transport errors", func() { + tracer.ClosedConnection(logging.NewTransportCloseReason(qerr.AEADLimitReached, false)) + entry := exportAndParseSingle() + Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond))) + Expect(entry.Name).To(Equal("transport:connection_closed")) + ev := entry.Event + Expect(ev).To(HaveLen(2)) + Expect(ev).To(HaveKeyWithValue("owner", "local")) + Expect(ev).To(HaveKeyWithValue("connection_code", "aead_limit_reached")) + }) + It("records sent transport parameters", func() { tracer.SentTransportParameters(&logging.TransportParameters{ InitialMaxStreamDataBidiLocal: 1000,