trace dropped packets in the server

internal/mocks/tracer.go

@@ -5,6 +5,7 @@
 package mocks
 
 import (
+	net "net"
 	reflect "reflect"
 
 	gomock "github.com/golang/mock/gomock"
@@ -35,6 +36,18 @@ func (m *MockTracer) EXPECT() *MockTracerMockRecorder {
 	return m.recorder
 }
 
+// DroppedPacket mocks base method
+func (m *MockTracer) DroppedPacket(arg0 net.Addr, arg1 protocol.PacketType, arg2 protocol.ByteCount, arg3 logging.PacketDropReason) {
+	m.ctrl.T.Helper()
+	m.ctrl.Call(m, "DroppedPacket", arg0, arg1, arg2, arg3)
+}
+
+// DroppedPacket indicates an expected call of DroppedPacket
+func (mr *MockTracerMockRecorder) DroppedPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call {
+	mr.mock.ctrl.T.Helper()
+	return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "DroppedPacket", reflect.TypeOf((*MockTracer)(nil).DroppedPacket), arg0, arg1, arg2, arg3)
+}
+
 // TracerForConnection mocks base method
 func (m *MockTracer) TracerForConnection(arg0 protocol.Perspective, arg1 protocol.ConnectionID) logging.ConnectionTracer {
 	m.ctrl.T.Helper()

logging/interface.go

@@ -84,6 +84,8 @@ type Tracer interface {
 	// The destination connection ID that the client used on the first Initial packet it sent on this connection.
 	// If nil is returned, tracing will be disabled for this connection.
 	TracerForConnection(p Perspective, odcid ConnectionID) ConnectionTracer
+
+	DroppedPacket(net.Addr, PacketType, ByteCount, PacketDropReason)
 }
 
 // A ConnectionTracer records events.

logging/mock_tracer_test.go

@@ -7,6 +7,7 @@ package logging
 import (
 	gomock "github.com/golang/mock/gomock"
 	protocol "github.com/lucas-clemente/quic-go/internal/protocol"
+	net "net"
 	reflect "reflect"
 )
 
@@ -33,6 +34,18 @@ func (m *MockTracer) EXPECT() *MockTracerMockRecorder {
 	return m.recorder
 }
 
+// DroppedPacket mocks base method
+func (m *MockTracer) DroppedPacket(arg0 net.Addr, arg1 protocol.PacketType, arg2 protocol.ByteCount, arg3 PacketDropReason) {
+	m.ctrl.T.Helper()
+	m.ctrl.Call(m, "DroppedPacket", arg0, arg1, arg2, arg3)
+}
+
+// DroppedPacket indicates an expected call of DroppedPacket
+func (mr *MockTracerMockRecorder) DroppedPacket(arg0, arg1, arg2, arg3 interface{}) *gomock.Call {
+	mr.mock.ctrl.T.Helper()
+	return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "DroppedPacket", reflect.TypeOf((*MockTracer)(nil).DroppedPacket), arg0, arg1, arg2, arg3)
+}
+
 // TracerForConnection mocks base method
 func (m *MockTracer) TracerForConnection(arg0 protocol.Perspective, arg1 protocol.ConnectionID) ConnectionTracer {
 	m.ctrl.T.Helper()

logging/multiplex.go

@@ -32,6 +32,12 @@ func (m *tracerMultiplexer) TracerForConnection(p Perspective, odcid ConnectionI
 	return newConnectionMultiplexer(connTracers...)
 }
 
+func (m *tracerMultiplexer) DroppedPacket(remote net.Addr, typ PacketType, size ByteCount, reason PacketDropReason) {
+	for _, t := range m.tracers {
+		t.DroppedPacket(remote, typ, size, reason)
+	}
+}
+
 type connTracerMultiplexer struct {
 	tracers []ConnectionTracer
 }

logging/multiplex_test.go

@@ -54,6 +54,13 @@ var _ = Describe("Tracing", func() {
 			tr2.EXPECT().TracerForConnection(PerspectiveClient, ConnectionID{1, 2, 3})
 			Expect(tracer.TracerForConnection(PerspectiveClient, ConnectionID{1, 2, 3})).To(BeNil())
 		})
+
+		It("traces the PacketSent event", func() {
+			remote := &net.UDPAddr{IP: net.IPv4(4, 3, 2, 1)}
+			tr1.EXPECT().DroppedPacket(remote, PacketTypeRetry, ByteCount(1024), PacketDropDuplicate)
+			tr2.EXPECT().DroppedPacket(remote, PacketTypeRetry, ByteCount(1024), PacketDropDuplicate)
+			tracer.DroppedPacket(remote, PacketTypeRetry, 1024, PacketDropDuplicate)
+		})
 	})
 
 	Context("Connection Tracer", func() {

metrics/metrics.go

@@ -65,6 +65,9 @@ func (t *tracer) TracerForConnection(p logging.Perspective, _ logging.Connection
 	return newConnTracer(t, p)
 }
 
+func (t *tracer) DroppedPacket(net.Addr, logging.PacketType, logging.ByteCount, logging.PacketDropReason) {
+}
+
 type connTracer struct {
 	perspective logging.Perspective
 	tracer      logging.Tracer

qlog/qlog.go

@@ -37,6 +37,9 @@ func (t *tracer) TracerForConnection(p logging.Perspective, odcid protocol.Conne
 	return nil
 }
 
+func (t *tracer) DroppedPacket(net.Addr, logging.PacketType, protocol.ByteCount, logging.PacketDropReason) {
+}
+
 type connectionTracer struct {
 	mutex sync.Mutex
 

server.go

@@ -308,6 +308,9 @@ func (s *baseServer) handlePacket(p *receivedPacket) {
 	case s.receivedPackets <- p:
 	default:
 		s.logger.Debugf("Dropping packet from %s (%d bytes). Server receive queue full.", p.remoteAddr, p.Size())
+		if s.config.Tracer != nil {
+			s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeNotDetermined, p.Size(), logging.PacketDropDOSPrevention)
+		}
 	}
 }
 
@@ -316,6 +319,9 @@ func (s *baseServer) handlePacketImpl(p *receivedPacket) bool /* should the buff
 	// The header will then be parsed again.
 	hdr, _, _, err := wire.ParsePacket(p.data, s.config.ConnectionIDLength)
 	if err != nil && err != wire.ErrUnsupportedVersion {
+		if s.config.Tracer != nil {
+			s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeNotDetermined, p.Size(), logging.PacketDropHeaderParseError)
+		}
 		s.logger.Debugf("Error parsing packet: %s", err)
 		return false
 	}
@@ -325,6 +331,9 @@ func (s *baseServer) handlePacketImpl(p *receivedPacket) bool /* should the buff
 	}
 	if hdr.Type == protocol.PacketTypeInitial && p.Size() < protocol.MinInitialPacketSize {
 		s.logger.Debugf("Dropping a packet that is too small to be a valid Initial (%d bytes)", p.Size())
+		if s.config.Tracer != nil {
+			s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeInitial, p.Size(), logging.PacketDropUnexpectedPacket)
+		}
 		return false
 	}
 	// send a Version Negotiation Packet if the client is speaking a different protocol version
@@ -338,9 +347,12 @@ func (s *baseServer) handlePacketImpl(p *receivedPacket) bool /* should the buff
 			return true
 		} else if hdr.Type != protocol.PacketTypeInitial {
 			// Drop long header packets.
-			// There's litte point in sending a Stateless Reset, since the client
+			// There's little point in sending a Stateless Reset, since the client
 			// might not have received the token yet.
 			s.logger.Debugf("Dropping long header packet of type %s (%d bytes)", hdr.Type, len(p.data))
+			if s.config.Tracer != nil {
+				s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeFromHeader(hdr), p.Size(), logging.PacketDropUnexpectedPacket)
+			}
 			return false
 		}
 	}
@@ -358,6 +370,9 @@ func (s *baseServer) handlePacketImpl(p *receivedPacket) bool /* should the buff
 func (s *baseServer) handleInitialImpl(p *receivedPacket, hdr *wire.Header) error {
 	if len(hdr.Token) == 0 && hdr.DestConnectionID.Len() < protocol.MinConnectionIDLenInitial {
 		p.buffer.Release()
+		if s.config.Tracer != nil {
+			s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeInitial, p.Size(), logging.PacketDropUnexpectedPacket)
+		}
 		return errors.New("too short connection ID")
 	}
 
@@ -549,12 +564,18 @@ func (s *baseServer) maybeSendInvalidToken(p *receivedPacket, hdr *wire.Header)
 	data := p.data[:hdr.ParsedLen()+hdr.Length]
 	extHdr, err := unpackHeader(opener, hdr, data, hdr.Version)
 	if err != nil {
+		if s.config.Tracer != nil {
+			s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeInitial, p.Size(), logging.PacketDropHeaderParseError)
+		}
 		// don't return the error here. Just drop the packet.
 		return nil
 	}
 	hdrLen := extHdr.ParsedLen()
 	if _, err := opener.Open(data[hdrLen:hdrLen], data[hdrLen:], extHdr.PacketNumber, data[:hdrLen]); err != nil {
 		// don't return the error here. Just drop the packet.
+		if s.config.Tracer != nil {
+			s.config.Tracer.DroppedPacket(p.remoteAddr, logging.PacketTypeInitial, p.Size(), logging.PacketDropPayloadDecryptError)
+		}
 		return nil
 	}
 	if s.logger.Debug() {

server_test.go

@@ -14,6 +14,8 @@ import (
 	"sync/atomic"
 	"time"
 
+	"github.com/lucas-clemente/quic-go/internal/mocks"
+
 	"github.com/lucas-clemente/quic-go/internal/handshake"
 	"github.com/lucas-clemente/quic-go/internal/protocol"
 	"github.com/lucas-clemente/quic-go/internal/qerr"
@@ -60,8 +62,9 @@ var _ = Describe("Server", func() {
 		data = data[:len(data)+16]
 		sealer.EncryptHeader(data[n:n+16], &data[0], data[n-4:n])
 		return &receivedPacket{
-			data:   data,
+			remoteAddr: &net.UDPAddr{IP: net.IPv4(4, 5, 6, 7), Port: 456},
-			buffer: buffer,
+			data:       data,
+			buffer:     buffer,
 		}
 	}
 
@@ -181,12 +184,14 @@ var _ = Describe("Server", func() {
 
 	Context("server accepting sessions that completed the handshake", func() {
 		var (
-			serv *baseServer
+			serv   *baseServer
-			phm  *MockPacketHandlerManager
+			phm    *MockPacketHandlerManager
+			tracer *mocks.MockTracer
 		)
 
 		BeforeEach(func() {
-			ln, err := Listen(conn, tlsConf, nil)
+			tracer = mocks.NewMockTracer(mockCtrl)
+			ln, err := Listen(conn, tlsConf, &Config{Tracer: tracer})
 			Expect(err).ToNot(HaveOccurred())
 			serv = ln.(*baseServer)
 			phm = NewMockPacketHandlerManager(mockCtrl)
@@ -200,46 +205,39 @@ var _ = Describe("Server", func() {
 
 		Context("handling packets", func() {
 			It("drops Initial packets with a too short connection ID", func() {
-				serv.handlePacket(getPacket(&wire.Header{
+				p := getPacket(&wire.Header{
 					IsLongHeader:     true,
 					Type:             protocol.PacketTypeInitial,
 					DestConnectionID: protocol.ConnectionID{1, 2, 3, 4},
 					Version:          serv.config.Versions[0],
-				}, nil))
+				}, nil)
+				tracer.EXPECT().DroppedPacket(p.remoteAddr, logging.PacketTypeInitial, p.Size(), logging.PacketDropUnexpectedPacket)
+				serv.handlePacket(p)
 				Consistently(conn.dataWritten).ShouldNot(Receive())
 			})
 
 			It("drops too small Initial", func() {
-				serv.handlePacket(getPacket(&wire.Header{
+				p := getPacket(&wire.Header{
 					IsLongHeader:     true,
 					Type:             protocol.PacketTypeInitial,
 					DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8},
 					Version:          serv.config.Versions[0],
 				}, make([]byte, protocol.MinInitialPacketSize-100),
-				))
+				)
-				Consistently(conn.dataWritten).ShouldNot(Receive())
+				tracer.EXPECT().DroppedPacket(p.remoteAddr, logging.PacketTypeInitial, p.Size(), logging.PacketDropUnexpectedPacket)
-			})
+				serv.handlePacket(p)
-
-			It("drops packets with a too short connection ID", func() {
-				serv.handlePacket(getPacket(&wire.Header{
-					IsLongHeader:     true,
-					Type:             protocol.PacketTypeInitial,
-					SrcConnectionID:  protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8},
-					DestConnectionID: protocol.ConnectionID{1, 2, 3, 4},
-					Version:          serv.config.Versions[0],
-				}, make([]byte, protocol.MinInitialPacketSize)))
 				Consistently(conn.dataWritten).ShouldNot(Receive())
 			})
 
 			It("drops non-Initial packets", func() {
-				serv.handlePacket(getPacket(
+				p := getPacket(&wire.Header{
-					&wire.Header{
+					IsLongHeader: true,
-						IsLongHeader: true,
+					Type:         protocol.PacketTypeHandshake,
-						Type:         protocol.PacketTypeHandshake,
+					Version:      serv.config.Versions[0],
-						Version:      serv.config.Versions[0],
+				}, []byte("invalid"))
-					},
+				tracer.EXPECT().DroppedPacket(p.remoteAddr, logging.PacketTypeHandshake, p.Size(), logging.PacketDropUnexpectedPacket)
-					[]byte("invalid"),
+				serv.handlePacket(p)
-				))
+				Consistently(conn.dataWritten).ShouldNot(Receive())
 			})
 
 			It("decodes the token from the Token field", func() {
@@ -321,6 +319,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				})
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, protocol.ConnectionID{0xde, 0xad, 0xc0, 0xde})
 				sess := NewMockQuicSession(mockCtrl)
 				serv.newSession = func(
 					_ connection,
@@ -466,6 +465,7 @@ var _ = Describe("Server", func() {
 				packet := getPacket(hdr, make([]byte, protocol.MinInitialPacketSize))
 				packet.data[len(packet.data)-10] ^= 0xff // corrupt the packet
 				packet.remoteAddr = &net.UDPAddr{IP: net.IPv4(127, 0, 0, 1), Port: 1337}
+				tracer.EXPECT().DroppedPacket(packet.remoteAddr, logging.PacketTypeInitial, packet.Size(), logging.PacketDropPayloadDecryptError)
 				serv.handlePacket(packet)
 				Consistently(conn.dataWritten).ShouldNot(Receive())
 			})
@@ -494,6 +494,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				})
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8, 9, 10})
 
 				sess := NewMockQuicSession(mockCtrl)
 				serv.newSession = func(
@@ -592,6 +593,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				})
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, gomock.Any())
 				Expect(serv.handlePacketImpl(initialPacket)).To(BeTrue())
 				Expect(createdSession).To(BeTrue())
 			})
@@ -602,6 +604,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				}).AnyTimes()
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, gomock.Any()).AnyTimes()
 
 				serv.config.AcceptToken = func(net.Addr, *Token) bool { return true }
 				acceptSession := make(chan struct{})
@@ -633,7 +636,9 @@ var _ = Describe("Server", func() {
 					return sess
 				}
 
-				serv.handlePacket(getInitial(protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}))
+				p := getInitial(protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8})
+				serv.handlePacket(p)
+				tracer.EXPECT().DroppedPacket(p.remoteAddr, logging.PacketTypeNotDetermined, p.Size(), logging.PacketDropDOSPrevention).MinTimes(1)
 				var wg sync.WaitGroup
 				for i := 0; i < 3*protocol.MaxServerUnprocessedPackets; i++ {
 					wg.Add(1)
@@ -719,6 +724,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				}).Times(protocol.MaxAcceptQueueSize)
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, gomock.Any()).Times(protocol.MaxAcceptQueueSize)
 
 				var wg sync.WaitGroup
 				wg.Add(protocol.MaxAcceptQueueSize)
@@ -784,6 +790,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				})
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, gomock.Any())
 
 				serv.handlePacket(p)
 				Consistently(conn.dataWritten).ShouldNot(Receive())
@@ -887,6 +894,7 @@ var _ = Describe("Server", func() {
 					fn()
 					return true
 				})
+				tracer.EXPECT().TracerForConnection(protocol.PerspectiveServer, gomock.Any())
 				serv.createNewSession(&net.UDPAddr{}, nil, nil, nil, nil, nil, protocol.VersionWhatever)
 				Consistently(done).ShouldNot(BeClosed())
 				cancel() // complete the handshake