add custom logger

fixes #45
This commit is contained in:
Lucas Clemente 2016-05-04 13:20:06 +02:00
parent 40ee20c02b
commit 09fb894fb2
7 changed files with 75 additions and 29 deletions

View file

@ -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
}

View file

@ -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")

View file

@ -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),

View file

@ -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{},

View file

@ -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,

View file

@ -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,

45
utils/log.go Normal file
View file

@ -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...)
}
}