diff --git a/connection.go b/connection.go index 6bbede9cb..eb0862dda 100644 --- a/connection.go +++ b/connection.go @@ -2174,23 +2174,38 @@ func (c *Conn) handleCloseError(closeErr *closeError) { transportErr *TransportError ) var isRemoteClose bool + var trigger qlog.ConnectionCloseTrigger + var reason string + var transportErrorCode *qlog.TransportErrorCode + var applicationErrorCode *qlog.ApplicationErrorCode switch { case errors.Is(e, qerr.ErrIdleTimeout), - errors.Is(e, qerr.ErrHandshakeTimeout), - errors.As(e, &statelessResetErr), - errors.As(e, &versionNegotiationErr), - errors.As(e, &recreateErr): + errors.Is(e, qerr.ErrHandshakeTimeout): + trigger = qlog.ConnectionCloseTriggerIdleTimeout + case errors.As(e, &statelessResetErr): + trigger = qlog.ConnectionCloseTriggerStatelessReset + case errors.As(e, &versionNegotiationErr): + trigger = qlog.ConnectionCloseTriggerVersionMismatch + case errors.As(e, &recreateErr): case errors.As(e, &applicationErr): isRemoteClose = applicationErr.Remote + reason = applicationErr.ErrorMessage + applicationErrorCode = &applicationErr.ErrorCode case errors.As(e, &transportErr): isRemoteClose = transportErr.Remote + reason = transportErr.ErrorMessage + transportErrorCode = &transportErr.ErrorCode case closeErr.immediate: e = closeErr.err default: - e = &qerr.TransportError{ + te := &qerr.TransportError{ ErrorCode: qerr.InternalError, ErrorMessage: e.Error(), } + e = te + reason = te.ErrorMessage + code := te.ErrorCode + transportErrorCode = &code } c.streamsMap.CloseWithError(e) @@ -2205,7 +2220,17 @@ func (c *Conn) handleCloseError(closeErr *closeError) { defer c.connIDManager.Close() if c.qlogger != nil && !errors.As(e, &recreateErr) { - c.qlogger.RecordEvent(qlog.ConnectionClosed{Error: e}) + initiator := qlog.InitiatorLocal + if isRemoteClose { + initiator = qlog.InitiatorRemote + } + c.qlogger.RecordEvent(qlog.ConnectionClosed{ + Initiator: initiator, + ConnectionError: transportErrorCode, + ApplicationError: applicationErrorCode, + Trigger: trigger, + Reason: reason, + }) } // If this is a remote close we're done here diff --git a/connection_test.go b/connection_test.go index b92df1264..3acc73791 100644 --- a/connection_test.go +++ b/connection_test.go @@ -313,8 +313,24 @@ func testConnectionClose(t *testing.T, useApplicationClose bool, expectedErr err synctest.Wait() + var want qlog.ConnectionClosed + if useApplicationClose { + code := expectedErr.(*qerr.ApplicationError).ErrorCode + want = qlog.ConnectionClosed{ + Initiator: qlog.InitiatorLocal, + ApplicationError: &code, + Reason: expectedErr.(*qerr.ApplicationError).ErrorMessage, + } + } else { + code := expectedErr.(*qerr.TransportError).ErrorCode + want = qlog.ConnectionClosed{ + Initiator: qlog.InitiatorLocal, + ConnectionError: &code, + Reason: expectedErr.(*qerr.TransportError).ErrorMessage, + } + } require.Equal(t, - []qlogwriter.Event{qlog.ConnectionClosed{Error: expectedErr}}, + []qlogwriter.Event{want}, eventRecorder.Events(qlog.ConnectionClosed{}), ) eventRecorder.Clear() @@ -346,7 +362,7 @@ func TestConnectionStatelessReset(t *testing.T) { synctest.Wait() require.Equal(t, - []qlogwriter.Event{qlog.ConnectionClosed{Error: &StatelessResetError{}}}, + []qlogwriter.Event{qlog.ConnectionClosed{Initiator: qlog.InitiatorLocal, Trigger: qlog.ConnectionCloseTriggerStatelessReset}}, eventRecorder.Events(qlog.ConnectionClosed{}), ) }) @@ -936,8 +952,15 @@ func TestConnectionRemoteClose(t *testing.T) { t.Fatal("timeout") } + code := expectedErr.ErrorCode require.Equal(t, - []qlogwriter.Event{qlog.ConnectionClosed{Error: expectedErr}}, + []qlogwriter.Event{ + qlog.ConnectionClosed{ + Initiator: qlog.InitiatorRemote, + ConnectionError: &code, + Reason: expectedErr.ErrorMessage, + }, + }, eventRecorder.Events(qlog.ConnectionClosed{}), ) }) @@ -971,7 +994,12 @@ func TestConnectionIdleTimeoutDuringHandshake(t *testing.T) { } require.Equal(t, - []qlogwriter.Event{qlog.ConnectionClosed{Error: &IdleTimeoutError{}}}, + []qlogwriter.Event{ + qlog.ConnectionClosed{ + Initiator: qlog.InitiatorLocal, + Trigger: qlog.ConnectionCloseTriggerIdleTimeout, + }, + }, eventRecorder.Events(qlog.ConnectionClosed{}), ) }) @@ -1003,7 +1031,12 @@ func TestConnectionHandshakeIdleTimeout(t *testing.T) { } require.Equal(t, - []qlogwriter.Event{qlog.ConnectionClosed{Error: &HandshakeTimeoutError{}}}, + []qlogwriter.Event{ + qlog.ConnectionClosed{ + Initiator: qlog.InitiatorLocal, + Trigger: qlog.ConnectionCloseTriggerIdleTimeout, + }, + }, eventRecorder.Events(qlog.ConnectionClosed{}), ) }) @@ -2763,7 +2796,10 @@ func TestConnectionVersionNegotiationNoMatch(t *testing.T) { }, SupportedVersions: vnpVersions, }, - qlog.ConnectionClosed{Error: verr}, + qlog.ConnectionClosed{ + Initiator: qlog.InitiatorLocal, + Trigger: qlog.ConnectionCloseTriggerVersionMismatch, + }, }, eventRecorder.Events(qlog.VersionNegotiationReceived{}, qlog.ConnectionClosed{}), ) @@ -3150,9 +3186,14 @@ func TestConnectionEarlyClose(t *testing.T) { case err := <-errChan: require.Error(t, err) require.ErrorContains(t, err, "early error") + code := qerr.InternalError require.Equal(t, []qlogwriter.Event{ - qlog.ConnectionClosed{Error: &qerr.TransportError{ErrorCode: qerr.InternalError, ErrorMessage: "early error"}}, + qlog.ConnectionClosed{ + Initiator: qlog.InitiatorLocal, + ConnectionError: &code, + Reason: "early error", + }, }, eventRecorder.Events(qlog.ConnectionClosed{}), ) diff --git a/qlog/event.go b/qlog/event.go index bef2334c3..226a043c5 100644 --- a/qlog/event.go +++ b/qlog/event.go @@ -1,7 +1,6 @@ package qlog import ( - "errors" "fmt" "net/netip" "time" @@ -130,7 +129,14 @@ func (e VersionInformation) Encode(enc *jsontext.Encoder, _ time.Time) error { } type ConnectionClosed struct { - Error error + Initiator Initiator + + ConnectionError *TransportErrorCode + ApplicationError *ApplicationErrorCode + + Reason string + + Trigger ConnectionCloseTrigger } func (e ConnectionClosed) Name() string { return "transport:connection_closed" } @@ -138,55 +144,68 @@ func (e ConnectionClosed) Name() string { return "transport:connection_closed" } func (e ConnectionClosed) Encode(enc *jsontext.Encoder, _ time.Time) error { h := encoderHelper{enc: enc} h.WriteToken(jsontext.BeginObject) - var ( - statelessResetErr *qerr.StatelessResetError - handshakeTimeoutErr *qerr.HandshakeTimeoutError - idleTimeoutErr *qerr.IdleTimeoutError - applicationErr *qerr.ApplicationError - transportErr *qerr.TransportError - versionNegotiationErr *qerr.VersionNegotiationError - ) - switch { - case errors.As(e.Error, &statelessResetErr): - h.WriteToken(jsontext.String("initiator")) - h.WriteToken(jsontext.String(string(InitiatorRemote))) - h.WriteToken(jsontext.String("trigger")) - h.WriteToken(jsontext.String("stateless_reset")) - case errors.As(e.Error, &handshakeTimeoutErr): - h.WriteToken(jsontext.String("initiator")) - h.WriteToken(jsontext.String(string(InitiatorLocal))) - h.WriteToken(jsontext.String("trigger")) - h.WriteToken(jsontext.String("handshake_timeout")) - case errors.As(e.Error, &idleTimeoutErr): - h.WriteToken(jsontext.String("initiator")) - h.WriteToken(jsontext.String(string(InitiatorLocal))) - h.WriteToken(jsontext.String("trigger")) - h.WriteToken(jsontext.String("idle_timeout")) - case errors.As(e.Error, &applicationErr): - initiator := InitiatorLocal - if applicationErr.Remote { - initiator = InitiatorRemote + h.WriteToken(jsontext.String("initiator")) + h.WriteToken(jsontext.String(string(e.Initiator))) + if e.ConnectionError != nil { + h.WriteToken(jsontext.String("connection_error")) + if e.ConnectionError.IsCryptoError() { + h.WriteToken(jsontext.String(fmt.Sprintf("crypto_error_%#x", uint16(*e.ConnectionError)))) + } else { + switch *e.ConnectionError { + case qerr.NoError: + h.WriteToken(jsontext.String("no_error")) + case qerr.InternalError: + h.WriteToken(jsontext.String("internal_error")) + case qerr.ConnectionRefused: + h.WriteToken(jsontext.String("connection_refused")) + case qerr.FlowControlError: + h.WriteToken(jsontext.String("flow_control_error")) + case qerr.StreamLimitError: + h.WriteToken(jsontext.String("stream_limit_error")) + case qerr.StreamStateError: + h.WriteToken(jsontext.String("stream_state_error")) + case qerr.FinalSizeError: + h.WriteToken(jsontext.String("final_size_error")) + case qerr.FrameEncodingError: + h.WriteToken(jsontext.String("frame_encoding_error")) + case qerr.TransportParameterError: + h.WriteToken(jsontext.String("transport_parameter_error")) + case qerr.ConnectionIDLimitError: + h.WriteToken(jsontext.String("connection_id_limit_error")) + case qerr.ProtocolViolation: + h.WriteToken(jsontext.String("protocol_violation")) + case qerr.InvalidToken: + h.WriteToken(jsontext.String("invalid_token")) + case qerr.ApplicationErrorErrorCode: + h.WriteToken(jsontext.String("application_error")) + case qerr.CryptoBufferExceeded: + h.WriteToken(jsontext.String("crypto_buffer_exceeded")) + case qerr.KeyUpdateError: + h.WriteToken(jsontext.String("key_update_error")) + case qerr.AEADLimitReached: + h.WriteToken(jsontext.String("aead_limit_reached")) + case qerr.NoViablePathError: + h.WriteToken(jsontext.String("no_viable_path")) + default: + h.WriteToken(jsontext.String("unknown")) + h.WriteToken(jsontext.String("error_code")) + h.WriteToken(jsontext.Uint(uint64(*e.ConnectionError))) + } } - h.WriteToken(jsontext.String("initiator")) - h.WriteToken(jsontext.String(string(initiator))) - h.WriteToken(jsontext.String("application_code")) - h.WriteToken(jsontext.Uint(uint64(applicationErr.ErrorCode))) + } + if e.ApplicationError != nil { + h.WriteToken(jsontext.String("application_error")) + h.WriteToken(jsontext.String("unknown")) + h.WriteToken(jsontext.String("error_code")) + h.WriteToken(jsontext.Uint(uint64(*e.ApplicationError))) + } + if e.ConnectionError != nil || e.ApplicationError != nil { h.WriteToken(jsontext.String("reason")) - h.WriteToken(jsontext.String(applicationErr.ErrorMessage)) - case errors.As(e.Error, &transportErr): - initiator := InitiatorLocal - if transportErr.Remote { - initiator = InitiatorRemote - } - h.WriteToken(jsontext.String("initiator")) - h.WriteToken(jsontext.String(string(initiator))) - h.WriteToken(jsontext.String("connection_code")) - h.WriteToken(jsontext.String(transportError(transportErr.ErrorCode).String())) - h.WriteToken(jsontext.String("reason")) - h.WriteToken(jsontext.String(transportErr.ErrorMessage)) - case errors.As(e.Error, &versionNegotiationErr): + h.WriteToken(jsontext.String(e.Reason)) + } + if e.Trigger != "" { h.WriteToken(jsontext.String("trigger")) - h.WriteToken(jsontext.String("version_mismatch")) + h.WriteToken(jsontext.String(string(e.Trigger))) } h.WriteToken(jsontext.EndObject) return h.err diff --git a/qlog/event_test.go b/qlog/event_test.go index 479d6cfa6..f14d4cd86 100644 --- a/qlog/event_test.go +++ b/qlog/event_test.go @@ -105,7 +105,8 @@ func TestVersionInformationWithNegotiation(t *testing.T) { func TestIdleTimeouts(t *testing.T) { name, ev := testEventEncoding(t, &ConnectionClosed{ - Error: &qerr.IdleTimeoutError{}, + Initiator: InitiatorLocal, + Trigger: ConnectionCloseTriggerIdleTimeout, }) require.Equal(t, "transport:connection_closed", name) @@ -114,20 +115,10 @@ func TestIdleTimeouts(t *testing.T) { require.Equal(t, "idle_timeout", ev["trigger"]) } -func TestHandshakeTimeouts(t *testing.T) { - name, ev := testEventEncoding(t, &ConnectionClosed{ - Error: &qerr.HandshakeTimeoutError{}, - }) - - require.Equal(t, "transport:connection_closed", name) - require.Len(t, ev, 2) - require.Equal(t, "local", ev["initiator"]) - require.Equal(t, "handshake_timeout", ev["trigger"]) -} - func TestReceivedStatelessResetPacket(t *testing.T) { name, ev := testEventEncoding(t, &ConnectionClosed{ - Error: &qerr.StatelessResetError{}, + Initiator: InitiatorRemote, + Trigger: ConnectionCloseTriggerStatelessReset, }) require.Equal(t, "transport:connection_closed", name) @@ -138,42 +129,85 @@ func TestReceivedStatelessResetPacket(t *testing.T) { func TestVersionNegotiationFailure(t *testing.T) { name, ev := testEventEncoding(t, &ConnectionClosed{ - Error: &qerr.VersionNegotiationError{}, + Initiator: InitiatorLocal, + Trigger: ConnectionCloseTriggerVersionMismatch, }) require.Equal(t, "transport:connection_closed", name) - require.Len(t, ev, 1) + require.Len(t, ev, 2) + require.Equal(t, "local", ev["initiator"]) require.Equal(t, "version_mismatch", ev["trigger"]) } func TestApplicationErrors(t *testing.T) { + code := qerr.ApplicationErrorCode(1337) name, ev := testEventEncoding(t, &ConnectionClosed{ - Error: &qerr.ApplicationError{ - Remote: true, - ErrorCode: 1337, - ErrorMessage: "foobar", - }, + Initiator: InitiatorRemote, + ApplicationError: &code, + Reason: "foobar", }) require.Equal(t, "transport:connection_closed", name) - require.Len(t, ev, 3) + require.Len(t, ev, 4) require.Equal(t, "remote", ev["initiator"]) - require.Equal(t, float64(1337), ev["application_code"]) + require.Equal(t, "unknown", ev["application_error"]) + require.Equal(t, float64(1337), ev["error_code"]) require.Equal(t, "foobar", ev["reason"]) } func TestTransportErrors(t *testing.T) { + tests := []struct { + code qerr.TransportErrorCode + want string + }{ + {qerr.NoError, "no_error"}, + {qerr.InternalError, "internal_error"}, + {qerr.ConnectionRefused, "connection_refused"}, + {qerr.FlowControlError, "flow_control_error"}, + {qerr.StreamLimitError, "stream_limit_error"}, + {qerr.StreamStateError, "stream_state_error"}, + {qerr.FinalSizeError, "final_size_error"}, + {qerr.FrameEncodingError, "frame_encoding_error"}, + {qerr.TransportParameterError, "transport_parameter_error"}, + {qerr.ConnectionIDLimitError, "connection_id_limit_error"}, + {qerr.ProtocolViolation, "protocol_violation"}, + {qerr.InvalidToken, "invalid_token"}, + {qerr.ApplicationErrorErrorCode, "application_error"}, + {qerr.CryptoBufferExceeded, "crypto_buffer_exceeded"}, + {qerr.KeyUpdateError, "key_update_error"}, + {qerr.AEADLimitReached, "aead_limit_reached"}, + {qerr.NoViablePathError, "no_viable_path"}, + } + + for _, tt := range tests { + t.Run(tt.want, func(t *testing.T) { + code := tt.code + name, ev := testEventEncoding(t, &ConnectionClosed{ + Initiator: InitiatorLocal, + ConnectionError: &code, + Reason: "foobar", + }) + + require.Equal(t, "transport:connection_closed", name) + require.Equal(t, "local", ev["initiator"]) + require.Equal(t, tt.want, ev["connection_error"]) + require.Equal(t, "foobar", ev["reason"]) + require.NotContains(t, ev, "error_code") + }) + } +} + +func TestTransportCryptoError(t *testing.T) { + code := qerr.TransportErrorCode(0x100 + 0x2a) name, ev := testEventEncoding(t, &ConnectionClosed{ - Error: &qerr.TransportError{ - ErrorCode: qerr.AEADLimitReached, - ErrorMessage: "foobar", - }, + Initiator: InitiatorLocal, + ConnectionError: &code, + Reason: "foobar", }) require.Equal(t, "transport:connection_closed", name) - require.Len(t, ev, 3) require.Equal(t, "local", ev["initiator"]) - require.Equal(t, "aead_limit_reached", ev["connection_code"]) + require.Equal(t, "crypto_error_0x12a", ev["connection_error"]) require.Equal(t, "foobar", ev["reason"]) } diff --git a/qlog/types.go b/qlog/types.go index 7b6b0d8f2..4cd2bb64c 100644 --- a/qlog/types.go +++ b/qlog/types.go @@ -16,6 +16,8 @@ type ( KeyPhaseBit = protocol.KeyPhaseBit KeyPhase = protocol.KeyPhase StreamID = protocol.StreamID + TransportErrorCode = qerr.TransportErrorCode + ApplicationErrorCode = qerr.ApplicationErrorCode ) const ( @@ -278,3 +280,16 @@ const ( // ECNStateCapable is the capable state ECNStateCapable ECNState = "capable" ) + +type ConnectionCloseTrigger string + +const ( + // IdleTimeout indicates the connection was closed due to idle timeout + ConnectionCloseTriggerIdleTimeout ConnectionCloseTrigger = "idle_timeout" + // Application indicates the connection was closed by the application + ConnectionCloseTriggerApplication ConnectionCloseTrigger = "application" + // VersionMismatch indicates the connection was closed due to a QUIC version mismatch + ConnectionCloseTriggerVersionMismatch ConnectionCloseTrigger = "version_mismatch" + // StatelessReset indicates the connection was closed due to receiving a stateless reset from the peer + ConnectionCloseTriggerStatelessReset ConnectionCloseTrigger = "stateless_reset" +)