quic/qlog/qlog.go - net - Git at Google

 // Copyright 2023 The Go Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style
 // license that can be found in the LICENSE file.

 //go:build go1.21

 // Package qlog serializes qlog events.
 package qlog

 import (
 	"bytes"
 	"context"
 	"errors"
 	"io"
 	"log/slog"
 	"os"
 	"path/filepath"
 	"sync"
 	"time"
 )

 // Vantage is the vantage point of a trace.
 type Vantage string

 const (
 	// VantageEndpoint traces contain events not specific to a single connection.
 	VantageEndpoint = Vantage("endpoint")

 	// VantageClient traces follow a connection from the client's perspective.
 	VantageClient = Vantage("client")

 	// VantageServer traces follow a connection from the server's perspective.
 	VantageServer = Vantage("server")
 )

 // TraceInfo contains information about a trace.
 type TraceInfo struct {
 	// Vantage is the vantage point of the trace.
 	Vantage Vantage

 	// GroupID identifies the logical group the trace belongs to.
 	// For a connection trace, the group will be the same for
 	// both the client and server vantage points.
 	GroupID string
 }

 // HandlerOptions are options for a JSONHandler.
 type HandlerOptions struct {
 	// Level reports the minimum record level that will be logged.
 	// If Level is nil, the handler assumes QLogLevelEndpoint.
 	Level slog.Leveler

 	// Dir is the directory in which to create trace files.
 	// The handler will create one file per connection.
 	// If NewTrace is non-nil or Dir is "", the handler will not create files.
 	Dir string

 	// NewTrace is called to create a new trace.
 	// If NewTrace is nil and Dir is set,
 	// the handler will create a new file in Dir for each trace.
 	NewTrace func(TraceInfo) (io.WriteCloser, error)
 }

 type endpointHandler struct {
 	opts HandlerOptions

 	traceOnce sync.Once
 	trace     *jsonTraceHandler
 }

 // NewJSONHandler returns a handler which serializes qlog events to JSON.
 //
 // The handler will write an endpoint-wide trace,
 // and a separate trace for each connection.
 // The HandlerOptions control the location traces are written.
 //
 // It uses the streamable JSON Text Sequences mapping (JSON-SEQ)
 // defined in draft-ietf-quic-qlog-main-schema-04, Section 6.2.
 //
 // A JSONHandler may be used as the handler for a quic.Config.QLogLogger.
 // It is not a general-purpose slog handler,
 // and may not properly handle events from other sources.
 func NewJSONHandler(opts HandlerOptions) slog.Handler {
 	if opts.Dir == "" && opts.NewTrace == nil {
 		return slogDiscard{}
 	}
 	return &endpointHandler{
 		opts: opts,
 	}
 }

 func (h *endpointHandler) Enabled(ctx context.Context, level slog.Level) bool {
 	return enabled(h.opts.Level, level)
 }

 func (h *endpointHandler) Handle(ctx context.Context, r slog.Record) error {
 	h.traceOnce.Do(func() {
 		h.trace, _ = newJSONTraceHandler(h.opts, nil)
 	})
 	if h.trace != nil {
 		h.trace.Handle(ctx, r)
 	}
 	return nil
 }

 func (h *endpointHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
 	// Create a new trace output file for each top-level WithAttrs.
 	tr, err := newJSONTraceHandler(h.opts, attrs)
 	if err != nil {
 		return withAttrs(h, attrs)
 	}
 	return tr
 }

 func (h *endpointHandler) WithGroup(name string) slog.Handler {
 	return withGroup(h, name)
 }

 type jsonTraceHandler struct {
 	level slog.Leveler
 	w     jsonWriter
 	start time.Time
 	buf   bytes.Buffer
 }

 func newJSONTraceHandler(opts HandlerOptions, attrs []slog.Attr) (*jsonTraceHandler, error) {
 	w, err := newTraceWriter(opts, traceInfoFromAttrs(attrs))
 	if err != nil {
 		return nil, err
 	}

 	// For testing, it might be nice to set the start time used for relative timestamps
 	// to the time of the first event.
 	//
 	// At the expense of some additional complexity here, we could defer writing
 	// the reference_time header field until the first event is processed.
 	//
 	// Just use the current time for now.
 	start := time.Now()

 	h := &jsonTraceHandler{
 		w:     jsonWriter{w: w},
 		level: opts.Level,
 		start: start,
 	}
 	h.writeHeader(attrs)
 	return h, nil
 }

 func traceInfoFromAttrs(attrs []slog.Attr) TraceInfo {
 	info := TraceInfo{
 		Vantage: VantageEndpoint, // default if not specified
 	}
 	for _, a := range attrs {
 		if a.Key == "group_id" && a.Value.Kind() == slog.KindString {
 			info.GroupID = a.Value.String()
 		}
 		if a.Key == "vantage_point" && a.Value.Kind() == slog.KindGroup {
 			for _, aa := range a.Value.Group() {
 				if aa.Key == "type" && aa.Value.Kind() == slog.KindString {
 					info.Vantage = Vantage(aa.Value.String())
 				}
 			}
 		}
 	}
 	return info
 }

 func newTraceWriter(opts HandlerOptions, info TraceInfo) (io.WriteCloser, error) {
 	var w io.WriteCloser
 	var err error
 	if opts.NewTrace != nil {
 		w, err = opts.NewTrace(info)
 	} else if opts.Dir != "" {
 		var filename string
 		if info.GroupID != "" {
 			filename = info.GroupID + "_"
 		}
 		filename += string(info.Vantage) + ".sqlog"
 		if !filepath.IsLocal(filename) {
 			return nil, errors.New("invalid trace filename")
 		}
 		w, err = os.OpenFile(filepath.Join(opts.Dir, filename), os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0666)
 	} else {
 		err = errors.New("no log destination")
 	}
 	return w, err
 }

 func (h *jsonTraceHandler) writeHeader(attrs []slog.Attr) {
 	h.w.writeRecordStart()
 	defer h.w.writeRecordEnd()

 	// At the time of writing this comment the most recent version is 0.4,
 	// but qvis only supports up to 0.3.
 	h.w.writeStringField("qlog_version", "0.3")
 	h.w.writeStringField("qlog_format", "JSON-SEQ")

 	// The attrs flatten both common trace event fields and Trace fields.
 	// This identifies the fields that belong to the Trace.
 	isTraceSeqField := func(s string) bool {
 		switch s {
 		case "title", "description", "configuration", "vantage_point":
 			return true
 		}
 		return false
 	}

 	h.w.writeObjectField("trace", func() {
 		h.w.writeObjectField("common_fields", func() {
 			h.w.writeRawField("protocol_type", `["QUIC"]`)
 			h.w.writeStringField("time_format", "relative")
 			h.w.writeTimeField("reference_time", h.start)
 			for _, a := range attrs {
 				if !isTraceSeqField(a.Key) {
 					h.w.writeAttr(a)
 				}
 			}
 		})
 		for _, a := range attrs {
 			if isTraceSeqField(a.Key) {
 				h.w.writeAttr(a)
 			}
 		}
 	})
 }

 func (h *jsonTraceHandler) Enabled(ctx context.Context, level slog.Level) bool {
 	return enabled(h.level, level)
 }

 func (h *jsonTraceHandler) Handle(ctx context.Context, r slog.Record) error {
 	h.w.writeRecordStart()
 	defer h.w.writeRecordEnd()
 	h.w.writeDurationField("time", r.Time.Sub(h.start))
 	h.w.writeStringField("name", r.Message)
 	h.w.writeObjectField("data", func() {
 		r.Attrs(func(a slog.Attr) bool {
 			h.w.writeAttr(a)
 			return true
 		})
 	})
 	return nil
 }

 func (h *jsonTraceHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
 	return withAttrs(h, attrs)
 }

 func (h *jsonTraceHandler) WithGroup(name string) slog.Handler {
 	return withGroup(h, name)
 }

 func enabled(leveler slog.Leveler, level slog.Level) bool {
 	var minLevel slog.Level
 	if leveler != nil {
 		minLevel = leveler.Level()
 	}
 	return level >= minLevel
 }

 type slogDiscard struct{}

 func (slogDiscard) Enabled(context.Context, slog.Level) bool        { return false }
 func (slogDiscard) Handle(ctx context.Context, r slog.Record) error { return nil }
 func (slogDiscard) WithAttrs(attrs []slog.Attr) slog.Handler        { return slogDiscard{} }
 func (slogDiscard) WithGroup(name string) slog.Handler              { return slogDiscard{} }
	// Copyright 2023 The Go Authors. All rights reserved.
	// Use of this source code is governed by a BSD-style
	// license that can be found in the LICENSE file.

	//go:build go1.21

	// Package qlog serializes qlog events.
	package qlog

	import (
	"bytes"
	"context"
	"errors"
	"io"
	"log/slog"
	"os"
	"path/filepath"
	"sync"
	"time"
	)

	// Vantage is the vantage point of a trace.
	type Vantage string

	const (
	// VantageEndpoint traces contain events not specific to a single connection.
	VantageEndpoint = Vantage("endpoint")

	// VantageClient traces follow a connection from the client's perspective.
	VantageClient = Vantage("client")

	// VantageServer traces follow a connection from the server's perspective.
	VantageServer = Vantage("server")
	)

	// TraceInfo contains information about a trace.
	type TraceInfo struct {
	// Vantage is the vantage point of the trace.
	Vantage Vantage

	// GroupID identifies the logical group the trace belongs to.
	// For a connection trace, the group will be the same for
	// both the client and server vantage points.
	GroupID string
	}

	// HandlerOptions are options for a JSONHandler.
	type HandlerOptions struct {
	// Level reports the minimum record level that will be logged.
	// If Level is nil, the handler assumes QLogLevelEndpoint.
	Level slog.Leveler

	// Dir is the directory in which to create trace files.
	// The handler will create one file per connection.
	// If NewTrace is non-nil or Dir is "", the handler will not create files.
	Dir string

	// NewTrace is called to create a new trace.
	// If NewTrace is nil and Dir is set,
	// the handler will create a new file in Dir for each trace.
	NewTrace func(TraceInfo) (io.WriteCloser, error)
	}

	type endpointHandler struct {
	opts HandlerOptions

	traceOnce sync.Once
	trace *jsonTraceHandler
	}

	// NewJSONHandler returns a handler which serializes qlog events to JSON.
	//
	// The handler will write an endpoint-wide trace,
	// and a separate trace for each connection.
	// The HandlerOptions control the location traces are written.
	//
	// It uses the streamable JSON Text Sequences mapping (JSON-SEQ)
	// defined in draft-ietf-quic-qlog-main-schema-04, Section 6.2.
	//
	// A JSONHandler may be used as the handler for a quic.Config.QLogLogger.
	// It is not a general-purpose slog handler,
	// and may not properly handle events from other sources.
	func NewJSONHandler(opts HandlerOptions) slog.Handler {
	if opts.Dir == "" && opts.NewTrace == nil {
	return slogDiscard{}
	}
	return &endpointHandler{
	opts: opts,
	}
	}

	func (h *endpointHandler) Enabled(ctx context.Context, level slog.Level) bool {
	return enabled(h.opts.Level, level)
	}

	func (h *endpointHandler) Handle(ctx context.Context, r slog.Record) error {
	h.traceOnce.Do(func() {
	h.trace, _ = newJSONTraceHandler(h.opts, nil)
	})
	if h.trace != nil {
	h.trace.Handle(ctx, r)
	}
	return nil
	}

	func (h *endpointHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
	// Create a new trace output file for each top-level WithAttrs.
	tr, err := newJSONTraceHandler(h.opts, attrs)
	if err != nil {
	return withAttrs(h, attrs)
	}
	return tr
	}

	func (h *endpointHandler) WithGroup(name string) slog.Handler {
	return withGroup(h, name)
	}

	type jsonTraceHandler struct {
	level slog.Leveler
	w jsonWriter
	start time.Time
	buf bytes.Buffer
	}

	func newJSONTraceHandler(opts HandlerOptions, attrs []slog.Attr) (*jsonTraceHandler, error) {
	w, err := newTraceWriter(opts, traceInfoFromAttrs(attrs))
	if err != nil {
	return nil, err
	}

	// For testing, it might be nice to set the start time used for relative timestamps
	// to the time of the first event.
	//
	// At the expense of some additional complexity here, we could defer writing
	// the reference_time header field until the first event is processed.
	//
	// Just use the current time for now.
	start := time.Now()

	h := &jsonTraceHandler{
	w: jsonWriter{w: w},
	level: opts.Level,
	start: start,
	}
	h.writeHeader(attrs)
	return h, nil
	}

	func traceInfoFromAttrs(attrs []slog.Attr) TraceInfo {
	info := TraceInfo{
	Vantage: VantageEndpoint, // default if not specified
	}
	for _, a := range attrs {
	if a.Key == "group_id" && a.Value.Kind() == slog.KindString {
	info.GroupID = a.Value.String()
	}
	if a.Key == "vantage_point" && a.Value.Kind() == slog.KindGroup {
	for _, aa := range a.Value.Group() {
	if aa.Key == "type" && aa.Value.Kind() == slog.KindString {
	info.Vantage = Vantage(aa.Value.String())
	}
	}
	}
	}
	return info
	}

	func newTraceWriter(opts HandlerOptions, info TraceInfo) (io.WriteCloser, error) {
	var w io.WriteCloser
	var err error
	if opts.NewTrace != nil {
	w, err = opts.NewTrace(info)
	} else if opts.Dir != "" {
	var filename string
	if info.GroupID != "" {
	filename = info.GroupID + "_"
	}
	filename += string(info.Vantage) + ".sqlog"
	if !filepath.IsLocal(filename) {
	return nil, errors.New("invalid trace filename")
	}
	w, err = os.OpenFile(filepath.Join(opts.Dir, filename), os.O_CREATE\|os.O_EXCL\|os.O_WRONLY, 0666)
	} else {
	err = errors.New("no log destination")
	}
	return w, err
	}

	func (h *jsonTraceHandler) writeHeader(attrs []slog.Attr) {
	h.w.writeRecordStart()
	defer h.w.writeRecordEnd()

	// At the time of writing this comment the most recent version is 0.4,
	// but qvis only supports up to 0.3.
	h.w.writeStringField("qlog_version", "0.3")
	h.w.writeStringField("qlog_format", "JSON-SEQ")

	// The attrs flatten both common trace event fields and Trace fields.
	// This identifies the fields that belong to the Trace.
	isTraceSeqField := func(s string) bool {
	switch s {
	case "title", "description", "configuration", "vantage_point":
	return true
	}
	return false
	}

	h.w.writeObjectField("trace", func() {
	h.w.writeObjectField("common_fields", func() {
	h.w.writeRawField("protocol_type", `["QUIC"]`)
	h.w.writeStringField("time_format", "relative")
	h.w.writeTimeField("reference_time", h.start)
	for _, a := range attrs {
	if !isTraceSeqField(a.Key) {
	h.w.writeAttr(a)
	}
	}
	})
	for _, a := range attrs {
	if isTraceSeqField(a.Key) {
	h.w.writeAttr(a)
	}
	}
	})
	}

	func (h *jsonTraceHandler) Enabled(ctx context.Context, level slog.Level) bool {
	return enabled(h.level, level)
	}

	func (h *jsonTraceHandler) Handle(ctx context.Context, r slog.Record) error {
	h.w.writeRecordStart()
	defer h.w.writeRecordEnd()
	h.w.writeDurationField("time", r.Time.Sub(h.start))
	h.w.writeStringField("name", r.Message)
	h.w.writeObjectField("data", func() {
	r.Attrs(func(a slog.Attr) bool {
	h.w.writeAttr(a)
	return true
	})
	})
	return nil
	}

	func (h *jsonTraceHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
	return withAttrs(h, attrs)
	}

	func (h *jsonTraceHandler) WithGroup(name string) slog.Handler {
	return withGroup(h, name)
	}

	func enabled(leveler slog.Leveler, level slog.Level) bool {
	var minLevel slog.Level
	if leveler != nil {
	minLevel = leveler.Level()
	}
	return level >= minLevel
	}

	type slogDiscard struct{}

	func (slogDiscard) Enabled(context.Context, slog.Level) bool { return false }
	func (slogDiscard) Handle(ctx context.Context, r slog.Record) error { return nil }
	func (slogDiscard) WithAttrs(attrs []slog.Attr) slog.Handler { return slogDiscard{} }
	func (slogDiscard) WithGroup(name string) slog.Handler { return slogDiscard{} }