diff --git a/congestion/rtt_stats.go b/congestion/rtt_stats.go index e538c8b6..3dc89e2f 100644 --- a/congestion/rtt_stats.go +++ b/congestion/rtt_stats.go @@ -1,7 +1,6 @@ package congestion import ( - "fmt" "math" "time" @@ -85,7 +84,7 @@ func (r *RTTStats) SetRecentMinRTTwindow(recentMinRTTwindow time.Duration) { // UpdateRTT updates the RTT based on a new sample. func (r *RTTStats) UpdateRTT(sendDelta, ackDelay time.Duration, now time.Time) { if sendDelta == math.MaxInt64 || sendDelta <= 0 { - fmt.Printf("Ignoring measured sendDelta, because it's is either infinite, zero, or negative: %d\n", sendDelta/time.Microsecond) + utils.Infof("Ignoring measured sendDelta, because it's is either infinite, zero, or negative: %d\n", sendDelta/time.Microsecond) return } diff --git a/example/main.go b/example/main.go index 789b9a1a..eb5bf128 100644 --- a/example/main.go +++ b/example/main.go @@ -9,9 +9,12 @@ import ( "github.com/lucas-clemente/quic-go/h2quic" "github.com/lucas-clemente/quic-go/testdata" + "github.com/lucas-clemente/quic-go/utils" ) func main() { + utils.SetLogLevel(utils.LogLevelDebug) + bindTo := flag.String("bind", "localhost", "bind to") certPath := flag.String("certpath", "", "certificate directory") www := flag.String("www", "/var/www", "www data") diff --git a/h2quic/response_writer.go b/h2quic/response_writer.go index ece09014..7ece2ab2 100644 --- a/h2quic/response_writer.go +++ b/h2quic/response_writer.go @@ -47,7 +47,7 @@ func (w *responseWriter) WriteHeader(status int) { enc.WriteField(hpack.HeaderField{Name: k, Value: v[0]}) } - fmt.Printf("Responding with %d %#v\n", status, w.header) + utils.Infof("Responding with %d %#v\n", status, w.header) h2framer := http2.NewFramer(w.headerStream, nil) err := h2framer.WriteHeaders(http2.HeadersFrameParam{ StreamID: uint32(w.dataStreamID), diff --git a/h2quic/server.go b/h2quic/server.go index 70ec938b..7fd053ab 100644 --- a/h2quic/server.go +++ b/h2quic/server.go @@ -3,7 +3,6 @@ package h2quic import ( "crypto/tls" "errors" - "fmt" "net/http" "github.com/lucas-clemente/quic-go" @@ -49,7 +48,7 @@ func (s *Server) handleStream(session *quic.Session, headerStream utils.Stream) go func() { for { if err := s.handleRequest(session, headerStream, hpackDecoder, h2framer); err != nil { - fmt.Printf("error handling h2 request: %s\n", err.Error()) + utils.Errorf("error handling h2 request: %s\n", err.Error()) return } } @@ -67,7 +66,7 @@ func (s *Server) handleRequest(session *quic.Session, headerStream utils.Stream, } headers, err := hpackDecoder.DecodeFull(h2headersFrame.HeaderBlockFragment()) if err != nil { - fmt.Printf("invalid http2 headers encoding: %s\n", err.Error()) + utils.Errorf("invalid http2 headers encoding: %s\n", err.Error()) return err } @@ -75,7 +74,7 @@ func (s *Server) handleRequest(session *quic.Session, headerStream utils.Stream, if err != nil { return err } - fmt.Printf("Request: %#v\n", req) + utils.Infof("Request: %#v\n", req) responseWriter := &responseWriter{ header: http.Header{}, diff --git a/server.go b/server.go index e16701b9..526d93c8 100644 --- a/server.go +++ b/server.go @@ -4,12 +4,12 @@ import ( "bytes" "crypto/tls" "errors" - "fmt" "net" "github.com/lucas-clemente/quic-go/crypto" "github.com/lucas-clemente/quic-go/handshake" "github.com/lucas-clemente/quic-go/protocol" + "github.com/lucas-clemente/quic-go/utils" ) // PacketHandler handles packets @@ -70,7 +70,7 @@ func (s *Server) ListenAndServe(address string) error { } data = data[:n] if err := s.handlePacket(s.conn, remoteAddr, data); err != nil { - fmt.Printf("error handling packet: %s", err.Error()) + utils.Errorf("error handling packet: %s", err.Error()) } } } @@ -93,7 +93,7 @@ func (s *Server) handlePacket(conn *net.UDPConn, remoteAddr *net.UDPAddr, packet // Send Version Negotiation Packet if the client is speaking a different protocol version if publicHeader.VersionFlag && !protocol.IsSupportedVersion(publicHeader.VersionNumber) { - fmt.Printf("Client offered version %d, sending VersionNegotiationPacket\n", publicHeader.VersionNumber) + utils.Infof("Client offered version %d, sending VersionNegotiationPacket\n", publicHeader.VersionNumber) _, err = conn.WriteToUDP(composeVersionNegotiation(publicHeader.ConnectionID), remoteAddr) if err != nil { return err @@ -103,7 +103,7 @@ func (s *Server) handlePacket(conn *net.UDPConn, remoteAddr *net.UDPAddr, packet session, ok := s.sessions[publicHeader.ConnectionID] if !ok { - fmt.Printf("Serving new connection: %d from %v\n", publicHeader.ConnectionID, remoteAddr) + utils.Infof("Serving new connection: %d from %v\n", publicHeader.ConnectionID, remoteAddr) session = s.newSession( &udpConn{conn: conn, currentAddr: remoteAddr}, publicHeader.VersionNumber, diff --git a/session.go b/session.go index 3fbcdc2a..1c20ac64 100644 --- a/session.go +++ b/session.go @@ -115,7 +115,7 @@ func (s *Session) Run() { case ackhandler.ErrMapAccess: s.Close(err, true) // TODO: sent correct error code here case errRstStreamOnInvalidStream: - fmt.Printf("Ignoring error in session: %s\n", err.Error()) + utils.Errorf("Ignoring error in session: %s\n", err.Error()) default: s.Close(err, true) } @@ -133,7 +133,7 @@ func (s *Session) handlePacket(remoteAddr interface{}, publicHeader *PublicHeade publicHeader.PacketNumber, ) s.lastRcvdPacketNumber = publicHeader.PacketNumber - fmt.Printf("<- Reading packet 0x%x (%d bytes) for connection %x\n", publicHeader.PacketNumber, r.Size(), publicHeader.ConnectionID) + utils.Infof("<- Reading packet 0x%x (%d bytes) for connection %x\n", publicHeader.PacketNumber, r.Size(), publicHeader.ConnectionID) // TODO: Only do this after authenticating s.conn.setCurrentRemoteAddr(remoteAddr) @@ -144,7 +144,7 @@ func (s *Session) handlePacket(remoteAddr interface{}, publicHeader *PublicHeade // instead save them to a queue and retry later. // See issue https://github.com/lucas-clemente/quic-go/issues/38 if qErr, ok := err.(*protocol.QuicError); ok && qErr.ErrorCode == errorcodes.QUIC_DECRYPTION_FAILURE { - fmt.Println("Discarding packet due to decryption failure.") + utils.Infof("Discarding packet due to decryption failure.") return nil // Discard packet } return err @@ -156,31 +156,31 @@ func (s *Session) handlePacket(remoteAddr interface{}, publicHeader *PublicHeade var err error switch frame := ff.(type) { case *frames.StreamFrame: - fmt.Printf("\t<- &frames.StreamFrame{StreamID: %d, FinBit: %t, Offset: %d}\n", frame.StreamID, frame.FinBit, frame.Offset) + utils.Debugf("\t<- &frames.StreamFrame{StreamID: %d, FinBit: %t, Offset: %d}\n", frame.StreamID, frame.FinBit, frame.Offset) err = s.handleStreamFrame(frame) case *frames.AckFrame: var duration time.Duration duration, err = s.sentPacketHandler.ReceivedAck(frame) s.rttStats.UpdateRTT(duration, frame.DelayTime, time.Now()) - fmt.Printf("\t<- %#v\n", frame) - fmt.Printf("\tEstimated RTT: %dms\n", s.rttStats.SmoothedRTT()/time.Millisecond) + utils.Debugf("\t<- %#v\n", frame) + utils.Debugf("\tEstimated RTT: %dms\n", s.rttStats.SmoothedRTT()/time.Millisecond) // ToDo: send right error in ConnectionClose frame case *frames.ConnectionCloseFrame: - fmt.Printf("\t<- %#v\n", frame) + utils.Debugf("\t<- %#v\n", frame) s.Close(nil, false) case *frames.StopWaitingFrame: - fmt.Printf("\t<- %#v\n", frame) + utils.Debugf("\t<- %#v\n", frame) err = s.receivedPacketHandler.ReceivedStopWaiting(frame) case *frames.RstStreamFrame: err = s.handleRstStreamFrame(frame) - fmt.Printf("\t<- %#v\n", frame) + utils.Debugf("\t<- %#v\n", frame) case *frames.WindowUpdateFrame: - fmt.Printf("\t<- %#v\n", frame) + utils.Debugf("\t<- %#v\n", frame) err = s.handleWindowUpdateFrame(frame) case *frames.BlockedFrame: - fmt.Printf("BLOCKED frame received for connection %x stream %d\n", s.connectionID, frame.StreamID) + utils.Infof("BLOCKED frame received for connection %x stream %d\n", s.connectionID, frame.StreamID) case *frames.PingFrame: - fmt.Printf("\t<- %#v\n", frame) + utils.Debugf("\t<- %#v\n", frame) default: panic("unexpected frame type") } @@ -268,7 +268,7 @@ func (s *Session) Close(e error, sendConnectionClose bool) error { if e == nil { e = protocol.NewQuicError(errorcodes.QUIC_PEER_GOING_AWAY, "peer going away") } - fmt.Printf("Closing session with error: %s\n", e.Error()) + utils.Errorf("Closing session with error: %s\n", e.Error()) errorCode := protocol.ErrorCode(1) reasonPhrase := e.Error() quicError, ok := e.(*protocol.QuicError) @@ -311,7 +311,7 @@ func (s *Session) sendPacket() error { // TODO: handle multiple packets retransmissions retransmitPacket := s.sentPacketHandler.DequeuePacketForRetransmission() if retransmitPacket != nil { - fmt.Printf("\tQueueing retransmission for packet 0x%x\n", retransmitPacket.PacketNumber) + utils.Infof("\tQueueing retransmission for packet 0x%x\n", retransmitPacket.PacketNumber) s.stopWaitingManager.RegisterPacketForRetransmission(retransmitPacket) // resend the frames that were in the packet controlFrames = append(controlFrames, retransmitPacket.GetControlFramesForRetransmission()...) @@ -347,12 +347,12 @@ func (s *Session) sendPacket() error { s.stopWaitingManager.SentStopWaitingWithPacket(packet.number) - fmt.Printf("-> Sending packet 0x%x (%d bytes)\n", packet.number, len(packet.raw)) + utils.Infof("-> Sending packet 0x%x (%d bytes)\n", packet.number, len(packet.raw)) for _, frame := range packet.frames { if streamFrame, isStreamFrame := frame.(*frames.StreamFrame); isStreamFrame { - fmt.Printf("\t-> &frames.StreamFrame{StreamID: %d, FinBit: %t, Offset: 0x%x, Data length: 0x%x, Offset + Data length: 0x%x}\n", streamFrame.StreamID, streamFrame.FinBit, streamFrame.Offset, len(streamFrame.Data), streamFrame.Offset+uint64(len(streamFrame.Data))) + utils.Debugf("\t-> &frames.StreamFrame{StreamID: %d, FinBit: %t, Offset: 0x%x, Data length: 0x%x, Offset + Data length: 0x%x}\n", streamFrame.StreamID, streamFrame.FinBit, streamFrame.Offset, len(streamFrame.Data), streamFrame.Offset+uint64(len(streamFrame.Data))) } else { - fmt.Printf("\t-> %#v\n", frame) + utils.Debugf("\t-> %#v\n", frame) } } @@ -399,7 +399,7 @@ func (s *Session) garbageCollectStreams() { } func (s *Session) sendPublicReset(rejectedPacketNumber protocol.PacketNumber) error { - fmt.Printf("Sending public reset for connection %x, packet number %d\n", s.connectionID, rejectedPacketNumber) + utils.Infof("Sending public reset for connection %x, packet number %d\n", s.connectionID, rejectedPacketNumber) packet := &publicResetPacket{ connectionID: s.connectionID, rejectedPacketNumber: rejectedPacketNumber, diff --git a/utils/log.go b/utils/log.go new file mode 100644 index 00000000..d2b483a7 --- /dev/null +++ b/utils/log.go @@ -0,0 +1,45 @@ +package utils + +import "fmt" + +// LogLevel of quic-go +type LogLevel uint8 + +const ( + // LogLevelDebug enables debug logs (e.g. packet contents) + LogLevelDebug LogLevel = iota + // LogLevelInfo enables info logs (e.g. packets) + LogLevelInfo + // LogLevelError enables err logs + LogLevelError + // LogLevelNothing disables + LogLevelNothing +) + +var logLevel = LogLevelNothing + +// SetLogLevel sets the log level +func SetLogLevel(level LogLevel) { + logLevel = level +} + +// Debugf logs something +func Debugf(format string, args ...interface{}) { + if logLevel == LogLevelDebug { + fmt.Printf(format+"\n", args...) + } +} + +// Infof logs something +func Infof(format string, args ...interface{}) { + if logLevel <= LogLevelInfo { + fmt.Printf(format+"\n", args...) + } +} + +// Errorf logs something +func Errorf(format string, args ...interface{}) { + if logLevel <= LogLevelError { + fmt.Printf(format+"\n", args...) + } +}