mirrors/uquic
1
0
Fork 0
mirror of https://github.com/refraction-networking/uquic.git synced 2025-04-04 12:47:36 +03:00
Code Issues Projects Releases Packages Wiki Activity

use decimal numbers when logging packet numbers

Browse source
This commit is contained in:
Marten Seemann 2020-04-15 15:15:45 +07:00
parent 5bd6252616
commit 140b90449b
7 changed files with 28 additions and 28 deletions
Download patch file Download diff file Expand all files Collapse all files

4
internal/ackhandler/received_packet_tracker.go
View file

@ -68,7 +68,7 @@ func (h *receivedPacketTracker) IgnoreBelow(p protocol.PacketNumber) {
h.ignoreBelow = p
h.packetHistory.DeleteBelow(p)
if h.logger.Debug() {
h.logger.Debugf("\tIgnoring all packets below %#x.", p)
h.logger.Debugf("\tIgnoring all packets below %d.", p)
}
}
@ -106,7 +106,7 @@ func (h *receivedPacketTracker) maybeQueueAck(packetNumber protocol.PacketNumber
// missing packets we reported in the previous ack, send an ACK immediately.
if wasMissing {
if h.logger.Debug() {
h.logger.Debugf("\tQueueing ACK because packet %#x was missing before.", packetNumber)
h.logger.Debugf("\tQueueing ACK because packet %d was missing before.", packetNumber)
}
h.ackQueued = true
}

10
internal/ackhandler/sent_packet_handler.go
View file

@ -213,7 +213,7 @@ func (h *sentPacketHandler) sentPacketImpl(packet *Packet) bool /* is ack-elicit
if h.logger.Debug() && pnSpace.history.HasOutstandingPackets() {
for p := utils.MaxPacketNumber(0, pnSpace.largestSent+1); p < packet.PacketNumber; p++ {
h.logger.Debugf("Skipping packet number %#x", p)
h.logger.Debugf("Skipping packet number %d", p)
}
}
@ -332,7 +332,7 @@ func (h *sentPacketHandler) detectAndRemoveAckedPackets(ack *wire.AckFrame, encL
if p.PacketNumber >= ackRange.Smallest { // packet i contained in ACK range
if p.PacketNumber > ackRange.Largest {
return false, fmt.Errorf("BUG: ackhandler would have acked wrong packet 0x%x, while evaluating range 0x%x -> 0x%x", p.PacketNumber, ackRange.Smallest, ackRange.Largest)
return false, fmt.Errorf("BUG: ackhandler would have acked wrong packet %d, while evaluating range %d -> %d", p.PacketNumber, ackRange.Smallest, ackRange.Largest)
}
ackedPackets = append(ackedPackets, p)
}
@ -346,7 +346,7 @@ func (h *sentPacketHandler) detectAndRemoveAckedPackets(ack *wire.AckFrame, encL
for i, p := range ackedPackets {
pns[i] = p.PacketNumber
}
h.logger.Debugf("\tnewly acked packets (%d): %#x", len(pns), pns)
h.logger.Debugf("\tnewly acked packets (%d): %d", len(pns), pns)
}
for _, p := range ackedPackets {
@ -500,7 +500,7 @@ func (h *sentPacketHandler) detectAndRemoveLostPackets(now time.Time, encLevel p
// Note: This conditional is only entered once per call
lossTime := packet.SendTime.Add(lossDelay)
if h.logger.Debug() {
h.logger.Debugf("\tsetting loss timer for packet %#x (%s) to %s (in %s)", packet.PacketNumber, encLevel, lossDelay, lossTime)
h.logger.Debugf("\tsetting loss timer for packet %d (%s) to %s (in %s)", packet.PacketNumber, encLevel, lossDelay, lossTime)
}
pnSpace.lossTime = lossTime
}
@ -514,7 +514,7 @@ func (h *sentPacketHandler) detectAndRemoveLostPackets(now time.Time, encLevel p
for i, p := range lostPackets {
pns[i] = p.PacketNumber
}
h.logger.Debugf("\tlost packets (%d): %#x", len(pns), pns)
h.logger.Debugf("\tlost packets (%d): %d", len(pns), pns)
}
for _, p := range lostPackets {

4
internal/wire/extended_header.go
View file

@ -226,8 +226,8 @@ func (h *ExtendedHeader) Log(logger utils.Logger) {
return
}
}
logger.Debugf("\tLong Header{Type: %s, DestConnectionID: %s, SrcConnectionID: %s, %sPacketNumber: %#x, PacketNumberLen: %d, Length: %d, Version: %s}", h.Type, h.DestConnectionID, h.SrcConnectionID, token, h.PacketNumber, h.PacketNumberLen, h.Length, h.Version)
logger.Debugf("\tLong Header{Type: %s, DestConnectionID: %s, SrcConnectionID: %s, %sPacketNumber: %d, PacketNumberLen: %d, Length: %d, Version: %s}", h.Type, h.DestConnectionID, h.SrcConnectionID, token, h.PacketNumber, h.PacketNumberLen, h.Length, h.Version)
} else {
logger.Debugf("\tShort Header{DestConnectionID: %s, PacketNumber: %#x, PacketNumberLen: %d, KeyPhase: %s}", h.DestConnectionID, h.PacketNumber, h.PacketNumberLen, h.KeyPhase)
logger.Debugf("\tShort Header{DestConnectionID: %s, PacketNumber: %d, PacketNumberLen: %d, KeyPhase: %s}", h.DestConnectionID, h.PacketNumber, h.PacketNumberLen, h.KeyPhase)
}
}

16
internal/wire/extended_header_test.go
View file

@ -322,10 +322,10 @@ var _ = Describe("Header", func() {
Length: 54321,
Version: 0xfeed,
},
PacketNumber: 0x1337,
PacketNumber: 1337,
PacketNumberLen: protocol.PacketNumberLen2,
}).Log(logger)
Expect(buf.String()).To(ContainSubstring("Long Header{Type: Handshake, DestConnectionID: 0xdeadbeefcafe1337, SrcConnectionID: 0xdecafbad13371337, PacketNumber: 0x1337, PacketNumberLen: 2, Length: 54321, Version: 0xfeed}"))
Expect(buf.String()).To(ContainSubstring("Long Header{Type: Handshake, DestConnectionID: 0xdeadbeefcafe1337, SrcConnectionID: 0xdecafbad13371337, PacketNumber: 1337, PacketNumberLen: 2, Length: 54321, Version: 0xfeed}"))
})
It("logs Initial Packets with a Token", func() {
@ -339,10 +339,10 @@ var _ = Describe("Header", func() {
Length: 100,
Version: 0xfeed,
},
PacketNumber: 0x42,
PacketNumber: 42,
PacketNumberLen: protocol.PacketNumberLen2,
}).Log(logger)
Expect(buf.String()).To(ContainSubstring("Long Header{Type: Initial, DestConnectionID: 0xcafe1337, SrcConnectionID: 0xdecafbad, Token: 0xdeadbeef, PacketNumber: 0x42, PacketNumberLen: 2, Length: 100, Version: 0xfeed}"))
Expect(buf.String()).To(ContainSubstring("Long Header{Type: Initial, DestConnectionID: 0xcafe1337, SrcConnectionID: 0xdecafbad, Token: 0xdeadbeef, PacketNumber: 42, PacketNumberLen: 2, Length: 100, Version: 0xfeed}"))
})
It("logs Initial packets without a Token", func() {
@ -355,10 +355,10 @@ var _ = Describe("Header", func() {
Length: 100,
Version: 0xfeed,
},
PacketNumber: 0x42,
PacketNumber: 42,
PacketNumberLen: protocol.PacketNumberLen2,
}).Log(logger)
Expect(buf.String()).To(ContainSubstring("Long Header{Type: Initial, DestConnectionID: 0xcafe1337, SrcConnectionID: 0xdecafbad, Token: (empty), PacketNumber: 0x42, PacketNumberLen: 2, Length: 100, Version: 0xfeed}"))
Expect(buf.String()).To(ContainSubstring("Long Header{Type: Initial, DestConnectionID: 0xcafe1337, SrcConnectionID: 0xdecafbad, Token: (empty), PacketNumber: 42, PacketNumberLen: 2, Length: 100, Version: 0xfeed}"))
})
It("logs Retry packets with a Token", func() {
@ -381,10 +381,10 @@ var _ = Describe("Header", func() {
DestConnectionID: protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0x13, 0x37},
},
KeyPhase: protocol.KeyPhaseOne,
PacketNumber: 0x1337,
PacketNumber: 1337,
PacketNumberLen: 4,
}).Log(logger)
Expect(buf.String()).To(ContainSubstring("Short Header{DestConnectionID: 0xdeadbeefcafe1337, PacketNumber: 0x1337, PacketNumberLen: 4, KeyPhase: 1}"))
Expect(buf.String()).To(ContainSubstring("Short Header{DestConnectionID: 0xdeadbeefcafe1337, PacketNumber: 1337, PacketNumberLen: 4, KeyPhase: 1}"))
})
})
})

6
internal/wire/log.go
View file

@ -27,11 +27,11 @@ func LogFrame(logger utils.Logger, frame Frame, sent bool) {
if len(f.AckRanges) > 1 {
ackRanges := make([]string, len(f.AckRanges))
for i, r := range f.AckRanges {
ackRanges[i] = fmt.Sprintf("{Largest: %#x, Smallest: %#x}", r.Largest, r.Smallest)
ackRanges[i] = fmt.Sprintf("{Largest: %d, Smallest: %d}", r.Largest, r.Smallest)
}
logger.Debugf("\t%s &wire.AckFrame{LargestAcked: %#x, LowestAcked: %#x, AckRanges: {%s}, DelayTime: %s}", dir, f.LargestAcked(), f.LowestAcked(), strings.Join(ackRanges, ", "), f.DelayTime.String())
logger.Debugf("\t%s &wire.AckFrame{LargestAcked: %d, LowestAcked: %d, AckRanges: {%s}, DelayTime: %s}", dir, f.LargestAcked(), f.LowestAcked(), strings.Join(ackRanges, ", "), f.DelayTime.String())
} else {
logger.Debugf("\t%s &wire.AckFrame{LargestAcked: %#x, LowestAcked: %#x, DelayTime: %s}", dir, f.LargestAcked(), f.LowestAcked(), f.DelayTime.String())
logger.Debugf("\t%s &wire.AckFrame{LargestAcked: %d, LowestAcked: %d, DelayTime: %s}", dir, f.LargestAcked(), f.LowestAcked(), f.DelayTime.String())
}
case *MaxStreamsFrame:
switch f.Type {

10
internal/wire/log_test.go
View file

@ -68,23 +68,23 @@ var _ = Describe("Frame logging", func() {
It("logs ACK frames without missing packets", func() {
frame := &AckFrame{
AckRanges: []AckRange{{Smallest: 0x42, Largest: 0x1337}},
AckRanges: []AckRange{{Smallest: 42, Largest: 1337}},
DelayTime: 1 * time.Millisecond,
}
LogFrame(logger, frame, false)
Expect(buf.String()).To(ContainSubstring("\t<- &wire.AckFrame{LargestAcked: 0x1337, LowestAcked: 0x42, DelayTime: 1ms}\n"))
Expect(buf.String()).To(ContainSubstring("\t<- &wire.AckFrame{LargestAcked: 1337, LowestAcked: 42, DelayTime: 1ms}\n"))
})
It("logs ACK frames with missing packets", func() {
frame := &AckFrame{
AckRanges: []AckRange{
{Smallest: 0x5, Largest: 0x8},
{Smallest: 0x2, Largest: 0x3},
{Smallest: 5, Largest: 8},
{Smallest: 2, Largest: 3},
},
DelayTime: 12 * time.Millisecond,
}
LogFrame(logger, frame, false)
Expect(buf.String()).To(ContainSubstring("\t<- &wire.AckFrame{LargestAcked: 0x8, LowestAcked: 0x2, AckRanges: {{Largest: 0x8, Smallest: 0x5}, {Largest: 0x3, Smallest: 0x2}}, DelayTime: 12ms}\n"))
Expect(buf.String()).To(ContainSubstring("\t<- &wire.AckFrame{LargestAcked: 8, LowestAcked: 2, AckRanges: {{Largest: 8, Smallest: 5}, {Largest: 3, Smallest: 2}}, DelayTime: 12ms}\n"))
})
It("logs MAX_STREAMS frames", func() {

6
session.go
View file

@ -795,7 +795,7 @@ func (s *session) handleSinglePacket(p *receivedPacket, hdr *wire.Header) bool /
}
if s.logger.Debug() {
s.logger.Debugf("<- Reading packet %#x (%d bytes) for connection %s, %s", packet.packetNumber, len(p.data), hdr.DestConnectionID, packet.encryptionLevel)
s.logger.Debugf("<- Reading packet %d (%d bytes) for connection %s, %s", packet.packetNumber, len(p.data), hdr.DestConnectionID, packet.encryptionLevel)
packet.hdr.Log(s.logger)
}
@ -1499,7 +1499,7 @@ func (s *session) logCoalescedPacket(now time.Time, packet *coalescedPacket) {
if len(packet.packets) > 1 {
s.logger.Debugf("-> Sending coalesced packet (%d parts, %d bytes) for connection %s", len(packet.packets), packet.buffer.Len(), s.logID)
} else {
s.logger.Debugf("-> Sending packet %#x (%d bytes) for connection %s, %s", packet.packets[0].header.PacketNumber, packet.buffer.Len(), s.logID, packet.packets[0].EncryptionLevel())
s.logger.Debugf("-> Sending packet %d (%d bytes) for connection %s, %s", packet.packets[0].header.PacketNumber, packet.buffer.Len(), s.logID, packet.packets[0].EncryptionLevel())
}
}
for _, p := range packet.packets {
@ -1509,7 +1509,7 @@ func (s *session) logCoalescedPacket(now time.Time, packet *coalescedPacket) {
func (s *session) logPacket(now time.Time, packet *packedPacket) {
if s.logger.Debug() {
s.logger.Debugf("-> Sending packet %#x (%d bytes) for connection %s, %s", packet.header.PacketNumber, packet.buffer.Len(), s.logID, packet.EncryptionLevel())
s.logger.Debugf("-> Sending packet %d (%d bytes) for connection %s, %s", packet.header.PacketNumber, packet.buffer.Len(), s.logID, packet.EncryptionLevel())
}
s.logPacketContents(now, packet.packetContents)
}