github.com/danielpfeifer02/quic-go-prio-packs@v0.41.0-28/qlog/connection_tracer.go (about)

     1  package qlog
     2  
     3  import (
     4  	"io"
     5  	"net"
     6  	"time"
     7  
     8  	"github.com/danielpfeifer02/quic-go-prio-packs/internal/protocol"
     9  	"github.com/danielpfeifer02/quic-go-prio-packs/internal/utils"
    10  	"github.com/danielpfeifer02/quic-go-prio-packs/internal/wire"
    11  	"github.com/danielpfeifer02/quic-go-prio-packs/logging"
    12  
    13  	"github.com/francoispqt/gojay"
    14  )
    15  
    16  type connectionTracer struct {
    17  	w           writer
    18  	lastMetrics *metrics
    19  
    20  	perspective logging.Perspective
    21  }
    22  
    23  // NewConnectionTracer creates a new tracer to record a qlog for a connection.
    24  func NewConnectionTracer(w io.WriteCloser, p logging.Perspective, odcid protocol.ConnectionID) *logging.ConnectionTracer {
    25  	tr := &trace{
    26  		VantagePoint: vantagePoint{Type: p},
    27  		CommonFields: commonFields{
    28  			ODCID:         odcid,
    29  			GroupID:       odcid,
    30  			ReferenceTime: time.Now(),
    31  		},
    32  	}
    33  	t := connectionTracer{
    34  		w:           *newWriter(w, tr),
    35  		perspective: p,
    36  	}
    37  	go t.w.Run()
    38  	return &logging.ConnectionTracer{
    39  		StartedConnection: func(local, remote net.Addr, srcConnID, destConnID logging.ConnectionID) {
    40  			t.StartedConnection(local, remote, srcConnID, destConnID)
    41  		},
    42  		NegotiatedVersion: func(chosen logging.VersionNumber, clientVersions, serverVersions []logging.VersionNumber) {
    43  			t.NegotiatedVersion(chosen, clientVersions, serverVersions)
    44  		},
    45  		ClosedConnection:            func(e error) { t.ClosedConnection(e) },
    46  		SentTransportParameters:     func(tp *wire.TransportParameters) { t.SentTransportParameters(tp) },
    47  		ReceivedTransportParameters: func(tp *wire.TransportParameters) { t.ReceivedTransportParameters(tp) },
    48  		RestoredTransportParameters: func(tp *wire.TransportParameters) { t.RestoredTransportParameters(tp) },
    49  		SentLongHeaderPacket: func(hdr *logging.ExtendedHeader, size logging.ByteCount, ecn logging.ECN, ack *logging.AckFrame, frames []logging.Frame) {
    50  			t.SentLongHeaderPacket(hdr, size, ecn, ack, frames)
    51  		},
    52  		SentShortHeaderPacket: func(hdr *logging.ShortHeader, size logging.ByteCount, ecn logging.ECN, ack *logging.AckFrame, frames []logging.Frame) {
    53  			t.SentShortHeaderPacket(hdr, size, ecn, ack, frames)
    54  		},
    55  		ReceivedLongHeaderPacket: func(hdr *logging.ExtendedHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) {
    56  			t.ReceivedLongHeaderPacket(hdr, size, ecn, frames)
    57  		},
    58  		ReceivedShortHeaderPacket: func(hdr *logging.ShortHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) {
    59  			t.ReceivedShortHeaderPacket(hdr, size, ecn, frames)
    60  		},
    61  		ReceivedRetry: func(hdr *wire.Header) {
    62  			t.ReceivedRetry(hdr)
    63  		},
    64  		ReceivedVersionNegotiationPacket: func(dest, src logging.ArbitraryLenConnectionID, versions []logging.VersionNumber) {
    65  			t.ReceivedVersionNegotiationPacket(dest, src, versions)
    66  		},
    67  		BufferedPacket: func(pt logging.PacketType, size protocol.ByteCount) {
    68  			t.BufferedPacket(pt, size)
    69  		},
    70  		DroppedPacket: func(pt logging.PacketType, pn logging.PacketNumber, size logging.ByteCount, reason logging.PacketDropReason) {
    71  			t.DroppedPacket(pt, pn, size, reason)
    72  		},
    73  		UpdatedMetrics: func(rttStats *utils.RTTStats, cwnd, bytesInFlight protocol.ByteCount, packetsInFlight int) {
    74  			t.UpdatedMetrics(rttStats, cwnd, bytesInFlight, packetsInFlight)
    75  		},
    76  		LostPacket: func(encLevel protocol.EncryptionLevel, pn protocol.PacketNumber, lossReason logging.PacketLossReason) {
    77  			t.LostPacket(encLevel, pn, lossReason)
    78  		},
    79  		UpdatedCongestionState: func(state logging.CongestionState) {
    80  			t.UpdatedCongestionState(state)
    81  		},
    82  		UpdatedPTOCount: func(value uint32) {
    83  			t.UpdatedPTOCount(value)
    84  		},
    85  		UpdatedKeyFromTLS: func(encLevel protocol.EncryptionLevel, pers protocol.Perspective) {
    86  			t.UpdatedKeyFromTLS(encLevel, pers)
    87  		},
    88  		UpdatedKey: func(keyPhase protocol.KeyPhase, remote bool) {
    89  			t.UpdatedKey(keyPhase, remote)
    90  		},
    91  		DroppedEncryptionLevel: func(encLevel protocol.EncryptionLevel) {
    92  			t.DroppedEncryptionLevel(encLevel)
    93  		},
    94  		DroppedKey: func(keyPhase protocol.KeyPhase) {
    95  			t.DroppedKey(keyPhase)
    96  		},
    97  		SetLossTimer: func(tt logging.TimerType, encLevel protocol.EncryptionLevel, timeout time.Time) {
    98  			t.SetLossTimer(tt, encLevel, timeout)
    99  		},
   100  		LossTimerExpired: func(tt logging.TimerType, encLevel protocol.EncryptionLevel) {
   101  			t.LossTimerExpired(tt, encLevel)
   102  		},
   103  		LossTimerCanceled: func() {
   104  			t.LossTimerCanceled()
   105  		},
   106  		ECNStateUpdated: func(state logging.ECNState, trigger logging.ECNStateTrigger) {
   107  			t.ECNStateUpdated(state, trigger)
   108  		},
   109  		ChoseALPN: func(protocol string) {
   110  			t.recordEvent(time.Now(), eventALPNInformation{chosenALPN: protocol})
   111  		},
   112  		Debug: func(name, msg string) {
   113  			t.Debug(name, msg)
   114  		},
   115  		Close: func() {
   116  			t.Close()
   117  		},
   118  	}
   119  }
   120  
   121  func (t *connectionTracer) recordEvent(eventTime time.Time, details eventDetails) {
   122  	t.w.RecordEvent(eventTime, details)
   123  }
   124  
   125  func (t *connectionTracer) Close() {
   126  	t.w.Close()
   127  }
   128  
   129  func (t *connectionTracer) StartedConnection(local, remote net.Addr, srcConnID, destConnID protocol.ConnectionID) {
   130  	// ignore this event if we're not dealing with UDP addresses here
   131  	localAddr, ok := local.(*net.UDPAddr)
   132  	if !ok {
   133  		return
   134  	}
   135  	remoteAddr, ok := remote.(*net.UDPAddr)
   136  	if !ok {
   137  		return
   138  	}
   139  	t.recordEvent(time.Now(), &eventConnectionStarted{
   140  		SrcAddr:          localAddr,
   141  		DestAddr:         remoteAddr,
   142  		SrcConnectionID:  srcConnID,
   143  		DestConnectionID: destConnID,
   144  	})
   145  }
   146  
   147  func (t *connectionTracer) NegotiatedVersion(chosen logging.VersionNumber, client, server []logging.VersionNumber) {
   148  	var clientVersions, serverVersions []versionNumber
   149  	if len(client) > 0 {
   150  		clientVersions = make([]versionNumber, len(client))
   151  		for i, v := range client {
   152  			clientVersions[i] = versionNumber(v)
   153  		}
   154  	}
   155  	if len(server) > 0 {
   156  		serverVersions = make([]versionNumber, len(server))
   157  		for i, v := range server {
   158  			serverVersions[i] = versionNumber(v)
   159  		}
   160  	}
   161  	t.recordEvent(time.Now(), &eventVersionNegotiated{
   162  		clientVersions: clientVersions,
   163  		serverVersions: serverVersions,
   164  		chosenVersion:  versionNumber(chosen),
   165  	})
   166  }
   167  
   168  func (t *connectionTracer) ClosedConnection(e error) {
   169  	t.recordEvent(time.Now(), &eventConnectionClosed{e: e})
   170  }
   171  
   172  func (t *connectionTracer) SentTransportParameters(tp *wire.TransportParameters) {
   173  	t.recordTransportParameters(t.perspective, tp)
   174  }
   175  
   176  func (t *connectionTracer) ReceivedTransportParameters(tp *wire.TransportParameters) {
   177  	t.recordTransportParameters(t.perspective.Opposite(), tp)
   178  }
   179  
   180  func (t *connectionTracer) RestoredTransportParameters(tp *wire.TransportParameters) {
   181  	ev := t.toTransportParameters(tp)
   182  	ev.Restore = true
   183  
   184  	t.recordEvent(time.Now(), ev)
   185  }
   186  
   187  func (t *connectionTracer) recordTransportParameters(sentBy protocol.Perspective, tp *wire.TransportParameters) {
   188  	ev := t.toTransportParameters(tp)
   189  	ev.Owner = ownerLocal
   190  	if sentBy != t.perspective {
   191  		ev.Owner = ownerRemote
   192  	}
   193  	ev.SentBy = sentBy
   194  
   195  	t.recordEvent(time.Now(), ev)
   196  }
   197  
   198  func (t *connectionTracer) toTransportParameters(tp *wire.TransportParameters) *eventTransportParameters {
   199  	var pa *preferredAddress
   200  	if tp.PreferredAddress != nil {
   201  		pa = &preferredAddress{
   202  			IPv4:                tp.PreferredAddress.IPv4,
   203  			IPv6:                tp.PreferredAddress.IPv6,
   204  			ConnectionID:        tp.PreferredAddress.ConnectionID,
   205  			StatelessResetToken: tp.PreferredAddress.StatelessResetToken,
   206  		}
   207  	}
   208  	return &eventTransportParameters{
   209  		OriginalDestinationConnectionID: tp.OriginalDestinationConnectionID,
   210  		InitialSourceConnectionID:       tp.InitialSourceConnectionID,
   211  		RetrySourceConnectionID:         tp.RetrySourceConnectionID,
   212  		StatelessResetToken:             tp.StatelessResetToken,
   213  		DisableActiveMigration:          tp.DisableActiveMigration,
   214  		MaxIdleTimeout:                  tp.MaxIdleTimeout,
   215  		MaxUDPPayloadSize:               tp.MaxUDPPayloadSize,
   216  		AckDelayExponent:                tp.AckDelayExponent,
   217  		MaxAckDelay:                     tp.MaxAckDelay,
   218  		ActiveConnectionIDLimit:         tp.ActiveConnectionIDLimit,
   219  		InitialMaxData:                  tp.InitialMaxData,
   220  		InitialMaxStreamDataBidiLocal:   tp.InitialMaxStreamDataBidiLocal,
   221  		InitialMaxStreamDataBidiRemote:  tp.InitialMaxStreamDataBidiRemote,
   222  		InitialMaxStreamDataUni:         tp.InitialMaxStreamDataUni,
   223  		InitialMaxStreamsBidi:           int64(tp.MaxBidiStreamNum),
   224  		InitialMaxStreamsUni:            int64(tp.MaxUniStreamNum),
   225  		PreferredAddress:                pa,
   226  		MaxDatagramFrameSize:            tp.MaxDatagramFrameSize,
   227  	}
   228  }
   229  
   230  func (t *connectionTracer) SentLongHeaderPacket(
   231  	hdr *logging.ExtendedHeader,
   232  	size logging.ByteCount,
   233  	ecn logging.ECN,
   234  	ack *logging.AckFrame,
   235  	frames []logging.Frame,
   236  ) {
   237  	t.sentPacket(*transformLongHeader(hdr), size, hdr.Length, ecn, ack, frames)
   238  }
   239  
   240  func (t *connectionTracer) SentShortHeaderPacket(
   241  	hdr *logging.ShortHeader,
   242  	size logging.ByteCount,
   243  	ecn logging.ECN,
   244  	ack *logging.AckFrame,
   245  	frames []logging.Frame,
   246  ) {
   247  	t.sentPacket(*transformShortHeader(hdr), size, 0, ecn, ack, frames)
   248  }
   249  
   250  func (t *connectionTracer) sentPacket(
   251  	hdr gojay.MarshalerJSONObject,
   252  	size, payloadLen logging.ByteCount,
   253  	ecn logging.ECN,
   254  	ack *logging.AckFrame,
   255  	frames []logging.Frame,
   256  ) {
   257  	numFrames := len(frames)
   258  	if ack != nil {
   259  		numFrames++
   260  	}
   261  	fs := make([]frame, 0, numFrames)
   262  	if ack != nil {
   263  		fs = append(fs, frame{Frame: ack})
   264  	}
   265  	for _, f := range frames {
   266  		fs = append(fs, frame{Frame: f})
   267  	}
   268  	t.recordEvent(time.Now(), &eventPacketSent{
   269  		Header:        hdr,
   270  		Length:        size,
   271  		PayloadLength: payloadLen,
   272  		ECN:           ecn,
   273  		Frames:        fs,
   274  	})
   275  }
   276  
   277  func (t *connectionTracer) ReceivedLongHeaderPacket(hdr *logging.ExtendedHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) {
   278  	fs := make([]frame, len(frames))
   279  	for i, f := range frames {
   280  		fs[i] = frame{Frame: f}
   281  	}
   282  	header := *transformLongHeader(hdr)
   283  	t.recordEvent(time.Now(), &eventPacketReceived{
   284  		Header:        header,
   285  		Length:        size,
   286  		PayloadLength: hdr.Length,
   287  		ECN:           ecn,
   288  		Frames:        fs,
   289  	})
   290  }
   291  
   292  func (t *connectionTracer) ReceivedShortHeaderPacket(hdr *logging.ShortHeader, size logging.ByteCount, ecn logging.ECN, frames []logging.Frame) {
   293  	fs := make([]frame, len(frames))
   294  	for i, f := range frames {
   295  		fs[i] = frame{Frame: f}
   296  	}
   297  	header := *transformShortHeader(hdr)
   298  	t.recordEvent(time.Now(), &eventPacketReceived{
   299  		Header:        header,
   300  		Length:        size,
   301  		PayloadLength: size - wire.ShortHeaderLen(hdr.DestConnectionID, hdr.PacketNumberLen),
   302  		ECN:           ecn,
   303  		Frames:        fs,
   304  	})
   305  }
   306  
   307  func (t *connectionTracer) ReceivedRetry(hdr *wire.Header) {
   308  	t.recordEvent(time.Now(), &eventRetryReceived{
   309  		Header: *transformHeader(hdr),
   310  	})
   311  }
   312  
   313  func (t *connectionTracer) ReceivedVersionNegotiationPacket(dest, src logging.ArbitraryLenConnectionID, versions []logging.VersionNumber) {
   314  	ver := make([]versionNumber, len(versions))
   315  	for i, v := range versions {
   316  		ver[i] = versionNumber(v)
   317  	}
   318  	t.recordEvent(time.Now(), &eventVersionNegotiationReceived{
   319  		Header: packetHeaderVersionNegotiation{
   320  			SrcConnectionID:  src,
   321  			DestConnectionID: dest,
   322  		},
   323  		SupportedVersions: ver,
   324  	})
   325  }
   326  
   327  func (t *connectionTracer) BufferedPacket(pt logging.PacketType, size protocol.ByteCount) {
   328  	t.recordEvent(time.Now(), &eventPacketBuffered{
   329  		PacketType: pt,
   330  		PacketSize: size,
   331  	})
   332  }
   333  
   334  func (t *connectionTracer) DroppedPacket(pt logging.PacketType, pn logging.PacketNumber, size protocol.ByteCount, reason logging.PacketDropReason) {
   335  	t.recordEvent(time.Now(), &eventPacketDropped{
   336  		PacketType:   pt,
   337  		PacketNumber: pn,
   338  		PacketSize:   size,
   339  		Trigger:      packetDropReason(reason),
   340  	})
   341  }
   342  
   343  func (t *connectionTracer) UpdatedMetrics(rttStats *utils.RTTStats, cwnd, bytesInFlight protocol.ByteCount, packetsInFlight int) {
   344  	m := &metrics{
   345  		MinRTT:           rttStats.MinRTT(),
   346  		SmoothedRTT:      rttStats.SmoothedRTT(),
   347  		LatestRTT:        rttStats.LatestRTT(),
   348  		RTTVariance:      rttStats.MeanDeviation(),
   349  		CongestionWindow: cwnd,
   350  		BytesInFlight:    bytesInFlight,
   351  		PacketsInFlight:  packetsInFlight,
   352  	}
   353  	t.recordEvent(time.Now(), &eventMetricsUpdated{
   354  		Last:    t.lastMetrics,
   355  		Current: m,
   356  	})
   357  	t.lastMetrics = m
   358  }
   359  
   360  func (t *connectionTracer) AcknowledgedPacket(protocol.EncryptionLevel, protocol.PacketNumber) {}
   361  
   362  func (t *connectionTracer) LostPacket(encLevel protocol.EncryptionLevel, pn protocol.PacketNumber, lossReason logging.PacketLossReason) {
   363  	t.recordEvent(time.Now(), &eventPacketLost{
   364  		PacketType:   getPacketTypeFromEncryptionLevel(encLevel),
   365  		PacketNumber: pn,
   366  		Trigger:      packetLossReason(lossReason),
   367  	})
   368  }
   369  
   370  func (t *connectionTracer) UpdatedCongestionState(state logging.CongestionState) {
   371  	t.recordEvent(time.Now(), &eventCongestionStateUpdated{state: congestionState(state)})
   372  }
   373  
   374  func (t *connectionTracer) UpdatedPTOCount(value uint32) {
   375  	t.recordEvent(time.Now(), &eventUpdatedPTO{Value: value})
   376  }
   377  
   378  func (t *connectionTracer) UpdatedKeyFromTLS(encLevel protocol.EncryptionLevel, pers protocol.Perspective) {
   379  	t.recordEvent(time.Now(), &eventKeyUpdated{
   380  		Trigger: keyUpdateTLS,
   381  		KeyType: encLevelToKeyType(encLevel, pers),
   382  	})
   383  }
   384  
   385  func (t *connectionTracer) UpdatedKey(generation protocol.KeyPhase, remote bool) {
   386  	trigger := keyUpdateLocal
   387  	if remote {
   388  		trigger = keyUpdateRemote
   389  	}
   390  	now := time.Now()
   391  	t.recordEvent(now, &eventKeyUpdated{
   392  		Trigger:  trigger,
   393  		KeyType:  keyTypeClient1RTT,
   394  		KeyPhase: generation,
   395  	})
   396  	t.recordEvent(now, &eventKeyUpdated{
   397  		Trigger:  trigger,
   398  		KeyType:  keyTypeServer1RTT,
   399  		KeyPhase: generation,
   400  	})
   401  }
   402  
   403  func (t *connectionTracer) DroppedEncryptionLevel(encLevel protocol.EncryptionLevel) {
   404  	now := time.Now()
   405  	if encLevel == protocol.Encryption0RTT {
   406  		t.recordEvent(now, &eventKeyDiscarded{KeyType: encLevelToKeyType(encLevel, t.perspective)})
   407  	} else {
   408  		t.recordEvent(now, &eventKeyDiscarded{KeyType: encLevelToKeyType(encLevel, protocol.PerspectiveServer)})
   409  		t.recordEvent(now, &eventKeyDiscarded{KeyType: encLevelToKeyType(encLevel, protocol.PerspectiveClient)})
   410  	}
   411  }
   412  
   413  func (t *connectionTracer) DroppedKey(generation protocol.KeyPhase) {
   414  	now := time.Now()
   415  	t.recordEvent(now, &eventKeyDiscarded{
   416  		KeyType:  encLevelToKeyType(protocol.Encryption1RTT, protocol.PerspectiveServer),
   417  		KeyPhase: generation,
   418  	})
   419  	t.recordEvent(now, &eventKeyDiscarded{
   420  		KeyType:  encLevelToKeyType(protocol.Encryption1RTT, protocol.PerspectiveClient),
   421  		KeyPhase: generation,
   422  	})
   423  }
   424  
   425  func (t *connectionTracer) SetLossTimer(tt logging.TimerType, encLevel protocol.EncryptionLevel, timeout time.Time) {
   426  	now := time.Now()
   427  	t.recordEvent(now, &eventLossTimerSet{
   428  		TimerType: timerType(tt),
   429  		EncLevel:  encLevel,
   430  		Delta:     timeout.Sub(now),
   431  	})
   432  }
   433  
   434  func (t *connectionTracer) LossTimerExpired(tt logging.TimerType, encLevel protocol.EncryptionLevel) {
   435  	t.recordEvent(time.Now(), &eventLossTimerExpired{
   436  		TimerType: timerType(tt),
   437  		EncLevel:  encLevel,
   438  	})
   439  }
   440  
   441  func (t *connectionTracer) LossTimerCanceled() {
   442  	t.recordEvent(time.Now(), &eventLossTimerCanceled{})
   443  }
   444  
   445  func (t *connectionTracer) ECNStateUpdated(state logging.ECNState, trigger logging.ECNStateTrigger) {
   446  	t.recordEvent(time.Now(), &eventECNStateUpdated{state: state, trigger: trigger})
   447  }
   448  
   449  func (t *connectionTracer) Debug(name, msg string) {
   450  	t.recordEvent(time.Now(), &eventGeneric{
   451  		name: name,
   452  		msg:  msg,
   453  	})
   454  }