connection_logging.go 4.9 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168
  1. package quic
  2. import (
  3. "slices"
  4. "github.com/Psiphon-Labs/quic-go/internal/ackhandler"
  5. "github.com/Psiphon-Labs/quic-go/internal/protocol"
  6. "github.com/Psiphon-Labs/quic-go/internal/wire"
  7. "github.com/Psiphon-Labs/quic-go/logging"
  8. )
  9. // ConvertFrame converts a wire.Frame into a logging.Frame.
  10. // This makes it possible for external packages to access the frames.
  11. // Furthermore, it removes the data slices from CRYPTO and STREAM frames.
  12. func toLoggingFrame(frame wire.Frame) logging.Frame {
  13. switch f := frame.(type) {
  14. case *wire.AckFrame:
  15. // We use a pool for ACK frames.
  16. // Implementations of the tracer interface may hold on to frames, so we need to make a copy here.
  17. return toLoggingAckFrame(f)
  18. case *wire.CryptoFrame:
  19. return &logging.CryptoFrame{
  20. Offset: f.Offset,
  21. Length: protocol.ByteCount(len(f.Data)),
  22. }
  23. case *wire.StreamFrame:
  24. return &logging.StreamFrame{
  25. StreamID: f.StreamID,
  26. Offset: f.Offset,
  27. Length: f.DataLen(),
  28. Fin: f.Fin,
  29. }
  30. case *wire.DatagramFrame:
  31. return &logging.DatagramFrame{
  32. Length: logging.ByteCount(len(f.Data)),
  33. }
  34. default:
  35. return logging.Frame(frame)
  36. }
  37. }
  38. func toLoggingAckFrame(f *wire.AckFrame) *logging.AckFrame {
  39. ack := &logging.AckFrame{
  40. AckRanges: slices.Clone(f.AckRanges),
  41. DelayTime: f.DelayTime,
  42. ECNCE: f.ECNCE,
  43. ECT0: f.ECT0,
  44. ECT1: f.ECT1,
  45. }
  46. return ack
  47. }
  48. func (s *connection) logLongHeaderPacket(p *longHeaderPacket, ecn protocol.ECN) {
  49. // quic-go logging
  50. if s.logger.Debug() {
  51. p.header.Log(s.logger)
  52. if p.ack != nil {
  53. wire.LogFrame(s.logger, p.ack, true)
  54. }
  55. for _, frame := range p.frames {
  56. wire.LogFrame(s.logger, frame.Frame, true)
  57. }
  58. for _, frame := range p.streamFrames {
  59. wire.LogFrame(s.logger, frame.Frame, true)
  60. }
  61. }
  62. // tracing
  63. if s.tracer != nil && s.tracer.SentLongHeaderPacket != nil {
  64. frames := make([]logging.Frame, 0, len(p.frames))
  65. for _, f := range p.frames {
  66. frames = append(frames, toLoggingFrame(f.Frame))
  67. }
  68. for _, f := range p.streamFrames {
  69. frames = append(frames, toLoggingFrame(f.Frame))
  70. }
  71. var ack *logging.AckFrame
  72. if p.ack != nil {
  73. ack = toLoggingAckFrame(p.ack)
  74. }
  75. s.tracer.SentLongHeaderPacket(p.header, p.length, ecn, ack, frames)
  76. }
  77. }
  78. func (s *connection) logShortHeaderPacket(
  79. destConnID protocol.ConnectionID,
  80. ackFrame *wire.AckFrame,
  81. frames []ackhandler.Frame,
  82. streamFrames []ackhandler.StreamFrame,
  83. pn protocol.PacketNumber,
  84. pnLen protocol.PacketNumberLen,
  85. kp protocol.KeyPhaseBit,
  86. ecn protocol.ECN,
  87. size protocol.ByteCount,
  88. isCoalesced bool,
  89. ) {
  90. if s.logger.Debug() && !isCoalesced {
  91. s.logger.Debugf("-> Sending packet %d (%d bytes) for connection %s, 1-RTT (ECN: %s)", pn, size, s.logID, ecn)
  92. }
  93. // quic-go logging
  94. if s.logger.Debug() {
  95. wire.LogShortHeader(s.logger, destConnID, pn, pnLen, kp)
  96. if ackFrame != nil {
  97. wire.LogFrame(s.logger, ackFrame, true)
  98. }
  99. for _, f := range frames {
  100. wire.LogFrame(s.logger, f.Frame, true)
  101. }
  102. for _, f := range streamFrames {
  103. wire.LogFrame(s.logger, f.Frame, true)
  104. }
  105. }
  106. // tracing
  107. if s.tracer != nil && s.tracer.SentShortHeaderPacket != nil {
  108. fs := make([]logging.Frame, 0, len(frames)+len(streamFrames))
  109. for _, f := range frames {
  110. fs = append(fs, toLoggingFrame(f.Frame))
  111. }
  112. for _, f := range streamFrames {
  113. fs = append(fs, toLoggingFrame(f.Frame))
  114. }
  115. var ack *logging.AckFrame
  116. if ackFrame != nil {
  117. ack = toLoggingAckFrame(ackFrame)
  118. }
  119. s.tracer.SentShortHeaderPacket(
  120. &logging.ShortHeader{DestConnectionID: destConnID, PacketNumber: pn, PacketNumberLen: pnLen, KeyPhase: kp},
  121. size,
  122. ecn,
  123. ack,
  124. fs,
  125. )
  126. }
  127. }
  128. func (s *connection) logCoalescedPacket(packet *coalescedPacket, ecn protocol.ECN) {
  129. if s.logger.Debug() {
  130. // There's a short period between dropping both Initial and Handshake keys and completion of the handshake,
  131. // during which we might call PackCoalescedPacket but just pack a short header packet.
  132. if len(packet.longHdrPackets) == 0 && packet.shortHdrPacket != nil {
  133. s.logShortHeaderPacket(
  134. packet.shortHdrPacket.DestConnID,
  135. packet.shortHdrPacket.Ack,
  136. packet.shortHdrPacket.Frames,
  137. packet.shortHdrPacket.StreamFrames,
  138. packet.shortHdrPacket.PacketNumber,
  139. packet.shortHdrPacket.PacketNumberLen,
  140. packet.shortHdrPacket.KeyPhase,
  141. ecn,
  142. packet.shortHdrPacket.Length,
  143. false,
  144. )
  145. return
  146. }
  147. if len(packet.longHdrPackets) > 1 {
  148. s.logger.Debugf("-> Sending coalesced packet (%d parts, %d bytes) for connection %s", len(packet.longHdrPackets), packet.buffer.Len(), s.logID)
  149. } else {
  150. s.logger.Debugf("-> Sending packet %d (%d bytes) for connection %s, %s", packet.longHdrPackets[0].header.PacketNumber, packet.buffer.Len(), s.logID, packet.longHdrPackets[0].EncryptionLevel())
  151. }
  152. }
  153. for _, p := range packet.longHdrPackets {
  154. s.logLongHeaderPacket(p, ecn)
  155. }
  156. if p := packet.shortHdrPacket; p != nil {
  157. s.logShortHeaderPacket(p.DestConnID, p.Ack, p.Frames, p.StreamFrames, p.PacketNumber, p.PacketNumberLen, p.KeyPhase, ecn, p.Length, true)
  158. }
  159. }