diff --git a/.gitignore b/.gitignore index 5eb300d8..86317213 100644 --- a/.gitignore +++ b/.gitignore @@ -3,6 +3,7 @@ debug.test main mockgen_tmp.go *.qtr +*.qlog fuzzing/*/*.zip fuzzing/*/coverprofile diff --git a/client.go b/client.go index e115acac..f5b668fd 100644 --- a/client.go +++ b/client.go @@ -12,6 +12,7 @@ import ( "github.com/lucas-clemente/quic-go/internal/protocol" "github.com/lucas-clemente/quic-go/internal/utils" "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/qlog" ) type client struct { @@ -176,7 +177,14 @@ func dialContext( return nil, err } c.packetHandlers = packetHandlers - if err := c.dial(ctx); err != nil { + + var qlogger qlog.Tracer + if c.config.GetLogWriter != nil { + if w := c.config.GetLogWriter(c.destConnID); w != nil { + qlogger = qlog.NewTracer(w, protocol.PerspectiveClient, c.destConnID) + } + } + if err := c.dial(ctx, qlogger); err != nil { return nil, err } return c.session, nil @@ -249,7 +257,7 @@ func populateClientConfig(config *Config, createdPacketConn bool) *Config { return config } -func (c *client) dial(ctx context.Context) error { +func (c *client) dial(ctx context.Context, qlogger qlog.Tracer) error { c.logger.Infof("Starting new connection to %s (%s -> %s), source connection ID %s, destination connection ID %s, version %s", c.tlsConf.ServerName, c.conn.LocalAddr(), c.conn.RemoteAddr(), c.srcConnID, c.destConnID, c.version) c.mutex.Lock() @@ -263,6 +271,7 @@ func (c *client) dial(ctx context.Context) error { c.initialPacketNumber, c.initialVersion, c.use0RTT, + qlogger, c.logger, c.version, ) @@ -271,21 +280,7 @@ func (c *client) dial(ctx context.Context) error { // since there's no way to securely communicate it to the server. c.packetHandlers.Add(c.srcConnID, c) - err := c.establishSecureConnection(ctx) - if err == errCloseForRecreating { - return c.dial(ctx) - } - return err -} - -// establishSecureConnection runs the session, and tries to establish a secure connection -// It returns: -// - errCloseForRecreating when the server sends a version negotiation packet -// - any other error that might occur -// - when the connection is forward-secure -func (c *client) establishSecureConnection(ctx context.Context) error { errorChan := make(chan error, 1) - go func() { err := c.session.run() // returns as soon as the session is closed if err != errCloseForRecreating && c.createdPacketConn { @@ -306,6 +301,9 @@ func (c *client) establishSecureConnection(ctx context.Context) error { c.session.shutdown() return ctx.Err() case err := <-errorChan: + if err == errCloseForRecreating { + return c.dial(ctx, qlogger) + } return err case <-earlySessionChan: // ready to send 0-RTT data diff --git a/client_test.go b/client_test.go index eb4866f2..3db99092 100644 --- a/client_test.go +++ b/client_test.go @@ -9,6 +9,8 @@ import ( "os" "time" + "github.com/lucas-clemente/quic-go/qlog" + "github.com/golang/mock/gomock" "github.com/lucas-clemente/quic-go/internal/protocol" "github.com/lucas-clemente/quic-go/internal/utils" @@ -39,6 +41,7 @@ var _ = Describe("Client", func() { initialPacketNumber protocol.PacketNumber, initialVersion protocol.VersionNumber, enable0RTT bool, + qlogger qlog.Tracer, logger utils.Logger, v protocol.VersionNumber, ) quicSession @@ -142,6 +145,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -173,6 +177,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -204,6 +209,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -240,6 +246,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, enable0RTT bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -280,6 +287,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, enable0RTT bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -325,6 +333,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -366,6 +375,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -415,6 +425,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -535,6 +546,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, /* initial version */ _ bool, + _ qlog.Tracer, _ utils.Logger, versionP protocol.VersionNumber, ) quicSession { @@ -584,6 +596,7 @@ var _ = Describe("Client", func() { _ protocol.PacketNumber, _ protocol.VersionNumber, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { diff --git a/config_test.go b/config_test.go index 239c1cb8..e1c86dbf 100644 --- a/config_test.go +++ b/config_test.go @@ -2,6 +2,7 @@ package quic import ( "fmt" + "io" "net" "reflect" "time" @@ -14,11 +15,16 @@ import ( var _ = Describe("Config", func() { It("clones function fields", func() { - var called bool - c1 := &Config{AcceptToken: func(_ net.Addr, _ *Token) bool { called = true; return true }} + var calledAcceptToken, calledGetLogWriter bool + c1 := &Config{ + AcceptToken: func(_ net.Addr, _ *Token) bool { calledAcceptToken = true; return true }, + GetLogWriter: func(connectionID []byte) io.WriteCloser { calledGetLogWriter = true; return nil }, + } c2 := c1.Clone() c2.AcceptToken(&net.UDPAddr{}, &Token{}) - Expect(called).To(BeTrue()) + c2.GetLogWriter([]byte{1, 2, 3}) + Expect(calledAcceptToken).To(BeTrue()) + Expect(calledGetLogWriter).To(BeTrue()) }) It("clones non-function fields", func() { @@ -34,7 +40,7 @@ var _ = Describe("Config", func() { } switch fn := typ.Field(i).Name; fn { - case "AcceptToken": + case "AcceptToken", "GetLogWriter": // Can't compare functions. case "Versions": f.Set(reflect.ValueOf([]VersionNumber{1, 2, 3})) diff --git a/example/client/main.go b/example/client/main.go index 8f2c6a3d..67d59a17 100644 --- a/example/client/main.go +++ b/example/client/main.go @@ -5,12 +5,14 @@ import ( "crypto/tls" "crypto/x509" "flag" + "fmt" "io" "log" "net/http" "os" "sync" + "github.com/lucas-clemente/quic-go" "github.com/lucas-clemente/quic-go/http3" "github.com/lucas-clemente/quic-go/internal/testdata" "github.com/lucas-clemente/quic-go/internal/utils" @@ -21,6 +23,7 @@ func main() { quiet := flag.Bool("q", false, "don't print the data") keyLogFile := flag.String("keylog", "", "key log file") insecure := flag.Bool("insecure", false, "skip certificate verification") + qlog := flag.Bool("qlog", false, "output a qlog (in the same directory)") flag.Parse() urls := flag.Args() @@ -48,12 +51,26 @@ func main() { log.Fatal(err) } testdata.AddRootCA(pool) + + var qconf quic.Config + if *qlog { + qconf.GetLogWriter = func(connID []byte) io.WriteCloser { + filename := fmt.Sprintf("client_%x.qlog", connID) + f, err := os.Create(filename) + if err != nil { + log.Fatal(err) + } + log.Printf("Creating qlog file %s.\n", filename) + return f + } + } roundTripper := &http3.RoundTripper{ TLSClientConfig: &tls.Config{ RootCAs: pool, InsecureSkipVerify: *insecure, KeyLogWriter: keyLog, }, + QuicConfig: &qconf, } defer roundTripper.Close() hclient := &http.Client{ diff --git a/example/main.go b/example/main.go index 6ab47d08..60fe0d71 100644 --- a/example/main.go +++ b/example/main.go @@ -186,6 +186,7 @@ func main() { www := flag.String("www", "", "www data") tcp := flag.Bool("tcp", false, "also listen on TCP") trace := flag.Bool("trace", false, "enable quic-trace") + qlog := flag.Bool("qlog", false, "output a qlog (in the same directory)") flag.Parse() logger := utils.DefaultLogger @@ -202,9 +203,20 @@ func main() { } handler := setupHandler(*www, *trace) - var quicConf *quic.Config + quicConf := &quic.Config{} if *trace { - quicConf = &quic.Config{QuicTracer: tracer} + quicConf.QuicTracer = tracer + } + if *qlog { + quicConf.GetLogWriter = func(connID []byte) io.WriteCloser { + filename := fmt.Sprintf("server_%x.qlog", connID) + f, err := os.Create(filename) + if err != nil { + log.Fatal(err) + } + log.Printf("Creating qlog file %s.\n", filename) + return f + } } var wg sync.WaitGroup diff --git a/go.mod b/go.mod index 0fecb9e7..59da8f9a 100644 --- a/go.mod +++ b/go.mod @@ -5,8 +5,9 @@ go 1.13 require ( github.com/alangpierce/go-forceexport v0.0.0-20160317203124-8f1d6941cd75 github.com/cheekybits/genny v1.0.0 + github.com/francoispqt/gojay v1.2.13 github.com/golang/mock v1.4.0 - github.com/golang/protobuf v1.3.0 + github.com/golang/protobuf v1.3.1 github.com/marten-seemann/chacha20 v0.2.0 github.com/marten-seemann/qpack v0.1.0 github.com/marten-seemann/qtls v0.7.1 diff --git a/go.sum b/go.sum index 3dbadd75..d395e5de 100644 --- a/go.sum +++ b/go.sum @@ -1,22 +1,80 @@ +cloud.google.com/go v0.26.0/go.mod h1:aQUYkXzVsufM+DwF1aE+0xfcU+56JwCaLick0ClmMTw= +cloud.google.com/go v0.31.0/go.mod h1:aQUYkXzVsufM+DwF1aE+0xfcU+56JwCaLick0ClmMTw= +cloud.google.com/go v0.34.0/go.mod h1:aQUYkXzVsufM+DwF1aE+0xfcU+56JwCaLick0ClmMTw= +cloud.google.com/go v0.37.0/go.mod h1:TS1dMSSfndXH133OKGwekG838Om/cQT0BUHV3HcBgoo= +dmitri.shuralyov.com/app/changes v0.0.0-20180602232624-0a106ad413e3/go.mod h1:Yl+fi1br7+Rr3LqpNJf1/uxUdtRUV+Tnj0o93V2B9MU= +dmitri.shuralyov.com/html/belt v0.0.0-20180602232347-f7d459c86be0/go.mod h1:JLBrvjyP0v+ecvNYvCpyZgu5/xkfAUhi6wJj28eUfSU= +dmitri.shuralyov.com/service/change v0.0.0-20181023043359-a85b471d5412/go.mod h1:a1inKt/atXimZ4Mv927x+r7UpyzRUf4emIoiiSC2TN4= +dmitri.shuralyov.com/state v0.0.0-20180228185332-28bcc343414c/go.mod h1:0PRwlb0D6DFvNNtx+9ybjezNCa8XF0xaYcETyp6rHWU= +git.apache.org/thrift.git v0.0.0-20180902110319-2566ecd5d999/go.mod h1:fPE2ZNJGynbRyZ4dJvy6G277gSllfV2HJqblrnkyeyg= +github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU= github.com/alangpierce/go-forceexport v0.0.0-20160317203124-8f1d6941cd75 h1:3ILjVyslFbc4jl1w5TWuvvslFD/nDfR2H8tVaMVLrEY= github.com/alangpierce/go-forceexport v0.0.0-20160317203124-8f1d6941cd75/go.mod h1:uAXEEpARkRhCZfEvy/y0Jcc888f9tHCc1W7/UeEtreE= +github.com/anmitsu/go-shlex v0.0.0-20161002113705-648efa622239/go.mod h1:2FmKhYUyUczH0OGQWaF5ceTx0UBShxjsH6f8oGKYe2c= +github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q= +github.com/bradfitz/go-smtpd v0.0.0-20170404230938-deb6d6237625/go.mod h1:HYsPBTaaSFSlLx/70C2HPIMNZpVV8+vt/A+FMnYP11g= +github.com/buger/jsonparser v0.0.0-20181115193947-bf1c66bbce23/go.mod h1:bbYlZJ7hK1yFx9hf58LP0zeX7UjIGs20ufpu3evjr+s= github.com/cheekybits/genny v1.0.0 h1:uGGa4nei+j20rOSeDeP5Of12XVm7TGUd4dJA9RDitfE= github.com/cheekybits/genny v1.0.0/go.mod h1:+tQajlRqAUrPI7DOSpB0XAqZYtQakVtB7wXkRAgjxjQ= +github.com/client9/misspell v0.3.4/go.mod h1:qj6jICC3Q7zFZvVWo7KLAzC3yx5G7kyvSDkc90ppPyw= +github.com/coreos/go-systemd v0.0.0-20181012123002-c6f51f82210d/go.mod h1:F5haX7vjVVG0kc13fIWeqUViNPyEJxv/OmvnBo0Yme4= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/dustin/go-humanize v1.0.0/go.mod h1:HtrtbFcZ19U5GC7JDqmcUSB87Iq5E25KnS6fMYU6eOk= +github.com/flynn/go-shlex v0.0.0-20150515145356-3f9db97f8568/go.mod h1:xEzjJPgXI435gkrCt3MPfRiAkVrwSbHsst4LCFVfpJc= +github.com/francoispqt/gojay v1.2.13 h1:d2m3sFjloqoIUQU3TsHBgj6qg/BVGlTBeHDUmyJnXKk= +github.com/francoispqt/gojay v1.2.13/go.mod h1:ehT5mTG4ua4581f1++1WLG0vPdaA9HaiDsoyrBGkyDY= github.com/fsnotify/fsnotify v1.4.7 h1:IXs+QLmnXW2CcXuY+8Mzv/fWEsPGWxqefPtCP5CnV9I= github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo= +github.com/ghodss/yaml v1.0.0/go.mod h1:4dBDuWmgqj2HViK6kFavaiC9ZROes6MMH2rRYeMEF04= +github.com/gliderlabs/ssh v0.1.1/go.mod h1:U7qILu1NlMHj9FlMhZLlkCdDnU1DBEAqr0aevW3Awn0= +github.com/go-errors/errors v1.0.1/go.mod h1:f4zRHt4oKfwPJE5k8C9vpYG+aDHdBFUsgrm6/TyX73Q= +github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ= +github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= +github.com/golang/lint v0.0.0-20180702182130-06c8688daad7/go.mod h1:tluoj9z5200jBnyusfRPU2LqT6J+DAorxEvtC7LHB+E= +github.com/golang/mock v1.1.1/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfbm0A= +github.com/golang/mock v1.2.0 h1:28o5sBqPkBsMGnC6b4MvE2TzSr5/AT4c/1fLqVGIwlk= +github.com/golang/mock v1.2.0/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfbm0A= github.com/golang/mock v1.4.0 h1:Rd1kQnQu0Hq3qvJppYSG0HtP+f5LPPUiDswTLiEegLg= github.com/golang/mock v1.4.0/go.mod h1:UOMv5ysSaYNkG+OFQykRIcU/QvvxJf3p21QfJ2Bt3cw= github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U= -github.com/golang/protobuf v1.3.0 h1:kbxbvI4Un1LUWKxufD+BiE6AEExYYgkQLQmLFqA1LFk= -github.com/golang/protobuf v1.3.0/go.mod h1:Qd/q+1AKNOZr9uGQzbzCmRO6sUih6GTPZv6a1/R87v0= +github.com/golang/protobuf v1.3.1 h1:YF8+flBXS5eO826T4nzqPrxfhQThhXl0YzfuUPu4SBg= +github.com/golang/protobuf v1.3.1/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U= +github.com/google/btree v0.0.0-20180813153112-4030bb1f1f0c/go.mod h1:lNA+9X1NB3Zf8V7Ke586lFgjr2dZNuvo3lPJSGZ5JPQ= +github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5aqRK0M= +github.com/google/go-github v17.0.0+incompatible/go.mod h1:zLgOLi98H3fifZn+44m+umXrS52loVEgC2AApnigrVQ= +github.com/google/go-querystring v1.0.0/go.mod h1:odCYkC5MyYFN7vkCjXpyrEuKhc/BUO6wN/zVPAxq5ck= +github.com/google/martian v2.1.0+incompatible/go.mod h1:9I4somxYTbIHy5NJKHRl3wXiIaQGbYVAs8BPL6v8lEs= +github.com/google/pprof v0.0.0-20181206194817-3ea8567a2e57/go.mod h1:zfwlbNMJ+OItoe0UupaVj+oy1omPYYDuagoSzA8v9mc= +github.com/googleapis/gax-go v2.0.0+incompatible/go.mod h1:SFVmujtThgffbyetf+mdk2eWhX2bMyUtNHzFKcPA9HY= +github.com/googleapis/gax-go/v2 v2.0.3/go.mod h1:LLvjysVCY1JZeum8Z6l8qUty8fiNwE08qbEPm1M08qg= +github.com/gopherjs/gopherjs v0.0.0-20181017120253-0766667cb4d1/go.mod h1:wJfORRmW1u3UXTncJ5qlYoELFm8eSnnEO6hX4iZ3EWY= +github.com/gregjones/httpcache v0.0.0-20180305231024-9cad4c3443a7/go.mod h1:FecbI9+v66THATjSRHfNgh1IVFe/9kFxbXtjV0ctIMA= +github.com/grpc-ecosystem/grpc-gateway v1.5.0/go.mod h1:RSKVYQBd5MCa4OVpNdGskqpgL2+G+NZTnrVHpWWfpdw= github.com/hpcloud/tail v1.0.0 h1:nfCOvKYfkgYP8hkirhJocXT2+zOD8yUNjXaWfTlyFKI= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= +github.com/jellevandenhooff/dkim v0.0.0-20150330215556-f50fe3d243e1/go.mod h1:E0B/fFc00Y+Rasa88328GlI/XbtyysCtTHZS8h7IrBU= +github.com/json-iterator/go v1.1.6/go.mod h1:+SdeFBvtyEkXs7REEP0seUULqWtbJapLOCVDaaPEHmU= +github.com/jstemmer/go-junit-report v0.0.0-20190106144839-af01ea7f8024/go.mod h1:6v2b51hI/fHJwM22ozAgKL4VKDeJcHhJFhtBdhmNjmU= +github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck= +github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/pty v1.1.3/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/lunixbochs/vtclean v1.0.0/go.mod h1:pHhQNgMf3btfWnGBVipUOjRYhoOsdGqdm/+2c2E2WMI= +github.com/mailru/easyjson v0.0.0-20190312143242-1de009706dbe/go.mod h1:C1wdFJiN94OJF2b5HbByQZoLdCWB1Yqtg26g4irojpc= github.com/marten-seemann/chacha20 v0.2.0 h1:f40vqzzx+3GdOmzQoItkLX5WLvHgPgyYqFFIO5Gh4hQ= github.com/marten-seemann/chacha20 v0.2.0/go.mod h1:HSdjFau7GzYRj+ahFNwsO3ouVJr1HFkWoEwNDb4TMtE= github.com/marten-seemann/qpack v0.1.0 h1:/0M7lkda/6mus9B8u34Asqm8ZhHAAt9Ho0vniNuVSVg= github.com/marten-seemann/qpack v0.1.0/go.mod h1:LFt1NU/Ptjip0C2CPkhimBz5CGE3WGDAUWqna+CNTrI= github.com/marten-seemann/qtls v0.7.1 h1:+jBCODo2UW86tVlc1HCxAG+ccD51CZquJunNPUsaPQU= github.com/marten-seemann/qtls v0.7.1/go.mod h1:2MdmPXnAOf1oOfu871hbP8oYrClgWsykCQvi0S96jnw= +github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0= +github.com/microcosm-cc/bluemonday v1.0.1/go.mod h1:hsXNsILzKxV+sX77C5b8FSuKF00vh2OMYv+xgHpAMF4= +github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= +github.com/modern-go/reflect2 v1.0.1/go.mod h1:bx2lNnkwVCuqBIxFjflWJWanXIb3RllmbCylyMrvgv0= +github.com/neelance/astrewrite v0.0.0-20160511093645-99348263ae86/go.mod h1:kHJEU3ofeGjhHklVoIGuVj85JJwZ6kWPaJwCIxgnFmo= +github.com/neelance/sourcemap v0.0.0-20151028013722-8c68805598ab/go.mod h1:Qr6/a/Q4r9LP1IltGz7tA7iOK1WonHEYhu1HRBA7ZiM= github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE= github.com/onsi/ginkgo v1.7.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE= github.com/onsi/ginkgo v1.11.0 h1:JAKSXpt1YjtLA7YpPiqO9ss6sNXEsPfSGdwN0UHqzrw= @@ -24,37 +82,139 @@ github.com/onsi/ginkgo v1.11.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+ github.com/onsi/gomega v1.4.3/go.mod h1:ex+gbHU/CVuBBDIJjb2X0qEXbFg53c61hWP/1CpauHY= github.com/onsi/gomega v1.8.1 h1:C5Dqfs/LeauYDX0jJXIe2SWmwCbGzx9yF8C8xy3Lh34= github.com/onsi/gomega v1.8.1/go.mod h1:Ho0h+IUsWyvy1OpqCwxlQ/21gkhVunqlU8fDGcoTdcA= +github.com/openzipkin/zipkin-go v0.1.1/go.mod h1:NtoC/o8u3JlF1lSlyPNswIbeQH9bJTmOf0Erfk+hxe8= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/prometheus/client_golang v0.8.0/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw= +github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= +github.com/prometheus/common v0.0.0-20180801064454-c7de2306084e/go.mod h1:daVV7qP5qjZbuso7PdcryaAu0sAZbrN9i7WWcTMWvro= +github.com/prometheus/procfs v0.0.0-20180725123919-05ee40e3a273/go.mod h1:c3At6R/oaqEKCNdg8wHV1ftS6bRYblBhIjjI8uT2IGk= +github.com/russross/blackfriday v1.5.2/go.mod h1:JO/DiYxRf+HjHt06OyowR9PTA263kcR/rfWxYHBV53g= +github.com/sergi/go-diff v1.0.0/go.mod h1:0CfEIISq7TuYL3j771MWULgwwjU+GofnZX9QAmXWZgo= +github.com/shurcooL/component v0.0.0-20170202220835-f88ec8f54cc4/go.mod h1:XhFIlyj5a1fBNx5aJTbKoIq0mNaPvOagO+HjB3EtxrY= +github.com/shurcooL/events v0.0.0-20181021180414-410e4ca65f48/go.mod h1:5u70Mqkb5O5cxEA8nxTsgrgLehJeAw6Oc4Ab1c/P1HM= +github.com/shurcooL/github_flavored_markdown v0.0.0-20181002035957-2122de532470/go.mod h1:2dOwnU2uBioM+SGy2aZoq1f/Sd1l9OkAeAUvjSyvgU0= +github.com/shurcooL/go v0.0.0-20180423040247-9e1955d9fb6e/go.mod h1:TDJrrUr11Vxrven61rcy3hJMUqaf/CLWYhHNPmT14Lk= +github.com/shurcooL/go-goon v0.0.0-20170922171312-37c2f522c041/go.mod h1:N5mDOmsrJOB+vfqUK+7DmDyjhSLIIBnXo9lvZJj3MWQ= +github.com/shurcooL/gofontwoff v0.0.0-20180329035133-29b52fc0a18d/go.mod h1:05UtEgK5zq39gLST6uB0cf3NEHjETfB4Fgr3Gx5R9Vw= +github.com/shurcooL/gopherjslib v0.0.0-20160914041154-feb6d3990c2c/go.mod h1:8d3azKNyqcHP1GaQE/c6dDgjkgSx2BZ4IoEi4F1reUI= +github.com/shurcooL/highlight_diff v0.0.0-20170515013008-09bb4053de1b/go.mod h1:ZpfEhSmds4ytuByIcDnOLkTHGUI6KNqRNPDLHDk+mUU= +github.com/shurcooL/highlight_go v0.0.0-20181028180052-98c3abbbae20/go.mod h1:UDKB5a1T23gOMUJrI+uSuH0VRDStOiUVSjBTRDVBVag= +github.com/shurcooL/home v0.0.0-20181020052607-80b7ffcb30f9/go.mod h1:+rgNQw2P9ARFAs37qieuu7ohDNQ3gds9msbT2yn85sg= +github.com/shurcooL/htmlg v0.0.0-20170918183704-d01228ac9e50/go.mod h1:zPn1wHpTIePGnXSHpsVPWEktKXHr6+SS6x/IKRb7cpw= +github.com/shurcooL/httperror v0.0.0-20170206035902-86b7830d14cc/go.mod h1:aYMfkZ6DWSJPJ6c4Wwz3QtW22G7mf/PEgaB9k/ik5+Y= +github.com/shurcooL/httpfs v0.0.0-20171119174359-809beceb2371/go.mod h1:ZY1cvUeJuFPAdZ/B6v7RHavJWZn2YPVFQ1OSXhCGOkg= +github.com/shurcooL/httpgzip v0.0.0-20180522190206-b1c53ac65af9/go.mod h1:919LwcH0M7/W4fcZ0/jy0qGght1GIhqyS/EgWGH2j5Q= +github.com/shurcooL/issues v0.0.0-20181008053335-6292fdc1e191/go.mod h1:e2qWDig5bLteJ4fwvDAc2NHzqFEthkqn7aOZAOpj+PQ= +github.com/shurcooL/issuesapp v0.0.0-20180602232740-048589ce2241/go.mod h1:NPpHK2TI7iSaM0buivtFUc9offApnI0Alt/K8hcHy0I= +github.com/shurcooL/notifications v0.0.0-20181007000457-627ab5aea122/go.mod h1:b5uSkrEVM1jQUspwbixRBhaIjIzL2xazXp6kntxYle0= +github.com/shurcooL/octicon v0.0.0-20181028054416-fa4f57f9efb2/go.mod h1:eWdoE5JD4R5UVWDucdOPg1g2fqQRq78IQa9zlOV1vpQ= +github.com/shurcooL/reactions v0.0.0-20181006231557-f2e0b4ca5b82/go.mod h1:TCR1lToEk4d2s07G3XGfz2QrgHXg4RJBvjrOozvoWfk= +github.com/shurcooL/sanitized_anchor_name v0.0.0-20170918181015-86672fcb3f95/go.mod h1:1NzhyTcUVG4SuEtjjoZeVRXNmyL/1OwPU0+IJeTBvfc= +github.com/shurcooL/users v0.0.0-20180125191416-49c67e49c537/go.mod h1:QJTqeLYEDaXHZDBsXlPCDqdhQuJkuw4NOtaxYe3xii4= +github.com/shurcooL/webdavfs v0.0.0-20170829043945-18c3829fa133/go.mod h1:hKmq5kWdCj2z2KEozexVbfEZIWiTjhE0+UjmZgPqehw= +github.com/sourcegraph/annotate v0.0.0-20160123013949-f4cad6c6324d/go.mod h1:UdhH50NIW0fCiwBSr0co2m7BnFLdv4fQTgdqdJTHFeE= +github.com/sourcegraph/syntaxhighlight v0.0.0-20170531221838-bd320f5d308e/go.mod h1:HuIsMU8RRBOtsCgI77wP899iHVBQpCmg4ErYMZB+2IA= +github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1w= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= +github.com/tarm/serial v0.0.0-20180830185346-98f6abe2eb07/go.mod h1:kDXzergiv9cbyO7IOYJZWg1U88JhDg3PB6klq9Hg2pA= +github.com/viant/assertly v0.4.8/go.mod h1:aGifi++jvCrUaklKEKT0BU95igDNaqkvz+49uaYMPRU= +github.com/viant/toolbox v0.24.0/go.mod h1:OxMCG57V0PXuIP2HNQrtJf2CjqdmbrOx5EkMILuUhzM= +go.opencensus.io v0.18.0/go.mod h1:vKdFvxhtzZ9onBp9VKHK8z/sRpBMnKAsufL7wlDrCOA= +go4.org v0.0.0-20180809161055-417644f6feb5/go.mod h1:MkTOUMDaeVYJUOUsaDXIhWPZYa1yOyC1qaOBpL57BhE= +golang.org/x/build v0.0.0-20190111050920-041ab4dc3f9d/go.mod h1:OWs+y06UdEOHN4y+MfF/py+xQ/tYqIWW03b70/CG9Rw= +golang.org/x/crypto v0.0.0-20181030102418-4d3f4d9ffa16/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/crypto v0.0.0-20190313024323-a1f597ede03a/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= golang.org/x/crypto v0.0.0-20190829043050-9756ffdc2472 h1:Gv7RPwsi3eZ2Fgewe3CBsuOebPwO27PoXzRpJPsvSSM= golang.org/x/crypto v0.0.0-20190829043050-9756ffdc2472/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= +golang.org/x/exp v0.0.0-20190121172915-509febef88a4/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA= +golang.org/x/lint v0.0.0-20180702182130-06c8688daad7/go.mod h1:UVdnD1Gm6xHRNCYTkRU2/jEulfH38KcIWyp/GAMgvoE= +golang.org/x/lint v0.0.0-20181026193005-c67002cb31c3/go.mod h1:UVdnD1Gm6xHRNCYTkRU2/jEulfH38KcIWyp/GAMgvoE= +golang.org/x/lint v0.0.0-20190227174305-5b3e6a55c961/go.mod h1:wehouNa3lNwaWXcvxsM5YxQ5yQlVC4a0KAMCusXpPoU= +golang.org/x/net v0.0.0-20180724234803-3673e40ba225/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20180826012351-8a410e7b638d/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20180906233101-161cd47e91fd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20181029044818-c44066c5c816/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20181106065722-10aee1819953/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20190108225652-1e06a53dbb7e/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20190213061140-3a22650c66bd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20190228165749-92fc7df08ae7 h1:Qe/u+eY379X4He4GBMFZYu3pmh1ML5yT1aL1ndNM1zQ= golang.org/x/net v0.0.0-20190228165749-92fc7df08ae7/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190313220215-9f648a60d977/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3 h1:0GoQqolDA55aaLxZyTzK/Y2ePZzZTUrRacwib7cNsYQ= golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/oauth2 v0.0.0-20180821212333-d2e6202438be/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U= +golang.org/x/oauth2 v0.0.0-20181017192945-9dcd33a902f4/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U= +golang.org/x/oauth2 v0.0.0-20181203162652-d668ce993890/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U= +golang.org/x/oauth2 v0.0.0-20190226205417-e64efc72b421/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw= +golang.org/x/perf v0.0.0-20180704124530-6e6d33e29852/go.mod h1:JLpeXjPJfIyPr5TlbXLkXWLhP8nz10XfvxElABhCtcw= +golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f h1:wMNYb4v58l5UBM7MYRLPG6ZhfOqbKu7X5eyFl8ZhKvA= golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20190227155943-e225da77a7e6 h1:bjcUS9ztw9kFmmIxJInhon/0Is3p+EHBKNgquIzo1OI= +golang.org/x/sync v0.0.0-20190227155943-e225da77a7e6/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20190423024810-112230192c58 h1:8gQV6CLnAEikrhgkHFbMAEhagSSnXWGV915qUMm9mrU= golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sys v0.0.0-20180830151530-49385e6e1522/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20180909124046-d0be0721c37e/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20181029174526-d69651ed3497/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190316082340-a2f829d7f35f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20190412213103-97732733099d h1:+R4KGOnez64A81RvjARKc4UT5/tI9ujCIVX+P5KiHuI= golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20190904154756-749cb33beabd h1:DBH9mDw0zluJT/R+nGuV3jWFWLFaHyYZWD4tOT+cjn0= golang.org/x/sys v0.0.0-20190904154756-749cb33beabd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/text v0.0.0-20170915032832-14c0d48ead0c/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.0 h1:g61tztE5qeGQ89tm6NTjjM9VPIm088od1l6aSorWRWg= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/text v0.3.1-0.20180807135948-17ff2d5776d2 h1:z99zHgr7hKfrUcX/KsoJk5FJfjTceCKIp96+biqP4To= +golang.org/x/text v0.3.1-0.20180807135948-17ff2d5776d2/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/time v0.0.0-20180412165947-fbb02b2291d2/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= +golang.org/x/time v0.0.0-20181108054448-85acf8d2951c/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= +golang.org/x/tools v0.0.0-20180828015842-6cd1fcedba52/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/tools v0.0.0-20181030000716-a0a13e073c7b/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/tools v0.0.0-20190114222345-bf090417da8b/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/tools v0.0.0-20190226205152-f727befe758c/go.mod h1:9Yl7xja0Znq3iFh3HoIrodX9oNMXvdceNzlUR8zjMvY= golang.org/x/tools v0.0.0-20190425150028-36563e24a262/go.mod h1:RgjU9mgBXZiqYHBnxXauZ1Gv1EHHAz9KjViQ78xBX0Q= golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7 h1:9zdDQZ7Thm29KFXgAX/+yaf3eVbP7djjWp/dXAppNCc= golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +google.golang.org/api v0.0.0-20180910000450-7ca32eb868bf/go.mod h1:4mhQ8q/RsB7i+udVvVy5NUi08OU8ZlA0gRVgrF7VFY0= +google.golang.org/api v0.0.0-20181030000543-1d582fd0359e/go.mod h1:4mhQ8q/RsB7i+udVvVy5NUi08OU8ZlA0gRVgrF7VFY0= +google.golang.org/api v0.1.0/go.mod h1:UGEZY7KEX120AnNLIHFMKIo4obdJhkp2tPbaPlQx13Y= +google.golang.org/appengine v1.1.0/go.mod h1:EbEs0AVv82hx2wNQdGPgUI5lhzA/G0D9YwlJXL52JkM= +google.golang.org/appengine v1.2.0/go.mod h1:xpcJRLb0r/rnEns0DIKYYv+WjYCduHsrkT7/EB5XEv4= +google.golang.org/appengine v1.3.0/go.mod h1:xpcJRLb0r/rnEns0DIKYYv+WjYCduHsrkT7/EB5XEv4= +google.golang.org/appengine v1.4.0/go.mod h1:xpcJRLb0r/rnEns0DIKYYv+WjYCduHsrkT7/EB5XEv4= +google.golang.org/genproto v0.0.0-20180817151627-c66870c02cf8/go.mod h1:JiN7NxoALGmiZfu7CAH4rXhgtRTLTxftemlI0sWmxmc= google.golang.org/genproto v0.0.0-20180831171423-11092d34479b/go.mod h1:JiN7NxoALGmiZfu7CAH4rXhgtRTLTxftemlI0sWmxmc= +google.golang.org/genproto v0.0.0-20181029155118-b69ba1387ce2/go.mod h1:JiN7NxoALGmiZfu7CAH4rXhgtRTLTxftemlI0sWmxmc= +google.golang.org/genproto v0.0.0-20181202183823-bd91e49a0898/go.mod h1:7Ep/1NZk928CDR8SjdVbjWNpdIf6nzjE3BTgJDr2Atg= +google.golang.org/genproto v0.0.0-20190306203927-b5d61aea6440/go.mod h1:VzzqZJRnGkLBvHegQrXjBqPurQTc5/KpmUdxsrq26oE= +google.golang.org/grpc v1.14.0/go.mod h1:yo6s7OP7yaDglbqo1J04qKzAhqBH6lvTonzMVmEdcZw= +google.golang.org/grpc v1.16.0/go.mod h1:0JHn/cJsOMiMfNA9+DeHDlAU7KAAB5GDlYFpa9MZMio= +google.golang.org/grpc v1.17.0/go.mod h1:6QZJwpn2B+Zp71q/5VxRsJ6NXXVCE5NRUHRo+f3cWCs= +google.golang.org/grpc v1.19.0/go.mod h1:mqu4LbDTu4XGKhr4mRzUsmM4RtVoemTSY81AxZiDr8c= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/fsnotify.v1 v1.4.7 h1:xOHLXZwVvI9hhs+cLKq5+I5onOuwQLhQwiu63xxlHs4= gopkg.in/fsnotify.v1 v1.4.7/go.mod h1:Tz8NjZHkW78fSQdbUxIjBTcgA1z1m8ZHf0WmKUhAMys= +gopkg.in/inf.v0 v0.9.1/go.mod h1:cWUDdTG/fYaXco+Dcufb5Vnc6Gp2YChqWtbxRZE0mXw= gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7 h1:uRGJdciOHaEIrze2W8Q3AKkepLTh2hOroT7a+7czfdQ= gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7/go.mod h1:dt/ZhP58zS4L8KSrWDmTeBkI65Dw0HsyUHuEVlX15mw= gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v2 v2.2.2 h1:ZCJp+EgiOT7lHqUV2J862kp8Qj64Jo6az82+3Td9dZw= +gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v2 v2.2.4 h1:/eiJrUcujPVeJ3xlSWaiNi3uSVmDGBK1pDHUHAnao1I= gopkg.in/yaml.v2 v2.2.4/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +grpc.go4.org v0.0.0-20170609214715-11d0a25b4919/go.mod h1:77eQGdRu53HpSqPFJFmuJdjuHRquDANNeA4x7B8WQ9o= +honnef.co/go/tools v0.0.0-20180728063816-88497007e858/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= +honnef.co/go/tools v0.0.0-20190102054323-c2f93a96b099/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= +honnef.co/go/tools v0.0.0-20190106161140-3f1c8253044a/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= rsc.io/quote/v3 v3.1.0/go.mod h1:yEA65RcK8LyAZtP9Kv3t0HmxON59tX3rD+tICJqUlj0= rsc.io/sampler v1.3.0/go.mod h1:T1hPZKmBbMNahiBKFy5HrXp6adAjACjK9JXDnKaTXpA= +sourcegraph.com/sourcegraph/go-diff v0.5.0/go.mod h1:kuch7UrkMzY0X+p9CRK03kfuPQ2zzQcaEFbx8wA8rck= +sourcegraph.com/sqs/pbtypes v0.0.0-20180604144634-d3ebe8f20ae4/go.mod h1:ketZ/q3QxT9HOBeFhu6RdvsftgpsbFHBF5Cas6cDKZ0= diff --git a/interface.go b/interface.go index 660034f8..d4118dbc 100644 --- a/interface.go +++ b/interface.go @@ -260,6 +260,10 @@ type Config struct { // QUIC Event Tracer. // Warning: Experimental. This API should not be considered stable and will change soon. QuicTracer quictrace.Tracer + // GetLogWriter is used to pass in a writer for the qlog. + // If it is nil, no qlog will be collected and exported. + // If it returns nil, no qlog will be collected and exported for the respective connection. + GetLogWriter func(connectionID []byte) io.WriteCloser } // A Listener for incoming QUIC connections diff --git a/internal/ackhandler/sent_packet_handler.go b/internal/ackhandler/sent_packet_handler.go index 6dcd7254..1bb568ed 100644 --- a/internal/ackhandler/sent_packet_handler.go +++ b/internal/ackhandler/sent_packet_handler.go @@ -10,6 +10,7 @@ import ( "github.com/lucas-clemente/quic-go/internal/qerr" "github.com/lucas-clemente/quic-go/internal/utils" "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/qlog" "github.com/lucas-clemente/quic-go/quictrace" ) @@ -73,7 +74,8 @@ type sentPacketHandler struct { traceCallback func(quictrace.Event) - logger utils.Logger + qlogger qlog.Tracer + logger utils.Logger } // NewSentPacketHandler creates a new sentPacketHandler @@ -81,6 +83,7 @@ func NewSentPacketHandler( initialPacketNumber protocol.PacketNumber, rttStats *congestion.RTTStats, traceCallback func(quictrace.Event), + qlogger qlog.Tracer, logger utils.Logger, ) SentPacketHandler { congestion := congestion.NewCubicSender( @@ -96,6 +99,7 @@ func NewSentPacketHandler( rttStats: rttStats, congestion: congestion, traceCallback: traceCallback, + qlogger: qlogger, logger: logger, } } @@ -209,6 +213,16 @@ func (h *sentPacketHandler) ReceivedAck(ackFrame *wire.AckFrame, withPacketNumbe h.logger.Debugf("\tupdated RTT: %s (σ: %s)", h.rttStats.SmoothedRTT(), h.rttStats.MeanDeviation()) } h.congestion.MaybeExitSlowStart() + if h.qlogger != nil { + packetsInFlight := h.appDataPackets.history.Len() + if h.handshakePackets != nil { + packetsInFlight += h.handshakePackets.history.Len() + } + if h.initialPackets != nil { + packetsInFlight += h.initialPackets.history.Len() + } + h.qlogger.UpdatedMetrics(rcvTime, h.rttStats, h.congestion.GetCongestionWindow(), h.bytesInFlight, packetsInFlight) + } } ackedPackets, err := h.determineNewlyAckedPackets(ackFrame, encLevel) @@ -395,8 +409,16 @@ func (h *sentPacketHandler) detectLostPackets( return false, nil } - if packet.SendTime.Before(lostSendTime) || pnSpace.largestAcked >= packet.PacketNumber+packetThreshold { + if packet.SendTime.Before(lostSendTime) { lostPackets = append(lostPackets, packet) + if h.qlogger != nil { + h.qlogger.LostPacket(now, packet.EncryptionLevel, packet.PacketNumber, qlog.PacketLossTimeThreshold) + } + } else if pnSpace.largestAcked >= packet.PacketNumber+packetThreshold { + lostPackets = append(lostPackets, packet) + if h.qlogger != nil { + h.qlogger.LostPacket(now, packet.EncryptionLevel, packet.PacketNumber, qlog.PacketLossReorderingThreshold) + } } else if pnSpace.lossTime.IsZero() { // Note: This conditional is only entered once per call lossTime := packet.SendTime.Add(lossDelay) diff --git a/internal/ackhandler/sent_packet_handler_test.go b/internal/ackhandler/sent_packet_handler_test.go index 04483f85..e1f60953 100644 --- a/internal/ackhandler/sent_packet_handler_test.go +++ b/internal/ackhandler/sent_packet_handler_test.go @@ -24,7 +24,7 @@ var _ = Describe("SentPacketHandler", func() { BeforeEach(func() { lostPackets = nil rttStats := &congestion.RTTStats{} - handler = NewSentPacketHandler(42, rttStats, nil, utils.DefaultLogger).(*sentPacketHandler) + handler = NewSentPacketHandler(42, rttStats, nil, nil, utils.DefaultLogger).(*sentPacketHandler) streamFrame = wire.StreamFrame{ StreamID: 5, Data: []byte{0x13, 0x37}, diff --git a/packet_packer.go b/packet_packer.go index b3cb82a0..cf010b88 100644 --- a/packet_packer.go +++ b/packet_packer.go @@ -63,7 +63,7 @@ func (p *packedPacket) IsAckEliciting() bool { return ackhandler.HasAckElicitingFrames(p.frames) } -func (p *packedPacket) ToAckHandlerPacket(q *retransmissionQueue) *ackhandler.Packet { +func (p *packedPacket) ToAckHandlerPacket(now time.Time, q *retransmissionQueue) *ackhandler.Packet { largestAcked := protocol.InvalidPacketNumber if p.ack != nil { largestAcked = p.ack.LargestAcked() @@ -88,7 +88,7 @@ func (p *packedPacket) ToAckHandlerPacket(q *retransmissionQueue) *ackhandler.Pa Frames: p.frames, Length: protocol.ByteCount(len(p.raw)), EncryptionLevel: encLevel, - SendTime: time.Now(), + SendTime: now, } } diff --git a/packet_packer_test.go b/packet_packer_test.go index c4bb50c4..547c0640 100644 --- a/packet_packer_test.go +++ b/packet_packer_test.go @@ -830,11 +830,12 @@ var _ = Describe("Converting to AckHandler packets", func() { ack: &wire.AckFrame{AckRanges: []wire.AckRange{{Largest: 100, Smallest: 80}}}, raw: []byte("foobar"), } - p := packet.ToAckHandlerPacket(nil) + t := time.Now() + p := packet.ToAckHandlerPacket(t, nil) Expect(p.Length).To(Equal(protocol.ByteCount(6))) Expect(p.Frames).To(Equal(packet.frames)) Expect(p.LargestAcked).To(Equal(protocol.PacketNumber(100))) - Expect(p.SendTime).To(BeTemporally("~", time.Now(), 50*time.Millisecond)) + Expect(p.SendTime).To(Equal(t)) }) It("sets the LargestAcked to invalid, if the packet doesn't have an ACK frame", func() { @@ -843,7 +844,7 @@ var _ = Describe("Converting to AckHandler packets", func() { frames: []ackhandler.Frame{{Frame: &wire.MaxDataFrame{}}, {Frame: &wire.PingFrame{}}}, raw: []byte("foobar"), } - p := packet.ToAckHandlerPacket(nil) + p := packet.ToAckHandlerPacket(time.Now(), nil) Expect(p.LargestAcked).To(Equal(protocol.InvalidPacketNumber)) }) @@ -857,7 +858,7 @@ var _ = Describe("Converting to AckHandler packets", func() { }, raw: []byte("foobar"), } - p := packet.ToAckHandlerPacket(newRetransmissionQueue(protocol.VersionTLS)) + p := packet.ToAckHandlerPacket(time.Now(), newRetransmissionQueue(protocol.VersionTLS)) Expect(p.Frames).To(HaveLen(2)) Expect(p.Frames[0].OnLost).ToNot(BeNil()) p.Frames[1].OnLost(nil) diff --git a/qlog/event.go b/qlog/event.go new file mode 100644 index 00000000..3c67a382 --- /dev/null +++ b/qlog/event.go @@ -0,0 +1,161 @@ +package qlog + +import ( + "sort" + "time" + + "github.com/lucas-clemente/quic-go/internal/protocol" + + "github.com/francoispqt/gojay" +) + +var eventFields = [4]string{"time", "category", "event", "data"} + +type events []event + +var _ sort.Interface = &events{} +var _ gojay.MarshalerJSONArray = events{} + +func (e events) IsNil() bool { return e == nil } +func (e events) Len() int { return len(e) } +func (e events) Less(i, j int) bool { + // Don't use time.Before() here. + // Before() uses monotonic time. + // We need to make sure that the actual exported timestamp are sorted. + return e[i].Time.UnixNano() < e[j].Time.UnixNano() +} +func (e events) Swap(i, j int) { e[i], e[j] = e[j], e[i] } + +func (e events) MarshalJSONArray(enc *gojay.Encoder) { + // Event timestamps are taken from multiple go routines. + // For example, the receiving go routine sets the receive time of the packet. + // Therefore, events can end up being slightly out of order. + // It turns out that Go's stable sort implementation is a lot faster in that case. + // See https://gist.github.com/marten-seemann/30251742b378318097e5400ea170c00f for benchmarking code. + sort.Stable(e) + for _, ev := range e { + enc.Array(ev) + } +} + +type eventDetails interface { + Category() category + Name() string + gojay.MarshalerJSONObject +} + +type event struct { + Time time.Time + eventDetails +} + +var _ gojay.MarshalerJSONArray = event{} + +func (e event) IsNil() bool { return false } +func (e event) MarshalJSONArray(enc *gojay.Encoder) { + enc.Float64(float64(e.Time.UnixNano()) / 1e6) + enc.String(e.Category().String()) + enc.String(e.Name()) + enc.Object(e.eventDetails) +} + +type eventPacketSent struct { + PacketType packetType + Header packetHeader + Frames frames + IsCoalesced bool + Trigger string +} + +var _ eventDetails = eventPacketSent{} + +func (e eventPacketSent) Category() category { return categoryTransport } +func (e eventPacketSent) Name() string { return "packet_sent" } +func (e eventPacketSent) IsNil() bool { return false } + +func (e eventPacketSent) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("packet_type", e.PacketType.String()) + enc.ObjectKey("header", e.Header) + enc.ArrayKeyOmitEmpty("frames", e.Frames) + enc.BoolKeyOmitEmpty("is_coalesced", e.IsCoalesced) + enc.StringKeyOmitEmpty("trigger", e.Trigger) +} + +type eventPacketReceived struct { + PacketType packetType + Header packetHeader + Frames frames + IsCoalesced bool + Trigger string +} + +var _ eventDetails = eventPacketReceived{} + +func (e eventPacketReceived) Category() category { return categoryTransport } +func (e eventPacketReceived) Name() string { return "packet_received" } +func (e eventPacketReceived) IsNil() bool { return false } + +func (e eventPacketReceived) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("packet_type", e.PacketType.String()) + enc.ObjectKey("header", e.Header) + enc.ArrayKeyOmitEmpty("frames", e.Frames) + enc.BoolKeyOmitEmpty("is_coalesced", e.IsCoalesced) + enc.StringKeyOmitEmpty("trigger", e.Trigger) +} + +type eventRetryReceived struct { + Header packetHeader +} + +func (e eventRetryReceived) Category() category { return categoryTransport } +func (e eventRetryReceived) Name() string { return "packet_received" } +func (e eventRetryReceived) IsNil() bool { return false } + +func (e eventRetryReceived) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("packet_type", packetTypeRetry.String()) + enc.ObjectKey("header", e.Header) +} + +func milliseconds(dur time.Duration) float64 { return float64(dur.Nanoseconds()) / 1e6 } + +type eventMetricsUpdated struct { + MinRTT time.Duration + SmoothedRTT time.Duration + LatestRTT time.Duration + RTTVariance time.Duration + + CongestionWindow protocol.ByteCount + BytesInFlight protocol.ByteCount + PacketsInFlight int +} + +func (e eventMetricsUpdated) Category() category { return categoryRecovery } +func (e eventMetricsUpdated) Name() string { return "metrics_updated" } +func (e eventMetricsUpdated) IsNil() bool { return false } + +func (e eventMetricsUpdated) MarshalJSONObject(enc *gojay.Encoder) { + enc.FloatKey("min_rtt", milliseconds(e.MinRTT)) + enc.FloatKey("smoothed_rtt", milliseconds(e.SmoothedRTT)) + enc.FloatKey("latest_rtt", milliseconds(e.LatestRTT)) + enc.FloatKey("rtt_variance", milliseconds(e.RTTVariance)) + + enc.Uint64Key("congestion_window", uint64(e.CongestionWindow)) + enc.Uint64Key("bytes_in_flight", uint64(e.BytesInFlight)) + enc.Uint64KeyOmitEmpty("packets_in_flight", uint64(e.PacketsInFlight)) +} + +type eventPacketLost struct { + PacketType packetType + PacketNumber protocol.PacketNumber + Trigger PacketLossReason +} + +func (e eventPacketLost) Category() category { return categoryRecovery } +func (e eventPacketLost) Name() string { return "packet_lost" } +func (e eventPacketLost) IsNil() bool { return false } + +func (e eventPacketLost) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("packet_type", e.PacketType.String()) + enc.StringKey("packet_number", toString(int64(e.PacketNumber))) + enc.StringKey("trigger", e.Trigger.String()) +} diff --git a/qlog/event_test.go b/qlog/event_test.go new file mode 100644 index 00000000..4a15f502 --- /dev/null +++ b/qlog/event_test.go @@ -0,0 +1,73 @@ +package qlog + +import ( + "bytes" + "encoding/json" + "time" + + "github.com/francoispqt/gojay" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +type mevent struct{} + +var _ eventDetails = mevent{} + +func (mevent) Category() category { return categoryConnectivity } +func (mevent) Name() string { return "mevent" } +func (mevent) IsNil() bool { return false } +func (mevent) MarshalJSONObject(enc *gojay.Encoder) { enc.StringKey("event", "details") } + +var _ = Describe("Events", func() { + It("marshals the fields before the event details", func() { + now := time.Now() + + buf := &bytes.Buffer{} + enc := gojay.NewEncoder(buf) + Expect(enc.Encode(event{ + Time: now, + eventDetails: mevent{}, + })).To(Succeed()) + + var decoded []interface{} + Expect(json.Unmarshal(buf.Bytes(), &decoded)).To(Succeed()) + Expect(decoded).To(HaveLen(4)) + + // 1st field + Expect(eventFields[0]).To(Equal("time")) + Expect(time.Unix(0, int64(1e6*decoded[0].(float64)))).To(BeTemporally("~", now, 2*time.Microsecond)) + + // 2nd field + Expect(eventFields[1]).To(Equal("category")) + Expect(decoded[1].(string)).To(Equal(categoryConnectivity.String())) + + // 3rd field + Expect(eventFields[2]).To(Equal("event")) + Expect(decoded[2].(string)).To(Equal("mevent")) + + // 4th field + Expect(eventFields[3]).To(Equal("data")) + Expect(decoded[3].(map[string]interface{})["event"]).To(Equal("details")) + }) + + It("sorts events", func() { + now := time.Now() + ev := events{ + event{Time: now.Add(time.Minute), eventDetails: mevent{}}, + event{Time: now, eventDetails: mevent{}}, + } + + buf := &bytes.Buffer{} + enc := gojay.NewEncoder(buf) + Expect(enc.Encode(ev)).To(Succeed()) + var decoded []interface{} + Expect(json.Unmarshal(buf.Bytes(), &decoded)).To(Succeed()) + Expect(decoded).To(HaveLen(2)) + t1 := time.Unix(0, int64(decoded[0].([]interface{})[0].(float64)*1e6)) + t2 := time.Unix(0, int64(decoded[1].([]interface{})[0].(float64)*1e6)) + Expect(t1).To(BeTemporally("~", now, time.Millisecond)) + Expect(t2).To(BeTemporally("~", now.Add(time.Minute), time.Millisecond)) + }) +}) diff --git a/qlog/frame.go b/qlog/frame.go new file mode 100644 index 00000000..b76a48f5 --- /dev/null +++ b/qlog/frame.go @@ -0,0 +1,248 @@ +package qlog + +import ( + "fmt" + + "github.com/francoispqt/gojay" + + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" +) + +type frame struct { + Frame interface{} +} + +var _ gojay.MarshalerJSONObject = frame{} + +type frames []frame + +func (fs frames) IsNil() bool { return fs == nil } +func (fs frames) MarshalJSONArray(enc *gojay.Encoder) { + for _, f := range fs { + enc.Object(f) + } +} + +var _ gojay.MarshalerJSONArray = frames{} + +type cryptoFrame struct { + Offset protocol.ByteCount + Length protocol.ByteCount +} + +type streamFrame struct { + StreamID protocol.StreamID + Offset protocol.ByteCount + Length protocol.ByteCount + FinBit bool +} + +func transformFrame(wf wire.Frame) *frame { + // We don't want to store CRYPTO and STREAM frames, for multiple reasons: + // * They both contain data, and we want to make this byte slice GC'able as soon as possible. + // * STREAM frames use a slice from the buffer pool, which is released as soon as the frame is processed. + switch f := wf.(type) { + case *wire.CryptoFrame: + return &frame{Frame: &cryptoFrame{ + Offset: f.Offset, + Length: protocol.ByteCount(len(f.Data)), + }} + case *wire.StreamFrame: + return &frame{Frame: &streamFrame{ + StreamID: f.StreamID, + Offset: f.Offset, + Length: f.DataLen(), + FinBit: f.FinBit, + }} + default: + return &frame{Frame: wf} + } +} + +func (f frame) MarshalJSONObject(enc *gojay.Encoder) { + switch frame := f.Frame.(type) { + case *wire.PingFrame: + marshalPingFrame(enc, frame) + case *wire.AckFrame: + marshalAckFrame(enc, frame) + case *wire.ResetStreamFrame: + marshalResetStreamFrame(enc, frame) + case *wire.StopSendingFrame: + marshalStopSendingFrame(enc, frame) + case *cryptoFrame: + marshalCryptoFrame(enc, frame) + case *wire.NewTokenFrame: + marshalNewTokenFrame(enc, frame) + case *streamFrame: + marshalStreamFrame(enc, frame) + case *wire.MaxDataFrame: + marshalMaxDataFrame(enc, frame) + case *wire.MaxStreamDataFrame: + marshalMaxStreamDataFrame(enc, frame) + case *wire.MaxStreamsFrame: + marshalMaxStreamsFrame(enc, frame) + case *wire.DataBlockedFrame: + marshalDataBlockedFrame(enc, frame) + case *wire.StreamDataBlockedFrame: + marshalStreamDataBlockedFrame(enc, frame) + case *wire.StreamsBlockedFrame: + marshalStreamsBlockedFrame(enc, frame) + case *wire.NewConnectionIDFrame: + marshalNewConnectionIDFrame(enc, frame) + case *wire.RetireConnectionIDFrame: + marshalRetireConnectionIDFrame(enc, frame) + case *wire.PathChallengeFrame: + marshalPathChallengeFrame(enc, frame) + case *wire.PathResponseFrame: + marshalPathResponseFrame(enc, frame) + case *wire.ConnectionCloseFrame: + marshalConnectionCloseFrame(enc, frame) + case *wire.HandshakeDoneFrame: + marshalHandshakeDoneFrame(enc, frame) + default: + panic("unknown frame type") + } +} + +func (f frame) IsNil() bool { return false } + +func marshalPingFrame(enc *gojay.Encoder, _ *wire.PingFrame) { + enc.StringKey("frame_type", "ping") +} + +type ackRanges []wire.AckRange + +func (ars ackRanges) MarshalJSONArray(enc *gojay.Encoder) { + for _, r := range ars { + enc.Array(ackRange(r)) + } +} + +func (ars ackRanges) IsNil() bool { return false } + +type ackRange wire.AckRange + +func (ar ackRange) MarshalJSONArray(enc *gojay.Encoder) { + enc.AddString(toString(int64(ar.Smallest))) + if ar.Smallest != ar.Largest { + enc.AddString(toString(int64(ar.Largest))) + } +} + +func (ar ackRange) IsNil() bool { return false } + +func marshalAckFrame(enc *gojay.Encoder, f *wire.AckFrame) { + enc.StringKey("frame_type", "ack") + if f.DelayTime != 0 { + enc.StringKey("ack_delay", toString(f.DelayTime.Milliseconds())) + } + enc.ArrayKey("acked_ranges", ackRanges(f.AckRanges)) +} + +func marshalResetStreamFrame(enc *gojay.Encoder, f *wire.ResetStreamFrame) { + enc.StringKey("frame_type", "reset_stream") + enc.StringKey("stream_id", toString(int64(f.StreamID))) + enc.Int64Key("error_code", int64(f.ErrorCode)) + enc.StringKey("final_size", toString(int64(f.ByteOffset))) +} + +func marshalStopSendingFrame(enc *gojay.Encoder, f *wire.StopSendingFrame) { + enc.StringKey("frame_type", "stop_sending") + enc.StringKey("stream_id", toString(int64(f.StreamID))) + enc.Int64Key("error_code", int64(f.ErrorCode)) +} + +func marshalCryptoFrame(enc *gojay.Encoder, f *cryptoFrame) { + enc.StringKey("frame_type", "crypto") + enc.StringKey("offset", toString(int64(f.Offset))) + enc.Int64Key("length", int64(f.Length)) +} + +func marshalNewTokenFrame(enc *gojay.Encoder, f *wire.NewTokenFrame) { + enc.StringKey("frame_type", "new_token") + enc.IntKey("length", len(f.Token)) + enc.StringKey("token", fmt.Sprintf("%x", f.Token)) +} + +func marshalStreamFrame(enc *gojay.Encoder, f *streamFrame) { + enc.StringKey("frame_type", "stream") + enc.StringKey("stream_id", toString(int64(f.StreamID))) + enc.StringKey("offset", toString(int64(f.Offset))) + enc.IntKey("length", int(f.Length)) + enc.BoolKeyOmitEmpty("fin", f.FinBit) +} + +func marshalMaxDataFrame(enc *gojay.Encoder, f *wire.MaxDataFrame) { + enc.StringKey("frame_type", "max_data") + enc.StringKey("maximum", toString(int64(f.ByteOffset))) +} + +func marshalMaxStreamDataFrame(enc *gojay.Encoder, f *wire.MaxStreamDataFrame) { + enc.StringKey("frame_type", "max_stream_data") + enc.StringKey("stream_id", toString(int64(f.StreamID))) + enc.StringKey("maximum", toString(int64(f.ByteOffset))) +} + +func marshalMaxStreamsFrame(enc *gojay.Encoder, f *wire.MaxStreamsFrame) { + enc.StringKey("frame_type", "max_streams") + enc.StringKey("stream_type", streamType(f.Type).String()) + enc.StringKey("maximum", toString(int64(f.MaxStreamNum))) +} + +func marshalDataBlockedFrame(enc *gojay.Encoder, f *wire.DataBlockedFrame) { + enc.StringKey("frame_type", "data_blocked") + enc.StringKey("limit", toString(int64(f.DataLimit))) +} + +func marshalStreamDataBlockedFrame(enc *gojay.Encoder, f *wire.StreamDataBlockedFrame) { + enc.StringKey("frame_type", "stream_data_blocked") + enc.StringKey("stream_id", toString(int64(f.StreamID))) + enc.StringKey("limit", toString(int64(f.DataLimit))) +} + +func marshalStreamsBlockedFrame(enc *gojay.Encoder, f *wire.StreamsBlockedFrame) { + enc.StringKey("frame_type", "streams_blocked") + enc.StringKey("stream_type", streamType(f.Type).String()) + enc.StringKey("limit", toString(int64(f.StreamLimit))) +} + +func marshalNewConnectionIDFrame(enc *gojay.Encoder, f *wire.NewConnectionIDFrame) { + enc.StringKey("frame_type", "new_connection_id") + enc.StringKey("sequence_number", toString(int64(f.SequenceNumber))) + enc.StringKey("retire_prior_to", toString(int64(f.RetirePriorTo))) + enc.IntKey("length", f.ConnectionID.Len()) + enc.StringKey("connection_id", connectionID(f.ConnectionID).String()) + enc.StringKey("reset_token", fmt.Sprintf("%x", f.StatelessResetToken)) +} + +func marshalRetireConnectionIDFrame(enc *gojay.Encoder, f *wire.RetireConnectionIDFrame) { + enc.StringKey("frame_type", "retire_connection_id") + enc.StringKey("sequence_number", toString(int64(f.SequenceNumber))) +} + +func marshalPathChallengeFrame(enc *gojay.Encoder, f *wire.PathChallengeFrame) { + enc.StringKey("frame_type", "path_challenge") + enc.StringKey("data", fmt.Sprintf("%x", f.Data[:])) +} + +func marshalPathResponseFrame(enc *gojay.Encoder, f *wire.PathResponseFrame) { + enc.StringKey("frame_type", "path_response") + enc.StringKey("data", fmt.Sprintf("%x", f.Data[:])) +} + +func marshalConnectionCloseFrame(enc *gojay.Encoder, f *wire.ConnectionCloseFrame) { + errorSpace := "transport" + if f.IsApplicationError { + errorSpace = "application" + } + enc.StringKey("frame_type", "connection_close") + enc.StringKey("error_space", errorSpace) + enc.Int64Key("error_code", int64(f.ErrorCode)) + enc.Int64Key("raw_error_code", int64(f.ErrorCode)) + enc.StringKey("reason", f.ReasonPhrase) +} + +func marshalHandshakeDoneFrame(enc *gojay.Encoder, _ *wire.HandshakeDoneFrame) { + enc.StringKey("frame_type", "handshake_done") +} diff --git a/qlog/frame_test.go b/qlog/frame_test.go new file mode 100644 index 00000000..1ef01b1e --- /dev/null +++ b/qlog/frame_test.go @@ -0,0 +1,349 @@ +package qlog + +import ( + "bytes" + "encoding/json" + "time" + + "github.com/francoispqt/gojay" + + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +var _ = Describe("Frames", func() { + check := func(f wire.Frame, expected map[string]interface{}) { + buf := &bytes.Buffer{} + enc := gojay.NewEncoder(buf) + ExpectWithOffset(1, enc.Encode(transformFrame(f))).To(Succeed()) + data := buf.Bytes() + ExpectWithOffset(1, json.Valid(data)).To(BeTrue()) + checkEncoding(data, expected) + } + + It("marshals PING frames", func() { + check( + &wire.PingFrame{}, + map[string]interface{}{ + "frame_type": "ping", + }, + ) + }) + + It("marshals ACK frames with a range acknowledging a single packet", func() { + check( + &wire.AckFrame{ + DelayTime: 86 * time.Millisecond, + AckRanges: []wire.AckRange{{Smallest: 120, Largest: 120}}, + }, + map[string]interface{}{ + "frame_type": "ack", + "ack_delay": "86", + "acked_ranges": [][]string{[]string{"120"}}, + }, + ) + }) + + It("marshals ACK frames without a delay", func() { + check( + &wire.AckFrame{ + AckRanges: []wire.AckRange{{Smallest: 120, Largest: 120}}, + }, + map[string]interface{}{ + "frame_type": "ack", + "acked_ranges": [][]string{[]string{"120"}}, + }, + ) + }) + + It("marshals ACK frames with a range acknowledging ranges of packets", func() { + check( + &wire.AckFrame{ + DelayTime: 86 * time.Millisecond, + AckRanges: []wire.AckRange{ + {Smallest: 5, Largest: 50}, + {Smallest: 100, Largest: 120}, + }, + }, + map[string]interface{}{ + "frame_type": "ack", + "ack_delay": "86", + "acked_ranges": [][]string{ + []string{"5", "50"}, + []string{"100", "120"}, + }, + }, + ) + }) + + It("marshals RESET_STREAM frames", func() { + check( + &wire.ResetStreamFrame{ + StreamID: 987, + ByteOffset: 1234, + ErrorCode: 42, + }, + map[string]interface{}{ + "frame_type": "reset_stream", + "stream_id": "987", + "error_code": 42, + "final_size": "1234", + }, + ) + }) + + It("marshals STOP_SENDING frames", func() { + check( + &wire.StopSendingFrame{ + StreamID: 987, + ErrorCode: 42, + }, + map[string]interface{}{ + "frame_type": "stop_sending", + "stream_id": "987", + "error_code": 42, + }, + ) + }) + + It("marshals CRYPTO frames", func() { + check( + &wire.CryptoFrame{ + Offset: 1337, + Data: []byte("foobar"), + }, + map[string]interface{}{ + "frame_type": "crypto", + "offset": "1337", + "length": 6, + }, + ) + }) + + It("marshals NEW_TOKEN frames", func() { + check( + &wire.NewTokenFrame{ + Token: []byte{0xde, 0xad, 0xbe, 0xef}, + }, + map[string]interface{}{ + "frame_type": "new_token", + "length": 4, + "token": "deadbeef", + }, + ) + }) + + It("marshals STREAM frames with FIN", func() { + check( + &wire.StreamFrame{ + StreamID: 42, + Offset: 1337, + FinBit: true, + Data: []byte("foobar"), + }, + map[string]interface{}{ + "frame_type": "stream", + "stream_id": "42", + "offset": "1337", + "fin": true, + "length": 6, + }, + ) + }) + + It("marshals STREAM frames without FIN", func() { + check( + &wire.StreamFrame{ + StreamID: 42, + Offset: 1337, + Data: []byte("foo"), + }, + map[string]interface{}{ + "frame_type": "stream", + "stream_id": "42", + "offset": "1337", + "length": 3, + }, + ) + }) + + It("marshals MAX_DATA frames", func() { + check( + &wire.MaxDataFrame{ + ByteOffset: 1337, + }, + map[string]interface{}{ + "frame_type": "max_data", + "maximum": "1337", + }, + ) + }) + + It("marshals MAX_STREAM_DATA frames", func() { + check( + &wire.MaxStreamDataFrame{ + StreamID: 1234, + ByteOffset: 1337, + }, + map[string]interface{}{ + "frame_type": "max_stream_data", + "stream_id": "1234", + "maximum": "1337", + }, + ) + }) + + It("marshals MAX_STREAMS frames", func() { + check( + &wire.MaxStreamsFrame{ + Type: protocol.StreamTypeBidi, + MaxStreamNum: 42, + }, + map[string]interface{}{ + "frame_type": "max_streams", + "stream_type": "bidirectional", + "maximum": "42", + }, + ) + }) + + It("marshals DATA_BLOCKED frames", func() { + check( + &wire.DataBlockedFrame{ + DataLimit: 1337, + }, + map[string]interface{}{ + "frame_type": "data_blocked", + "limit": "1337", + }, + ) + }) + + It("marshals STREAM_DATA_BLOCKED frames", func() { + check( + &wire.StreamDataBlockedFrame{ + StreamID: 42, + DataLimit: 1337, + }, + map[string]interface{}{ + "frame_type": "stream_data_blocked", + "stream_id": "42", + "limit": "1337", + }, + ) + }) + + It("marshals STREAMS_BLOCKED frames", func() { + check( + &wire.StreamsBlockedFrame{ + Type: protocol.StreamTypeUni, + StreamLimit: 123, + }, + map[string]interface{}{ + "frame_type": "streams_blocked", + "stream_type": "unidirectional", + "limit": "123", + }, + ) + }) + + It("marshals NEW_CONNECTION_ID frames", func() { + check( + &wire.NewConnectionIDFrame{ + SequenceNumber: 42, + RetirePriorTo: 24, + ConnectionID: protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef}, + StatelessResetToken: [16]byte{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 0xa, 0xb, 0xc, 0xd, 0xe, 0xf}, + }, + map[string]interface{}{ + "frame_type": "new_connection_id", + "sequence_number": "42", + "retire_prior_to": "24", + "length": 4, + "connection_id": "deadbeef", + "reset_token": "000102030405060708090a0b0c0d0e0f", + }, + ) + }) + + It("marshals RETIRE_CONNECTION_ID frames", func() { + check( + &wire.RetireConnectionIDFrame{ + SequenceNumber: 1337, + }, + map[string]interface{}{ + "frame_type": "retire_connection_id", + "sequence_number": "1337", + }, + ) + }) + + It("marshals PATH_CHALLENGE frames", func() { + check( + &wire.PathChallengeFrame{ + Data: [8]byte{0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0xc0, 0x01}, + }, + map[string]interface{}{ + "frame_type": "path_challenge", + "data": "deadbeefcafec001", + }, + ) + }) + + It("marshals PATH_RESPONSE frames", func() { + check( + &wire.PathResponseFrame{ + Data: [8]byte{0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0xc0, 0x01}, + }, + map[string]interface{}{ + "frame_type": "path_response", + "data": "deadbeefcafec001", + }, + ) + }) + + It("marshals CONNECTION_CLOSE frames, for application error codes", func() { + check( + &wire.ConnectionCloseFrame{ + IsApplicationError: true, + ErrorCode: 1337, + ReasonPhrase: "lorem ipsum", + }, + map[string]interface{}{ + "frame_type": "connection_close", + "error_space": "application", + "error_code": 1337, + "raw_error_code": 1337, + "reason": "lorem ipsum", + }, + ) + }) + + It("marshals CONNECTION_CLOSE frames, for transport error codes", func() { + check( + &wire.ConnectionCloseFrame{ + ErrorCode: 1337, + ReasonPhrase: "lorem ipsum", + }, + map[string]interface{}{ + "frame_type": "connection_close", + "error_space": "transport", + "error_code": 1337, + "raw_error_code": 1337, + "reason": "lorem ipsum", + }, + ) + }) + + It("marshals HANDSHAKE_DONE frames", func() { + check( + &wire.HandshakeDoneFrame{}, + map[string]interface{}{ + "frame_type": "handshake_done", + }, + ) + }) +}) diff --git a/qlog/packet_header.go b/qlog/packet_header.go new file mode 100644 index 00000000..5428defa --- /dev/null +++ b/qlog/packet_header.go @@ -0,0 +1,90 @@ +package qlog + +import ( + "github.com/francoispqt/gojay" + + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" +) + +func getPacketTypeFromHeader(hdr *wire.ExtendedHeader) packetType { + if !hdr.IsLongHeader { + return packetType1RTT + } + if hdr.Version == 0 { + return packetTypeVersionNegotiation + } + switch hdr.Type { + case protocol.PacketTypeInitial: + return packetTypeInitial + case protocol.PacketTypeHandshake: + return packetTypeHandshake + case protocol.PacketType0RTT: + return packetType0RTT + case protocol.PacketTypeRetry: + return packetTypeRetry + default: + panic("unknown packet type") + } +} + +func getPacketTypeFromEncryptionLevel(encLevel protocol.EncryptionLevel) packetType { + switch encLevel { + case protocol.EncryptionInitial: + return packetTypeInitial + case protocol.EncryptionHandshake: + return packetTypeHandshake + case protocol.Encryption0RTT: + return packetType0RTT + case protocol.Encryption1RTT: + return packetType1RTT + default: + panic("unknown encryption level") + } +} + +func transformHeader(hdr *wire.Header) *packetHeader { + return &packetHeader{ + PayloadLength: hdr.Length, + SrcConnectionID: hdr.SrcConnectionID, + DestConnectionID: hdr.DestConnectionID, + Version: hdr.Version, + } +} + +func transformExtendedHeader(hdr *wire.ExtendedHeader) *packetHeader { + h := transformHeader(&hdr.Header) + h.PacketNumber = hdr.PacketNumber + return h +} + +type packetHeader struct { + PacketNumber protocol.PacketNumber + PayloadLength protocol.ByteCount + // Size of the QUIC packet (QUIC header + payload). + // See https://github.com/quiclog/internet-drafts/issues/40. + PacketSize protocol.ByteCount + + Version protocol.VersionNumber + SrcConnectionID protocol.ConnectionID + DestConnectionID protocol.ConnectionID +} + +func (h packetHeader) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("packet_number", toString(int64(h.PacketNumber))) + enc.Int64KeyOmitEmpty("payload_length", int64(h.PayloadLength)) + enc.Int64KeyOmitEmpty("packet_size", int64(h.PacketSize)) + if h.Version != 0 { + enc.StringKey("version", versionNumber(h.Version).String()) + } + if h.SrcConnectionID.Len() > 0 { + enc.StringKey("scil", toString(int64(h.SrcConnectionID.Len()))) + enc.StringKey("scid", connectionID(h.SrcConnectionID).String()) + } + if h.DestConnectionID.Len() > 0 { + enc.StringKey("dcil", toString(int64(h.DestConnectionID.Len()))) + enc.StringKey("dcid", connectionID(h.DestConnectionID).String()) + } +} + +func (packetHeader) IsNil() bool { return false } diff --git a/qlog/packet_header_test.go b/qlog/packet_header_test.go new file mode 100644 index 00000000..1ed42ba4 --- /dev/null +++ b/qlog/packet_header_test.go @@ -0,0 +1,153 @@ +package qlog + +import ( + "bytes" + "encoding/json" + + "github.com/francoispqt/gojay" + + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +var _ = Describe("Packet Header", func() { + It("determines the packet type from the encryption level", func() { + Expect(getPacketTypeFromEncryptionLevel(protocol.EncryptionInitial)).To(Equal(packetTypeInitial)) + Expect(getPacketTypeFromEncryptionLevel(protocol.EncryptionHandshake)).To(Equal(packetTypeHandshake)) + Expect(getPacketTypeFromEncryptionLevel(protocol.Encryption0RTT)).To(Equal(packetType0RTT)) + Expect(getPacketTypeFromEncryptionLevel(protocol.Encryption1RTT)).To(Equal(packetType1RTT)) + }) + + Context("determining the packet type from the header", func() { + It("recognizes Initial packets", func() { + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeInitial, + Version: protocol.VersionTLS, + }, + })).To(Equal(packetTypeInitial)) + }) + + It("recognizes Handshake packets", func() { + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeHandshake, + Version: protocol.VersionTLS, + }, + })).To(Equal(packetTypeHandshake)) + }) + + It("recognizes Retry packets", func() { + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeRetry, + Version: protocol.VersionTLS, + }, + })).To(Equal(packetTypeRetry)) + }) + + It("recognizes 0-RTT packets", func() { + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketType0RTT, + Version: protocol.VersionTLS, + }, + })).To(Equal(packetType0RTT)) + }) + + It("recognizes Version Negotiation packets", func() { + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ + Header: wire.Header{IsLongHeader: true}, + })).To(Equal(packetTypeVersionNegotiation)) + }) + + It("recognizes 1-RTT packets", func() { + Expect(getPacketTypeFromHeader(&wire.ExtendedHeader{ + Header: wire.Header{}, + })).To(Equal(packetType1RTT)) + }) + }) + + Context("marshalling", func() { + check := func(hdr *wire.ExtendedHeader, expected map[string]interface{}) { + buf := &bytes.Buffer{} + enc := gojay.NewEncoder(buf) + ExpectWithOffset(1, enc.Encode(transformExtendedHeader(hdr))).To(Succeed()) + data := buf.Bytes() + ExpectWithOffset(1, json.Valid(data)).To(BeTrue()) + checkEncoding(data, expected) + } + + It("marshals a header", func() { + check( + &wire.ExtendedHeader{PacketNumber: 42}, + map[string]interface{}{ + "packet_number": "42", + }, + ) + }) + + It("marshals a header with a payload length", func() { + check( + &wire.ExtendedHeader{ + PacketNumber: 42, + Header: wire.Header{Length: 123}, + }, + map[string]interface{}{ + "packet_number": "42", + "payload_length": 123, + }, + ) + }) + + It("marshals a header with a source connection ID", func() { + check( + &wire.ExtendedHeader{ + PacketNumber: 42, + Header: wire.Header{ + SrcConnectionID: protocol.ConnectionID{0x00, 0x11, 0x22, 0x33, 0x44, 0x55, 0x66, 0x77, 0x88, 0x99, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff}, + }, + }, + map[string]interface{}{ + "packet_number": "42", + "scil": "16", + "scid": "00112233445566778899aabbccddeeff", + }, + ) + }) + + It("marshals a header with a destination connection ID", func() { + check( + &wire.ExtendedHeader{ + PacketNumber: 42, + Header: wire.Header{DestConnectionID: protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef}}, + }, + map[string]interface{}{ + "packet_number": "42", + "dcil": "4", + "dcid": "deadbeef", + }, + ) + }) + + It("marshals a header with a version number", func() { + check( + &wire.ExtendedHeader{ + PacketNumber: 42, + Header: wire.Header{Version: protocol.VersionNumber(0xdecafbad)}, + }, + map[string]interface{}{ + "packet_number": "42", + "version": "decafbad", + }, + ) + }) + }) +}) diff --git a/qlog/qlog.go b/qlog/qlog.go new file mode 100644 index 00000000..2eec8e6c --- /dev/null +++ b/qlog/qlog.go @@ -0,0 +1,137 @@ +package qlog + +import ( + "io" + "time" + + "github.com/lucas-clemente/quic-go/internal/congestion" + + "github.com/francoispqt/gojay" + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" +) + +// A Tracer records events to be exported to a qlog. +type Tracer interface { + Export() error + SentPacket(t time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, ack *wire.AckFrame, frames []wire.Frame) + ReceivedRetry(time.Time, *wire.Header) + ReceivedPacket(t time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, frames []wire.Frame) + UpdatedMetrics(t time.Time, rttStats *congestion.RTTStats, cwnd protocol.ByteCount, bytesInFLight protocol.ByteCount, packetsInFlight int) + LostPacket(time.Time, protocol.EncryptionLevel, protocol.PacketNumber, PacketLossReason) +} + +type tracer struct { + w io.WriteCloser + odcid protocol.ConnectionID + perspective protocol.Perspective + + events []event +} + +var _ Tracer = &tracer{} + +// NewTracer creates a new tracer to record a qlog. +func NewTracer(w io.WriteCloser, p protocol.Perspective, odcid protocol.ConnectionID) Tracer { + return &tracer{ + w: w, + perspective: p, + odcid: odcid, + } +} + +func (t *tracer) Active() bool { return true } + +// Export writes a qlog. +func (t *tracer) Export() error { + enc := gojay.NewEncoder(t.w) + tl := &topLevel{ + traces: traces{ + { + VantagePoint: vantagePoint{Type: t.perspective}, + CommonFields: commonFields{ODCID: connectionID(t.odcid), GroupID: connectionID(t.odcid)}, + EventFields: eventFields[:], + Events: t.events, + }, + }} + if err := enc.Encode(tl); err != nil { + return err + } + return t.w.Close() +} + +func (t *tracer) SentPacket(time time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, ack *wire.AckFrame, frames []wire.Frame) { + numFrames := len(frames) + if ack != nil { + numFrames++ + } + fs := make([]frame, 0, numFrames) + if ack != nil { + fs = append(fs, *transformFrame(ack)) + } + for _, f := range frames { + fs = append(fs, *transformFrame(f)) + } + header := *transformExtendedHeader(hdr) + header.PacketSize = packetSize + t.events = append(t.events, event{ + Time: time, + eventDetails: eventPacketSent{ + PacketType: getPacketTypeFromHeader(hdr), + Header: header, + Frames: fs, + }, + }) +} + +func (t *tracer) ReceivedPacket(time time.Time, hdr *wire.ExtendedHeader, packetSize protocol.ByteCount, frames []wire.Frame) { + fs := make([]frame, len(frames)) + for i, f := range frames { + fs[i] = *transformFrame(f) + } + header := *transformExtendedHeader(hdr) + header.PacketSize = packetSize + t.events = append(t.events, event{ + Time: time, + eventDetails: eventPacketReceived{ + PacketType: getPacketTypeFromHeader(hdr), + Header: header, + Frames: fs, + }, + }) +} + +func (t *tracer) ReceivedRetry(time time.Time, hdr *wire.Header) { + t.events = append(t.events, event{ + Time: time, + eventDetails: eventRetryReceived{ + Header: *transformHeader(hdr), + }, + }) +} + +func (t *tracer) UpdatedMetrics(time time.Time, rttStats *congestion.RTTStats, cwnd, bytesInFlight protocol.ByteCount, packetsInFlight int) { + t.events = append(t.events, event{ + Time: time, + eventDetails: eventMetricsUpdated{ + MinRTT: rttStats.MinRTT(), + SmoothedRTT: rttStats.SmoothedRTT(), + LatestRTT: rttStats.LatestRTT(), + RTTVariance: rttStats.MeanDeviation(), + CongestionWindow: cwnd, + BytesInFlight: bytesInFlight, + PacketsInFlight: packetsInFlight, + }, + }) +} + +func (t *tracer) LostPacket(time time.Time, encLevel protocol.EncryptionLevel, pn protocol.PacketNumber, lossReason PacketLossReason) { + t.events = append(t.events, event{ + Time: time, + eventDetails: eventPacketLost{ + PacketType: getPacketTypeFromEncryptionLevel(encLevel), + PacketNumber: pn, + Trigger: lossReason, + }, + }) +} diff --git a/qlog/qlog_suite_test.go b/qlog/qlog_suite_test.go new file mode 100644 index 00000000..f47c5e60 --- /dev/null +++ b/qlog/qlog_suite_test.go @@ -0,0 +1,40 @@ +package qlog + +import ( + "encoding/json" + "testing" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +func TestQlog(t *testing.T) { + RegisterFailHandler(Fail) + RunSpecs(t, "qlog Suite") +} + +func checkEncoding(data []byte, expected map[string](interface{})) { + // unmarshal the data + m := make(map[string](interface{})) + ExpectWithOffset(1, json.Unmarshal(data, &m)).To(Succeed()) + ExpectWithOffset(1, m).To(HaveLen(len(expected))) + for key, value := range expected { + switch value.(type) { + case string: + ExpectWithOffset(1, m).To(HaveKeyWithValue(key, value)) + case int: + ExpectWithOffset(1, m).To(HaveKeyWithValue(key, float64(value.(int)))) + case bool: + ExpectWithOffset(1, m).To(HaveKeyWithValue(key, value.(bool))) + case [][]string: // used in the ACK frame + ExpectWithOffset(1, m).To(HaveKey(key)) + for i, l := range value.([][]string) { + for j, s := range l { + ExpectWithOffset(1, m[key].([]interface{})[i].([]interface{})[j].(string)).To(Equal(s)) + } + } + default: + Fail("unexpected type") + } + } +} diff --git a/qlog/qlog_test.go b/qlog/qlog_test.go new file mode 100644 index 00000000..f7ae6313 --- /dev/null +++ b/qlog/qlog_test.go @@ -0,0 +1,242 @@ +package qlog + +import ( + "bytes" + "encoding/json" + "io" + "time" + + "github.com/lucas-clemente/quic-go/internal/congestion" + "github.com/lucas-clemente/quic-go/internal/protocol" + "github.com/lucas-clemente/quic-go/internal/wire" + + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +type nopWriteCloserImpl struct{ io.Writer } + +func (nopWriteCloserImpl) Close() error { return nil } + +func nopWriteCloser(w io.Writer) io.WriteCloser { + return &nopWriteCloserImpl{Writer: w} +} + +var _ = Describe("Tracer", func() { + var ( + tracer Tracer + buf *bytes.Buffer + ) + + BeforeEach(func() { + buf = &bytes.Buffer{} + tracer = NewTracer( + nopWriteCloser(buf), + protocol.PerspectiveServer, + protocol.ConnectionID{0xde, 0xad, 0xbe, 0xef}, + ) + }) + + It("exports a trace that has the right metadata", func() { + Expect(tracer.Export()).To(Succeed()) + + m := make(map[string]interface{}) + Expect(json.Unmarshal(buf.Bytes(), &m)).To(Succeed()) + Expect(m).To(HaveKeyWithValue("qlog_version", "draft-02-wip")) + Expect(m).To(HaveKey("title")) + Expect(m).To(HaveKey("traces")) + traces := m["traces"].([]interface{}) + Expect(traces).To(HaveLen(1)) + trace := traces[0].(map[string]interface{}) + Expect(trace).To(HaveKey(("common_fields"))) + commonFields := trace["common_fields"].(map[string]interface{}) + Expect(commonFields).To(HaveKeyWithValue("ODCID", "deadbeef")) + Expect(commonFields).To(HaveKeyWithValue("group_id", "deadbeef")) + Expect(trace).To(HaveKey("event_fields")) + for i, ef := range trace["event_fields"].([]interface{}) { + Expect(ef.(string)).To(Equal(eventFields[i])) + } + Expect(trace).To(HaveKey("vantage_point")) + vantagePoint := trace["vantage_point"].(map[string]interface{}) + Expect(vantagePoint).To(HaveKeyWithValue("type", "server")) + }) + + Context("Events", func() { + exportAndParse := func() (time.Time, string /* category */, string /* event */, map[string]interface{}) { + Expect(tracer.Export()).To(Succeed()) + + m := make(map[string]interface{}) + Expect(json.Unmarshal(buf.Bytes(), &m)).To(Succeed()) + Expect(m).To(HaveKey("traces")) + traces := m["traces"].([]interface{}) + Expect(traces).To(HaveLen(1)) + trace := traces[0].(map[string]interface{}) + Expect(trace).To(HaveKey("events")) + events := trace["events"].([]interface{}) + Expect(events).To(HaveLen(1)) + ev := events[0].([]interface{}) + Expect(ev).To(HaveLen(4)) + return time.Unix(0, int64(1e6*ev[0].(float64))), ev[1].(string), ev[2].(string), ev[3].(map[string]interface{}) + } + + It("records a sent packet, without an ACK", func() { + now := time.Now() + tracer.SentPacket( + now, + &wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeHandshake, + DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, + SrcConnectionID: protocol.ConnectionID{4, 3, 2, 1}, + Version: protocol.VersionTLS, + }, + PacketNumber: 1337, + }, + 987, + nil, + []wire.Frame{ + &wire.MaxStreamDataFrame{StreamID: 42, ByteOffset: 987}, + &wire.StreamFrame{StreamID: 123, Offset: 1234, Data: []byte("foobar"), FinBit: true}, + }, + ) + t, category, eventName, ev := exportAndParse() + Expect(t).To(BeTemporally("~", now, time.Millisecond)) + Expect(category).To(Equal("transport")) + Expect(eventName).To(Equal("packet_sent")) + Expect(ev).To(HaveKeyWithValue("packet_type", "handshake")) + Expect(ev).To(HaveKey("header")) + hdr := ev["header"].(map[string]interface{}) + Expect(hdr).To(HaveKeyWithValue("packet_size", float64(987))) + Expect(hdr).To(HaveKeyWithValue("packet_number", "1337")) + Expect(hdr).To(HaveKeyWithValue("scid", "04030201")) + Expect(ev).To(HaveKey("frames")) + frames := ev["frames"].([]interface{}) + Expect(frames).To(HaveLen(2)) + Expect(frames[0].(map[string]interface{})).To(HaveKeyWithValue("frame_type", "max_stream_data")) + Expect(frames[1].(map[string]interface{})).To(HaveKeyWithValue("frame_type", "stream")) + }) + + It("records a sent packet, without an ACK", func() { + tracer.SentPacket( + time.Now(), + &wire.ExtendedHeader{ + Header: wire.Header{DestConnectionID: protocol.ConnectionID{1, 2, 3, 4}}, + PacketNumber: 1337, + }, + 123, + &wire.AckFrame{AckRanges: []wire.AckRange{{Smallest: 1, Largest: 10}}}, + []wire.Frame{&wire.MaxDataFrame{ByteOffset: 987}}, + ) + _, _, _, ev := exportAndParse() + Expect(ev).To(HaveKeyWithValue("packet_type", "1RTT")) + Expect(ev).To(HaveKey("header")) + Expect(ev).To(HaveKey("frames")) + frames := ev["frames"].([]interface{}) + Expect(frames).To(HaveLen(2)) + Expect(frames[0].(map[string]interface{})).To(HaveKeyWithValue("frame_type", "ack")) + Expect(frames[1].(map[string]interface{})).To(HaveKeyWithValue("frame_type", "max_data")) + }) + + It("records a received packet", func() { + now := time.Now() + tracer.ReceivedPacket( + now, + &wire.ExtendedHeader{ + Header: wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeInitial, + DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, + SrcConnectionID: protocol.ConnectionID{4, 3, 2, 1}, + Version: protocol.VersionTLS, + }, + PacketNumber: 1337, + }, + 789, + []wire.Frame{ + &wire.MaxStreamDataFrame{StreamID: 42, ByteOffset: 987}, + &wire.StreamFrame{StreamID: 123, Offset: 1234, Data: []byte("foobar"), FinBit: true}, + }, + ) + t, category, eventName, ev := exportAndParse() + Expect(t).To(BeTemporally("~", now, time.Millisecond)) + Expect(category).To(Equal("transport")) + Expect(eventName).To(Equal("packet_received")) + Expect(ev).To(HaveKeyWithValue("packet_type", "initial")) + Expect(ev).To(HaveKey("header")) + hdr := ev["header"].(map[string]interface{}) + Expect(hdr).To(HaveKeyWithValue("packet_size", float64(789))) + Expect(hdr).To(HaveKeyWithValue("packet_number", "1337")) + Expect(hdr).To(HaveKeyWithValue("scid", "04030201")) + Expect(ev).To(HaveKey("frames")) + Expect(ev["frames"].([]interface{})).To(HaveLen(2)) + }) + + It("records a received Retry packet", func() { + now := time.Now() + tracer.ReceivedRetry( + now, + &wire.Header{ + IsLongHeader: true, + Type: protocol.PacketTypeRetry, + DestConnectionID: protocol.ConnectionID{1, 2, 3, 4, 5, 6, 7, 8}, + SrcConnectionID: protocol.ConnectionID{4, 3, 2, 1}, + Version: protocol.VersionTLS, + }, + ) + t, category, eventName, ev := exportAndParse() + Expect(t).To(BeTemporally("~", now, time.Millisecond)) + Expect(category).To(Equal("transport")) + Expect(eventName).To(Equal("packet_received")) + Expect(ev).To(HaveKeyWithValue("packet_type", "retry")) + Expect(ev).To(HaveKey("header")) + Expect(ev).ToNot(HaveKey("frames")) + }) + + It("records metrics updates", func() { + now := time.Now() + rttStats := congestion.NewRTTStats() + rttStats.UpdateRTT(15*time.Millisecond, 0, now) + rttStats.UpdateRTT(20*time.Millisecond, 0, now) + rttStats.UpdateRTT(25*time.Millisecond, 0, now) + Expect(rttStats.MinRTT()).To(Equal(15 * time.Millisecond)) + Expect(rttStats.SmoothedRTT()).To(And( + BeNumerically(">", 15*time.Millisecond), + BeNumerically("<", 25*time.Millisecond), + )) + Expect(rttStats.LatestRTT()).To(Equal(25 * time.Millisecond)) + tracer.UpdatedMetrics( + now, + rttStats, + 4321, + 1234, + 42, + ) + t, category, eventName, ev := exportAndParse() + Expect(t).To(BeTemporally("~", now, time.Millisecond)) + Expect(category).To(Equal("recovery")) + Expect(eventName).To(Equal("metrics_updated")) + Expect(ev).To(HaveKeyWithValue("min_rtt", float64(15))) + Expect(ev).To(HaveKeyWithValue("latest_rtt", float64(25))) + Expect(ev).To(HaveKey("smoothed_rtt")) + Expect(time.Duration(ev["smoothed_rtt"].(float64)) * time.Millisecond).To(BeNumerically("~", rttStats.SmoothedRTT(), time.Millisecond)) + Expect(ev).To(HaveKey("rtt_variance")) + Expect(time.Duration(ev["rtt_variance"].(float64)) * time.Millisecond).To(BeNumerically("~", rttStats.MeanDeviation(), time.Millisecond)) + Expect(ev).To(HaveKeyWithValue("congestion_window", float64(4321))) + Expect(ev).To(HaveKeyWithValue("bytes_in_flight", float64(1234))) + Expect(ev).To(HaveKeyWithValue("packets_in_flight", float64(42))) + }) + + It("records lost packets", func() { + now := time.Now() + tracer.LostPacket(now, protocol.EncryptionHandshake, 42, PacketLossReorderingThreshold) + t, category, eventName, ev := exportAndParse() + Expect(t).To(BeTemporally("~", now, time.Millisecond)) + Expect(category).To(Equal("recovery")) + Expect(eventName).To(Equal("packet_lost")) + Expect(ev).To(HaveKeyWithValue("packet_type", "handshake")) + Expect(ev).To(HaveKeyWithValue("packet_number", "42")) + Expect(ev).To(HaveKeyWithValue("trigger", "reordering_threshold")) + }) + }) +}) diff --git a/qlog/trace.go b/qlog/trace.go new file mode 100644 index 00000000..2d3628d0 --- /dev/null +++ b/qlog/trace.go @@ -0,0 +1,72 @@ +package qlog + +import ( + "github.com/francoispqt/gojay" + + "github.com/lucas-clemente/quic-go/internal/protocol" +) + +type topLevel struct { + traces traces +} + +func (topLevel) IsNil() bool { return false } +func (l topLevel) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("qlog_version", "draft-02-wip") + enc.StringKeyOmitEmpty("title", "quic-go qlog") + enc.ArrayKey("traces", l.traces) +} + +type vantagePoint struct { + Name string + Type protocol.Perspective +} + +func (p vantagePoint) IsNil() bool { return false } +func (p vantagePoint) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKeyOmitEmpty("name", p.Name) + switch p.Type { + case protocol.PerspectiveClient: + enc.StringKey("type", "client") + case protocol.PerspectiveServer: + enc.StringKey("type", "server") + } +} + +type commonFields struct { + ODCID connectionID + GroupID connectionID + ProtocolType string +} + +func (f commonFields) MarshalJSONObject(enc *gojay.Encoder) { + enc.StringKey("ODCID", f.ODCID.String()) + enc.StringKey("group_id", f.ODCID.String()) + enc.StringKeyOmitEmpty("protocol_type", f.ProtocolType) +} + +func (f commonFields) IsNil() bool { return false } + +type traces []trace + +func (t traces) IsNil() bool { return t == nil } +func (t traces) MarshalJSONArray(enc *gojay.Encoder) { + for _, tr := range t { + enc.Object(tr) + } +} + +type trace struct { + VantagePoint vantagePoint + CommonFields commonFields + EventFields []string + Events events +} + +func (trace) IsNil() bool { return false } +func (t trace) MarshalJSONObject(enc *gojay.Encoder) { + enc.ObjectKey("vantage_point", t.VantagePoint) + enc.ObjectKey("common_fields", t.CommonFields) + enc.SliceStringKey("event_fields", t.EventFields) + enc.ArrayKey("events", t.Events) +} diff --git a/qlog/types.go b/qlog/types.go new file mode 100644 index 00000000..711c4171 --- /dev/null +++ b/qlog/types.go @@ -0,0 +1,112 @@ +package qlog + +import ( + "fmt" + "strconv" + + "github.com/lucas-clemente/quic-go/internal/protocol" +) + +func toString(i int64) string { + return strconv.FormatInt(i, 10) +} + +type versionNumber protocol.VersionNumber + +func (v versionNumber) String() string { + return fmt.Sprintf("%x", uint32(v)) +} + +type streamType protocol.StreamType + +func (s streamType) String() string { + switch protocol.StreamType(s) { + case protocol.StreamTypeUni: + return "unidirectional" + case protocol.StreamTypeBidi: + return "bidirectional" + default: + panic("unknown stream type") + } +} + +type connectionID protocol.ConnectionID + +func (c connectionID) String() string { + return fmt.Sprintf("%x", []byte(c)) +} + +// category is the qlog event category. +type category uint8 + +const ( + categoryConnectivity category = iota + categoryTransport + categorySecurity + categoryRecovery +) + +func (c category) String() string { + switch c { + case categoryConnectivity: + return "connectivity" + case categoryTransport: + return "transport" + case categorySecurity: + return "security" + case categoryRecovery: + return "recovery" + default: + panic("unknown category") + } +} + +type packetType protocol.PacketType + +const ( + packetTypeInitial packetType = iota + packetTypeHandshake + packetTypeRetry + packetType0RTT + packetTypeVersionNegotiation + packetType1RTT +) + +func (t packetType) String() string { + switch t { + case packetTypeInitial: + return "initial" + case packetTypeHandshake: + return "handshake" + case packetTypeRetry: + return "retry" + case packetType0RTT: + return "0RTT" + case packetTypeVersionNegotiation: + return "version_negotiation" + case packetType1RTT: + return "1RTT" + default: + panic("unknown packet type") + } +} + +type PacketLossReason uint8 + +const ( + // PacketLossReorderingThreshold: when a packet is deemed lost due to reordering threshold + PacketLossReorderingThreshold PacketLossReason = iota + // PacketLossTimeThreshold: when a packet is deemed lost due to time threshold + PacketLossTimeThreshold +) + +func (r PacketLossReason) String() string { + switch r { + case PacketLossReorderingThreshold: + return "reordering_threshold" + case PacketLossTimeThreshold: + return "time_threshold" + default: + panic("unknown loss reason") + } +} diff --git a/qlog/types_test.go b/qlog/types_test.go new file mode 100644 index 00000000..3f10ebfa --- /dev/null +++ b/qlog/types_test.go @@ -0,0 +1,24 @@ +package qlog + +import ( + . "github.com/onsi/ginkgo" + . "github.com/onsi/gomega" +) + +var _ = Describe("Types", func() { + It("has a string representation for the category", func() { + Expect(categoryConnectivity.String()).To(Equal("connectivity")) + Expect(categoryTransport.String()).To(Equal("transport")) + Expect(categoryRecovery.String()).To(Equal("recovery")) + Expect(categorySecurity.String()).To(Equal("security")) + }) + + It("has a string representation for the packet type", func() { + Expect(packetTypeInitial.String()).To(Equal("initial")) + Expect(packetTypeHandshake.String()).To(Equal("handshake")) + Expect(packetType0RTT.String()).To(Equal("0RTT")) + Expect(packetType1RTT.String()).To(Equal("1RTT")) + Expect(packetTypeRetry.String()).To(Equal("retry")) + Expect(packetTypeVersionNegotiation.String()).To(Equal("version_negotiation")) + }) +}) diff --git a/server.go b/server.go index 08dd035d..93129721 100644 --- a/server.go +++ b/server.go @@ -11,6 +11,8 @@ import ( "sync/atomic" "time" + "github.com/lucas-clemente/quic-go/qlog" + "github.com/lucas-clemente/quic-go/internal/handshake" "github.com/lucas-clemente/quic-go/internal/protocol" "github.com/lucas-clemente/quic-go/internal/qerr" @@ -71,7 +73,7 @@ type baseServer struct { receivedPackets chan *receivedPacket // set as a member, so they can be set in the tests - newSession func(connection, sessionRunner, protocol.ConnectionID /* original connection ID */, protocol.ConnectionID /* client dest connection ID */, protocol.ConnectionID /* destination connection ID */, protocol.ConnectionID /* source connection ID */, [16]byte, *Config, *tls.Config, *handshake.TokenGenerator, bool /* enable 0-RTT */, utils.Logger, protocol.VersionNumber) quicSession + newSession func(connection, sessionRunner, protocol.ConnectionID /* original connection ID */, protocol.ConnectionID /* client dest connection ID */, protocol.ConnectionID /* destination connection ID */, protocol.ConnectionID /* source connection ID */, [16]byte, *Config, *tls.Config, *handshake.TokenGenerator, bool /* enable 0-RTT */, qlog.Tracer, utils.Logger, protocol.VersionNumber) quicSession serverError error errorChan chan struct{} @@ -394,6 +396,12 @@ func (s *baseServer) createNewSession( srcConnID protocol.ConnectionID, version protocol.VersionNumber, ) quicSession { + var qlogger qlog.Tracer + if s.config.GetLogWriter != nil { + if w := s.config.GetLogWriter(origDestConnID); w != nil { + qlogger = qlog.NewTracer(w, protocol.PerspectiveServer, origDestConnID) + } + } sess := s.newSession( &conn{pconn: s.conn, currentAddr: remoteAddr}, s.sessionHandler, @@ -406,6 +414,7 @@ func (s *baseServer) createNewSession( s.tlsConf, s.tokenGenerator, s.acceptEarlySessions, + qlogger, s.logger, version, ) diff --git a/server_test.go b/server_test.go index 96161637..b3ac89db 100644 --- a/server_test.go +++ b/server_test.go @@ -13,6 +13,8 @@ import ( "sync" "time" + "github.com/lucas-clemente/quic-go/qlog" + "github.com/golang/mock/gomock" "github.com/lucas-clemente/quic-go/internal/handshake" "github.com/lucas-clemente/quic-go/internal/protocol" @@ -349,6 +351,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, enable0RTT bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -402,6 +405,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -431,6 +435,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -491,6 +496,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -594,6 +600,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -656,6 +663,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, enable0RTT bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -689,6 +697,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { @@ -748,6 +757,7 @@ var _ = Describe("Server", func() { _ *tls.Config, _ *handshake.TokenGenerator, _ bool, + _ qlog.Tracer, _ utils.Logger, _ protocol.VersionNumber, ) quicSession { diff --git a/session.go b/session.go index 4d8ec6f6..d3dfb0c9 100644 --- a/session.go +++ b/session.go @@ -20,6 +20,7 @@ import ( "github.com/lucas-clemente/quic-go/internal/qerr" "github.com/lucas-clemente/quic-go/internal/utils" "github.com/lucas-clemente/quic-go/internal/wire" + "github.com/lucas-clemente/quic-go/qlog" "github.com/lucas-clemente/quic-go/quictrace" ) @@ -186,8 +187,9 @@ type session struct { traceCallback func(quictrace.Event) - logID string - logger utils.Logger + logID string + qlogger qlog.Tracer + logger utils.Logger } var _ Session = &session{} @@ -206,6 +208,7 @@ var newSession = func( tlsConf *tls.Config, tokenGenerator *handshake.TokenGenerator, enable0RTT bool, + qlogger qlog.Tracer, logger utils.Logger, v protocol.VersionNumber, ) quicSession { @@ -218,6 +221,7 @@ var newSession = func( oneRTTStream: newCryptoStream(), perspective: protocol.PerspectiveServer, handshakeCompleteChan: make(chan struct{}), + qlogger: qlogger, logger: logger, version: v, } @@ -244,7 +248,7 @@ var newSession = func( s.queueControlFrame, ) s.preSetup() - s.sentPacketHandler = ackhandler.NewSentPacketHandler(0, s.rttStats, s.traceCallback, s.logger) + s.sentPacketHandler = ackhandler.NewSentPacketHandler(0, s.rttStats, s.traceCallback, s.qlogger, s.logger) initialStream := newCryptoStream() handshakeStream := newCryptoStream() params := &handshake.TransportParameters{ @@ -313,6 +317,7 @@ var newClientSession = func( initialPacketNumber protocol.PacketNumber, initialVersion protocol.VersionNumber, enable0RTT bool, + qlogger qlog.Tracer, logger utils.Logger, v protocol.VersionNumber, ) quicSession { @@ -325,6 +330,7 @@ var newClientSession = func( handshakeCompleteChan: make(chan struct{}), logID: destConnID.String(), logger: logger, + qlogger: qlogger, initialVersion: initialVersion, version: v, } @@ -346,7 +352,7 @@ var newClientSession = func( s.queueControlFrame, ) s.preSetup() - s.sentPacketHandler = ackhandler.NewSentPacketHandler(initialPacketNumber, s.rttStats, s.traceCallback, s.logger) + s.sentPacketHandler = ackhandler.NewSentPacketHandler(initialPacketNumber, s.rttStats, s.traceCallback, s.qlogger, s.logger) initialStream := newCryptoStream() handshakeStream := newCryptoStream() params := &handshake.TransportParameters{ @@ -565,6 +571,11 @@ runLoop: s.logger.Infof("Connection %s closed.", s.logID) s.cryptoStreamHandler.Close() s.sendQueue.Close() + if s.qlogger != nil { + if err := s.qlogger.Export(); err != nil { + return err + } + } return closeErr.err } @@ -780,6 +791,9 @@ func (s *session) handleRetryPacket(hdr *wire.Header, data []byte) bool /* was t } s.logger.Debugf("<- Received Retry") s.logger.Debugf("Switching destination connection ID to: %s", hdr.SrcConnectionID) + if s.qlogger != nil { + s.qlogger.ReceivedRetry(time.Now(), hdr) + } s.origDestConnID = s.handshakeDestConnID newDestConnID := hdr.SrcConnectionID s.receivedRetry = true @@ -831,7 +845,7 @@ func (s *session) handleUnpackedPacket(packet *unpackedPacket, rcvTime time.Time if ackhandler.IsFrameAckEliciting(frame) { isAckEliciting = true } - if s.traceCallback != nil { + if s.traceCallback != nil || s.qlogger != nil { frames = append(frames, frame) } if err := s.handleFrame(frame, packet.packetNumber, packet.encryptionLevel); err != nil { @@ -851,6 +865,9 @@ func (s *session) handleUnpackedPacket(packet *unpackedPacket, rcvTime time.Time Frames: frames, }) } + if s.qlogger != nil { + s.qlogger.ReceivedPacket(rcvTime, packet.hdr, protocol.ByteCount(len(packet.data)), frames) + } return s.receivedPacketHandler.ReceivedPacket(packet.packetNumber, packet.encryptionLevel, rcvTime, isAckEliciting) } @@ -1235,7 +1252,6 @@ func (s *session) maybeSendAckOnlyPacket() error { if packet == nil { return nil } - s.sentPacketHandler.SentPacket(packet.ToAckHandlerPacket(s.retransmissionQueue)) s.sendPackedPacket(packet) return nil } @@ -1277,7 +1293,6 @@ func (s *session) sendProbePacket(encLevel protocol.EncryptionLevel) error { if packet == nil { return fmt.Errorf("session BUG: couldn't pack %s probe packet", encLevel) } - s.sentPacketHandler.SentPacket(packet.ToAckHandlerPacket(s.retransmissionQueue)) s.sendPackedPacket(packet) return nil } @@ -1292,7 +1307,6 @@ func (s *session) sendPacket() (bool, error) { if err != nil || packet == nil { return false, err } - s.sentPacketHandler.SentPacket(packet.ToAckHandlerPacket(s.retransmissionQueue)) s.sendPackedPacket(packet) return true, nil } @@ -1301,13 +1315,15 @@ func (s *session) sendPackedPacket(packet *packedPacket) { if s.firstAckElicitingPacketAfterIdleSentTime.IsZero() && packet.IsAckEliciting() { s.firstAckElicitingPacketAfterIdleSentTime = time.Now() } + now := time.Now() + s.sentPacketHandler.SentPacket(packet.ToAckHandlerPacket(now, s.retransmissionQueue)) if s.traceCallback != nil { frames := make([]wire.Frame, 0, len(packet.frames)) for _, f := range packet.frames { frames = append(frames, f.Frame) } s.traceCallback(quictrace.Event{ - Time: time.Now(), + Time: now, EventType: quictrace.PacketSent, TransportState: s.sentPacketHandler.GetStats(), EncryptionLevel: packet.EncryptionLevel(), @@ -1316,6 +1332,13 @@ func (s *session) sendPackedPacket(packet *packedPacket) { Frames: frames, }) } + if s.qlogger != nil { + frames := make([]wire.Frame, 0, len(packet.frames)) + for _, f := range packet.frames { + frames = append(frames, f.Frame) + } + s.qlogger.SentPacket(now, packet.header, protocol.ByteCount(len(packet.raw)), packet.ack, frames) + } s.logPacket(packet) s.connIDManager.SentPacket() s.sendQueue.Send(packet) diff --git a/session_test.go b/session_test.go index 6163648f..dd759e5a 100644 --- a/session_test.go +++ b/session_test.go @@ -92,6 +92,7 @@ var _ = Describe("Session", func() { nil, // tls.Config tokenGenerator, false, + nil, utils.DefaultLogger, protocol.VersionTLS, ).(*session) @@ -1698,6 +1699,7 @@ var _ = Describe("Client Session", func() { 42, // initial packet number protocol.VersionTLS, false, + nil, utils.DefaultLogger, protocol.VersionTLS, ).(*session)