qlog sent and received transport parameters

This commit is contained in:
Marten Seemann
2020-03-13 16:44:07 +07:00
parent 05ec6d2ea8
commit 99f03d1595
6 changed files with 167 additions and 1 deletions

View File

@@ -1,6 +1,7 @@
package qlog
import (
"fmt"
"net"
"sort"
"time"
@@ -252,3 +253,52 @@ func (e eventKeyRetired) MarshalJSONObject(enc *gojay.Encoder) {
enc.StringKey("trigger", "tls")
enc.StringKey("key_type", e.KeyType.String())
}
type eventTransportParameters struct {
Owner owner
OriginalConnectionID protocol.ConnectionID
StatelessResetToken *[16]byte
DisableActiveMigration bool
MaxIdleTimeout time.Duration
MaxPacketSize protocol.ByteCount
AckDelayExponent uint8
MaxAckDelay time.Duration
ActiveConnectionIDLimit uint64
InitialMaxData protocol.ByteCount
InitialMaxStreamDataBidiLocal protocol.ByteCount
InitialMaxStreamDataBidiRemote protocol.ByteCount
InitialMaxStreamDataUni protocol.ByteCount
InitialMaxStreamsBidi int64
InitialMaxStreamsUni int64
// TODO: add the preferred_address
}
func (e eventTransportParameters) Category() category { return categoryTransport }
func (e eventTransportParameters) Name() string { return "parameters_set" }
func (e eventTransportParameters) IsNil() bool { return false }
func (e eventTransportParameters) MarshalJSONObject(enc *gojay.Encoder) {
enc.StringKey("owner", e.Owner.String())
if e.OriginalConnectionID != nil {
enc.StringKey("original_connection_id", connectionID(e.OriginalConnectionID).String())
}
if e.StatelessResetToken != nil {
enc.StringKey("stateless_reset_token", fmt.Sprintf("%x", e.StatelessResetToken[:]))
}
enc.BoolKey("disable_active_migration", e.DisableActiveMigration)
enc.FloatKeyOmitEmpty("max_idle_timeout", milliseconds(e.MaxIdleTimeout))
enc.Uint64KeyNullEmpty("max_packet_size", uint64(e.MaxPacketSize))
enc.Uint8KeyOmitEmpty("ack_delay_exponent", e.AckDelayExponent)
enc.FloatKeyOmitEmpty("max_ack_delay", milliseconds(e.MaxAckDelay))
enc.Uint64KeyOmitEmpty("active_connection_id_limit", e.ActiveConnectionIDLimit)
enc.Int64KeyOmitEmpty("initial_max_data", int64(e.InitialMaxData))
enc.Int64KeyOmitEmpty("initial_max_stream_data_bidi_local", int64(e.InitialMaxStreamDataBidiLocal))
enc.Int64KeyOmitEmpty("initial_max_stream_data_bidi_remote", int64(e.InitialMaxStreamDataBidiRemote))
enc.Int64KeyOmitEmpty("initial_max_stream_data_uni", int64(e.InitialMaxStreamDataUni))
enc.Int64KeyOmitEmpty("initial_max_streams_bidi", e.InitialMaxStreamsBidi)
enc.Int64KeyOmitEmpty("initial_max_streams_uni", e.InitialMaxStreamsUni)
}

View File

@@ -16,6 +16,8 @@ import (
type Tracer interface {
Export() error
StartedConnection(t time.Time, local, remote net.Addr, version protocol.VersionNumber, srcConnID, destConnID protocol.ConnectionID)
SentTransportParameters(time.Time, *wire.TransportParameters)
ReceivedTransportParameters(time.Time, *wire.TransportParameters)
SentPacket(t time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, ack *wire.AckFrame, frames []wire.Frame)
ReceivedRetry(time.Time, *wire.Header)
ReceivedPacket(t time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, frames []wire.Frame)
@@ -89,6 +91,37 @@ func (t *tracer) StartedConnection(time time.Time, local, remote net.Addr, versi
})
}
func (t *tracer) SentTransportParameters(time time.Time, tp *wire.TransportParameters) {
t.recordTransportParameters(time, ownerLocal, tp)
}
func (t *tracer) ReceivedTransportParameters(time time.Time, tp *wire.TransportParameters) {
t.recordTransportParameters(time, ownerRemote, tp)
}
func (t *tracer) recordTransportParameters(time time.Time, owner owner, tp *wire.TransportParameters) {
t.events = append(t.events, event{
Time: time,
eventDetails: eventTransportParameters{
Owner: owner,
OriginalConnectionID: tp.OriginalConnectionID,
StatelessResetToken: tp.StatelessResetToken,
DisableActiveMigration: tp.DisableActiveMigration,
MaxIdleTimeout: tp.MaxIdleTimeout,
MaxPacketSize: tp.MaxPacketSize,
AckDelayExponent: tp.AckDelayExponent,
MaxAckDelay: tp.MaxAckDelay,
ActiveConnectionIDLimit: tp.ActiveConnectionIDLimit,
InitialMaxData: tp.InitialMaxData,
InitialMaxStreamDataBidiLocal: tp.InitialMaxStreamDataBidiLocal,
InitialMaxStreamDataBidiRemote: tp.InitialMaxStreamDataBidiRemote,
InitialMaxStreamDataUni: tp.InitialMaxStreamDataUni,
InitialMaxStreamsBidi: int64(tp.MaxBidiStreamNum),
InitialMaxStreamsUni: int64(tp.MaxUniStreamNum),
},
})
}
func (t *tracer) SentPacket(time time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, ack *wire.AckFrame, frames []wire.Frame) {
numFrames := len(frames)
if ack != nil {

View File

@@ -125,6 +125,55 @@ var _ = Describe("Tracer", func() {
Expect(ev).To(HaveKeyWithValue("dst_cid", "05060708"))
})
It("records sent transport parameters", func() {
now := time.Now()
tracer.SentTransportParameters(now, &wire.TransportParameters{
InitialMaxStreamDataBidiLocal: 1000,
InitialMaxStreamDataBidiRemote: 2000,
InitialMaxStreamDataUni: 3000,
InitialMaxData: 4000,
MaxBidiStreamNum: 10,
MaxUniStreamNum: 20,
MaxAckDelay: 123 * time.Millisecond,
AckDelayExponent: 12,
DisableActiveMigration: true,
MaxPacketSize: 1234,
MaxIdleTimeout: 321 * time.Millisecond,
StatelessResetToken: &[16]byte{0x11, 0x22, 0x33, 0x44, 0x55, 0x66, 0x77, 0x88, 0x99, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff, 0x00},
OriginalConnectionID: protocol.ConnectionID{0xde, 0xad, 0xc0, 0xde},
ActiveConnectionIDLimit: 7,
})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", now, time.Millisecond))
Expect(entry.Category).To(Equal("transport"))
Expect(entry.Name).To(Equal("parameters_set"))
ev := entry.Event
Expect(ev).To(HaveKeyWithValue("owner", "local"))
Expect(ev).To(HaveKeyWithValue("original_connection_id", "deadc0de"))
Expect(ev).To(HaveKeyWithValue("stateless_reset_token", "112233445566778899aabbccddeeff00"))
Expect(ev).To(HaveKeyWithValue("max_idle_timeout", float64(321)))
Expect(ev).To(HaveKeyWithValue("max_packet_size", float64(1234)))
Expect(ev).To(HaveKeyWithValue("ack_delay_exponent", float64(12)))
Expect(ev).To(HaveKeyWithValue("active_connection_id_limit", float64(7)))
Expect(ev).To(HaveKeyWithValue("initial_max_data", float64(4000)))
Expect(ev).To(HaveKeyWithValue("initial_max_stream_data_bidi_local", float64(1000)))
Expect(ev).To(HaveKeyWithValue("initial_max_stream_data_bidi_remote", float64(2000)))
Expect(ev).To(HaveKeyWithValue("initial_max_stream_data_uni", float64(3000)))
Expect(ev).To(HaveKeyWithValue("initial_max_streams_bidi", float64(10)))
Expect(ev).To(HaveKeyWithValue("initial_max_streams_uni", float64(20)))
})
It("records received transport parameters", func() {
now := time.Now()
tracer.ReceivedTransportParameters(now, &wire.TransportParameters{})
entry := exportAndParseSingle()
Expect(entry.Time).To(BeTemporally("~", now, time.Millisecond))
Expect(entry.Category).To(Equal("transport"))
Expect(entry.Name).To(Equal("parameters_set"))
ev := entry.Event
Expect(ev).To(HaveKeyWithValue("owner", "remote"))
})
It("records a sent packet, without an ACK", func() {
now := time.Now()
tracer.SentPacket(

View File

@@ -6,6 +6,24 @@ import (
"github.com/lucas-clemente/quic-go/internal/protocol"
)
type owner uint8
const (
ownerLocal owner = iota
ownerRemote
)
func (o owner) String() string {
switch o {
case ownerLocal:
return "local"
case ownerRemote:
return "remote"
default:
panic("unknown owner")
}
}
type versionNumber protocol.VersionNumber
func (v versionNumber) String() string {

View File

@@ -7,6 +7,11 @@ import (
)
var _ = Describe("Types", func() {
It("has a string representation for the owner", func() {
Expect(ownerLocal.String()).To(Equal("local"))
Expect(ownerRemote.String()).To(Equal("remote"))
})
It("has a string representation for the category", func() {
Expect(categoryConnectivity.String()).To(Equal("connectivity"))
Expect(categoryTransport.String()).To(Equal("transport"))

View File

@@ -275,6 +275,9 @@ var newSession = func(
OriginalConnectionID: origDestConnID,
ActiveConnectionIDLimit: protocol.MaxActiveConnectionIDs,
}
if s.qlogger != nil {
s.qlogger.SentTransportParameters(time.Now(), params)
}
cs := handshake.NewCryptoSetupServer(
initialStream,
handshakeStream,
@@ -387,6 +390,9 @@ var newClientSession = func(
DisableActiveMigration: true,
ActiveConnectionIDLimit: protocol.MaxActiveConnectionIDs,
}
if s.qlogger != nil {
s.qlogger.SentTransportParameters(time.Now(), params)
}
cs, clientHelloWritten := handshake.NewCryptoSetupClient(
initialStream,
handshakeStream,
@@ -1179,7 +1185,12 @@ func (s *session) processTransportParameters(params *wire.TransportParameters) {
return
}
s.logger.Debugf("Processed Transport Parameters: %s", params)
if s.logger.Debug() {
s.logger.Debugf("Processed Transport Parameters: %s", params)
}
if s.qlogger != nil {
s.qlogger.ReceivedTransportParameters(time.Now(), params)
}
s.peerParams = params
// Our local idle timeout will always be > 0.
s.idleTimeout = utils.MinNonZeroDuration(s.config.MaxIdleTimeout, params.MaxIdleTimeout)