github.com/TugasAkhir-QUIC/quic-go@v0.0.2-0.20240215011318-d20e25a9054c/qlog/connection_tracer.go (about) 1 package qlog 2 3 import ( 4 "io" 5 "net" 6 "time" 7 8 "github.com/TugasAkhir-QUIC/quic-go/internal/protocol" 9 "github.com/TugasAkhir-QUIC/quic-go/internal/utils" 10 "github.com/TugasAkhir-QUIC/quic-go/internal/wire" 11 "github.com/TugasAkhir-QUIC/quic-go/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 }