use the new error types to log the reason why a connection is closed

This commit is contained in:
Marten Seemann
2021-05-03 14:00:41 +07:00
parent 5f2cf0422e
commit 1613809ba2
16 changed files with 87 additions and 307 deletions

View File

@@ -1,13 +1,14 @@
package qlog
import (
"errors"
"fmt"
"net"
"time"
"github.com/lucas-clemente/quic-go/internal/utils"
"github.com/lucas-clemente/quic-go"
"github.com/lucas-clemente/quic-go/internal/protocol"
"github.com/lucas-clemente/quic-go/internal/utils"
"github.com/lucas-clemente/quic-go/logging"
"github.com/francoispqt/gojay"
@@ -103,7 +104,7 @@ func (e eventVersionNegotiated) MarshalJSONObject(enc *gojay.Encoder) {
}
type eventConnectionClosed struct {
Reason logging.CloseReason
e error
}
func (e eventConnectionClosed) Category() category { return categoryTransport }
@@ -111,34 +112,40 @@ func (e eventConnectionClosed) Name() string { return "connection_closed"
func (e eventConnectionClosed) IsNil() bool { return false }
func (e eventConnectionClosed) MarshalJSONObject(enc *gojay.Encoder) {
if token, ok := e.Reason.StatelessReset(); ok {
var (
statelessResetErr *quic.StatelessResetError
handshakeTimeoutErr *quic.HandshakeTimeoutError
idleTimeoutErr *quic.IdleTimeoutError
applicationErr *quic.ApplicationError
transportErr *quic.TransportError
versionNegotiationErr *quic.VersionNegotiationError
)
switch {
case errors.As(e.e, &statelessResetErr):
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("stateless_reset_token", fmt.Sprintf("%x", statelessResetErr.Token))
case errors.As(e.e, &handshakeTimeoutErr):
enc.StringKey("owner", ownerLocal.String())
enc.StringKey("trigger", timeoutReason(timeout).String())
return
}
if code, remote, ok := e.Reason.ApplicationError(); ok {
enc.StringKey("trigger", "handshake_timeout")
case errors.As(e.e, &idleTimeoutErr):
enc.StringKey("owner", ownerLocal.String())
enc.StringKey("trigger", "idle_timeout")
case errors.As(e.e, &applicationErr):
owner := ownerLocal
if remote {
if applicationErr.Remote {
owner = ownerRemote
}
enc.StringKey("owner", owner.String())
enc.Uint64Key("application_code", uint64(code))
}
if code, remote, ok := e.Reason.TransportError(); ok {
enc.Uint64Key("application_code", uint64(applicationErr.ErrorCode))
case errors.As(e.e, &transportErr):
owner := ownerLocal
if remote {
if transportErr.Remote {
owner = ownerRemote
}
enc.StringKey("owner", owner.String())
enc.StringKey("connection_code", transportError(code).String())
}
if _, ok := e.Reason.VersionNegotiation(); ok {
enc.StringKey("connection_code", transportError(transportErr.ErrorCode).String())
case errors.As(e.e, &versionNegotiationErr):
enc.StringKey("owner", ownerRemote.String())
enc.StringKey("trigger", "version_negotiation")
}

View File

@@ -206,9 +206,9 @@ func (t *connectionTracer) NegotiatedVersion(chosen logging.VersionNumber, clien
t.mutex.Unlock()
}
func (t *connectionTracer) ClosedConnection(r logging.CloseReason) {
func (t *connectionTracer) ClosedConnection(e error) {
t.mutex.Lock()
t.recordEvent(time.Now(), &eventConnectionClosed{Reason: r})
t.recordEvent(time.Now(), &eventConnectionClosed{e: e})
t.mutex.Unlock()
}

View File

@@ -11,6 +11,7 @@ import (
"os"
"time"
"github.com/lucas-clemente/quic-go"
"github.com/lucas-clemente/quic-go/internal/protocol"
"github.com/lucas-clemente/quic-go/internal/qerr"
"github.com/lucas-clemente/quic-go/internal/utils"
@@ -195,7 +196,7 @@ var _ = Describe("Tracing", func() {
})
It("records idle timeouts", func() {
tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonIdle))
tracer.ClosedConnection(&quic.IdleTimeoutError{})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
Expect(entry.Name).To(Equal("transport:connection_closed"))
@@ -206,7 +207,7 @@ var _ = Describe("Tracing", func() {
})
It("records handshake timeouts", func() {
tracer.ClosedConnection(logging.NewTimeoutCloseReason(logging.TimeoutReasonHandshake))
tracer.ClosedConnection(&quic.HandshakeTimeoutError{})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
Expect(entry.Name).To(Equal("transport:connection_closed"))
@@ -217,7 +218,9 @@ var _ = Describe("Tracing", func() {
})
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}))
tracer.ClosedConnection(&quic.StatelessResetError{
Token: protocol.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:connection_closed"))
@@ -229,7 +232,7 @@ var _ = Describe("Tracing", func() {
})
It("records connection closing due to version negotiation failure", func() {
tracer.ClosedConnection(logging.NewVersionNegotiationError([]logging.VersionNumber{1, 2, 3}))
tracer.ClosedConnection(&quic.VersionNegotiationError{})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
Expect(entry.Name).To(Equal("transport:connection_closed"))
@@ -240,7 +243,10 @@ var _ = Describe("Tracing", func() {
})
It("records application errors", func() {
tracer.ClosedConnection(logging.NewApplicationCloseReason(1337, true))
tracer.ClosedConnection(&quic.ApplicationError{
Remote: true,
ErrorCode: 1337,
})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
Expect(entry.Name).To(Equal("transport:connection_closed"))
@@ -251,7 +257,7 @@ var _ = Describe("Tracing", func() {
})
It("records transport errors", func() {
tracer.ClosedConnection(logging.NewTransportCloseReason(qerr.AEADLimitReached, false))
tracer.ClosedConnection(&quic.TransportError{ErrorCode: qerr.AEADLimitReached})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", time.Now(), scaleDuration(10*time.Millisecond)))
Expect(entry.Name).To(Equal("transport:connection_closed"))

View File

@@ -302,19 +302,6 @@ func (t timerType) String() string {
}
}
type timeoutReason logging.TimeoutReason
func (r timeoutReason) String() string {
switch logging.TimeoutReason(r) {
case logging.TimeoutReasonHandshake:
return "handshake_timeout"
case logging.TimeoutReasonIdle:
return "idle_timeout"
default:
return "unknown close reason"
}
}
type congestionState logging.CongestionState
func (s congestionState) String() string {

View File

@@ -58,11 +58,6 @@ var _ = Describe("Types", func() {
Expect(timerType(logging.TimerTypePTO).String()).To(Equal("pto"))
})
It("has a string representation for the close reason", func() {
Expect(timeoutReason(logging.TimeoutReasonHandshake).String()).To(Equal("handshake_timeout"))
Expect(timeoutReason(logging.TimeoutReasonIdle).String()).To(Equal("idle_timeout"))
})
It("has a string representation for the key type", func() {
Expect(encLevelToKeyType(protocol.EncryptionInitial, protocol.PerspectiveClient).String()).To(Equal("client_initial_secret"))
Expect(encLevelToKeyType(protocol.EncryptionInitial, protocol.PerspectiveServer).String()).To(Equal("server_initial_secret"))