qlog: add a default tracer that writes to QLOGDIR (#4233)

* add qlog default tracer which writes to QLOGDIR

* gofumpt

* add qlog default tracer which writes to QLOGDIR

* fix flaky tests

* Update README.md

Co-authored-by: Marten Seemann <martenseemann@gmail.com>

* Update README.md

Co-authored-by: Marten Seemann <martenseemann@gmail.com>

* Update README.md

Co-authored-by: Marten Seemann <martenseemann@gmail.com>

* Update README.md

Co-authored-by: Marten Seemann <martenseemann@gmail.com>

---------

Co-authored-by: Marten Seemann <martenseemann@gmail.com>

README.md

@@ -183,26 +183,20 @@ quic-go logs a wide range of events defined in [draft-ietf-quic-qlog-quic-events
 
 qlog files can be processed by a number of 3rd-party tools. [qviz](https://qvis.quictools.info/) has proven very useful for debugging all kinds of QUIC connection failures.
 
-qlog is activated by setting a `Tracer` callback on the `Config`. It is called as soon as quic-go decides to starts the QUIC handshake on a new connection.
+qlog can be activated by setting the `Tracer` callback on the `Config`. It is called as soon as quic-go decides to start the QUIC handshake on a new connection.
-A useful implementation of this callback could look like this:
+`qlog.DefaultTracer` provides a tracer implementation which writes qlog files to a directory specified by the `QLOGDIR` environment variable, if set.
+The default qlog tracer can be used like this:
 ```go
 quic.Config{
-  Tracer: func(ctx context.Context, p logging.Perspective, connID quic.ConnectionID) *logging.ConnectionTracer {
+  Tracer: qlog.DefaultTracer,
-    role := "server"
-    if p == logging.PerspectiveClient {
-      role = "client"
-    }
-    filename := fmt.Sprintf("./log_%s_%s.qlog", connID, role)
-    f, err := os.Create(filename)
-    // handle the error
-    return qlog.NewConnectionTracer(f, p, connID)
-  }
 }
 ```
 
-This implementation of the callback creates a new qlog file in the current directory named `log_<client / server>_<QUIC connection ID>.qlog`.
+This example creates a new qlog file under `<QLOGDIR>/<Original Destination Connection ID>_<Vantage Point>.qlog`, e.g. `qlogs/2e0407da_client.qlog`.
 
 
+For custom qlog behavior, `qlog.NewConnectionTracer` can be used.
+
 ## Using HTTP/3
 
 ### As a server

integrationtests/self/qlog_dir_test.go

@@ -0,0 +1,90 @@
+package self_test
+
+import (
+	"context"
+	"os"
+	"path"
+	"regexp"
+
+	. "github.com/onsi/ginkgo/v2"
+	. "github.com/onsi/gomega"
+	"github.com/quic-go/quic-go"
+	"github.com/quic-go/quic-go/qlog"
+)
+
+var _ = Describe("qlog dir tests", Serial, func() {
+	var originalQlogDirValue string
+	var tempTestDirPath string
+
+	BeforeEach(func() {
+		originalQlogDirValue = os.Getenv("QLOGDIR")
+		var err error
+		tempTestDirPath, err = os.MkdirTemp("", "temp_test_dir")
+		Expect(err).ToNot(HaveOccurred())
+	})
+
+	AfterEach(func() {
+		err := os.Setenv("QLOGDIR", originalQlogDirValue)
+		Expect(err).ToNot(HaveOccurred())
+		err = os.RemoveAll(tempTestDirPath)
+		Expect(err).ToNot(HaveOccurred())
+	})
+
+	handshake := func() {
+		serverStopped := make(chan struct{})
+		server, err := quic.ListenAddr(
+			"localhost:0",
+			getTLSConfig(),
+			&quic.Config{
+				Tracer: qlog.DefaultTracer,
+			},
+		)
+		Expect(err).ToNot(HaveOccurred())
+
+		go func() {
+			defer GinkgoRecover()
+			defer close(serverStopped)
+			for {
+				if _, err := server.Accept(context.Background()); err != nil {
+					return
+				}
+			}
+		}()
+
+		conn, err := quic.DialAddr(
+			context.Background(),
+			server.Addr().String(),
+			getTLSClientConfig(),
+			&quic.Config{
+				Tracer: qlog.DefaultTracer,
+			},
+		)
+		Expect(err).ToNot(HaveOccurred())
+		conn.CloseWithError(0, "")
+		server.Close()
+		<-serverStopped
+	}
+
+	It("environment variable is set", func() {
+		qlogDir := path.Join(tempTestDirPath, "qlogs")
+		err := os.Setenv("QLOGDIR", qlogDir)
+		Expect(err).ToNot(HaveOccurred())
+		handshake()
+		_, err = os.Stat(tempTestDirPath)
+		qlogDirCreated := !os.IsNotExist(err)
+		Expect(qlogDirCreated).To(BeTrue())
+		childs, err := os.ReadDir(qlogDir)
+		Expect(err).ToNot(HaveOccurred())
+		Expect(len(childs)).To(Equal(2))
+		odcids := make([]string, 0)
+		vantagePoints := make([]string, 0)
+		qlogFileNameRegexp := regexp.MustCompile(`^([0-f]+)_(client|server).qlog$`)
+		for _, child := range childs {
+			matches := qlogFileNameRegexp.FindStringSubmatch(child.Name())
+			odcids = append(odcids, matches[1])
+			vantagePoints = append(vantagePoints, matches[2])
+		}
+		Expect(odcids[0]).To(Equal(odcids[1]))
+		Expect(vantagePoints).To(ContainElements("client", "server"))
+	})
+})

qlog/qlog_dir.go

@@ -0,0 +1,49 @@
+package qlog
+
+import (
+	"bufio"
+	"context"
+	"fmt"
+	"log"
+	"os"
+	"strings"
+
+	"github.com/quic-go/quic-go/internal/utils"
+	"github.com/quic-go/quic-go/logging"
+)
+
+// DefaultTracer creates a qlog file in the qlog directory specified by the QLOGDIR environment variable.
+// File names are <odcid>_<perspective>.qlog.
+// Returns nil if QLOGDIR is not set.
+func DefaultTracer(_ context.Context, p logging.Perspective, connID logging.ConnectionID) *logging.ConnectionTracer {
+	var label string
+	switch p {
+	case logging.PerspectiveClient:
+		label = "client"
+	case logging.PerspectiveServer:
+		label = "server"
+	}
+	return qlogDirTracer(p, connID, label)
+}
+
+// qlogDirTracer creates a qlog file in the qlog directory specified by the QLOGDIR environment variable.
+// File names are <odcid>_<label>.qlog.
+// Returns nil if QLOGDIR is not set.
+func qlogDirTracer(p logging.Perspective, connID logging.ConnectionID, label string) *logging.ConnectionTracer {
+	qlogDir := os.Getenv("QLOGDIR")
+	if qlogDir == "" {
+		return nil
+	}
+	if _, err := os.Stat(qlogDir); os.IsNotExist(err) {
+		if err := os.MkdirAll(qlogDir, 0o755); err != nil {
+			log.Fatalf("failed to create qlog dir %s: %v", qlogDir, err)
+		}
+	}
+	path := fmt.Sprintf("%s/%s_%s.qlog", strings.TrimRight(qlogDir, "/"), connID, label)
+	f, err := os.Create(path)
+	if err != nil {
+		log.Printf("Failed to create qlog file %s: %s", path, err.Error())
+		return nil
+	}
+	return NewConnectionTracer(utils.NewBufferedWriteCloser(bufio.NewWriter(f), f), p, connID)
+}

qlog/qlog_dir_test.go

@@ -0,0 +1,56 @@
+package qlog
+
+import (
+	"context"
+	"os"
+	"path"
+
+	. "github.com/onsi/ginkgo/v2"
+	. "github.com/onsi/gomega"
+	"github.com/quic-go/quic-go/internal/protocol"
+	"github.com/quic-go/quic-go/logging"
+)
+
+var _ = Describe("qlog dir tests", Serial, func() {
+	var originalQlogDirValue string
+	var tempTestDirPath string
+	ctx := context.Background()
+	perspective := logging.PerspectiveClient
+	connID, _ := protocol.GenerateConnectionIDForInitial()
+
+	BeforeEach(func() {
+		originalQlogDirValue = os.Getenv("QLOGDIR")
+		var err error
+		tempTestDirPath, err = os.MkdirTemp("", "temp_test_dir")
+		Expect(err).ToNot(HaveOccurred())
+	})
+
+	AfterEach(func() {
+		err := os.Setenv("QLOGDIR", originalQlogDirValue)
+		Expect(err).ToNot(HaveOccurred())
+		err = os.RemoveAll(tempTestDirPath)
+		Expect(err).ToNot(HaveOccurred())
+	})
+
+	It("environment variable is set", func() {
+		qlogDir := path.Join(tempTestDirPath, "qlogs")
+		err := os.Setenv("QLOGDIR", qlogDir)
+		Expect(err).ToNot(HaveOccurred())
+		tracer := DefaultTracer(ctx, perspective, connID)
+		Expect(tracer).ToNot(BeNil())
+		tracer.Close()
+		_, err = os.Stat(qlogDir)
+		qlogDirCreated := !os.IsNotExist(err)
+		Expect(qlogDirCreated).To(BeTrue())
+		childs, err := os.ReadDir(qlogDir)
+		Expect(err).ToNot(HaveOccurred())
+		Expect(len(childs)).To(Equal(1))
+	})
+
+	It("environment variable is not set", func() {
+		err := os.Setenv("QLOGDIR", "")
+		Expect(err).ToNot(HaveOccurred())
+		tracer := DefaultTracer(ctx, perspective, connID)
+		Expect(tracer).To(BeNil())
+	})
+})