《游戏服务端编程实践》3.4.3 调试与协议日志分析

00000000  47 53 01 01 03 e9 00 00  00 07 00 00 00 0a c0 44  |GS.............D|
00000010  41 8a 00 00 4d 4f 56 45  20 31 30 20 32 30        |A...MOVE 10 20|

// file: ch03/debug/dump.go
// tier: L1
// verify: go test ./ch03/debug/

// Package debug turns raw protocol bytes into evidence: a bounded hex dump,
// a frame parser that can resynchronise after garbage, and log records that
// deliberately carry no payload.
package debug

import (
	"encoding/binary"
	"errors"
	"fmt"
	"io"
	"strings"
	"sync/atomic"
	"time"
)

const (
	HeaderSize = 20
	Magic      = 0x4753 // "GS"
	MaxBody    = 1 << 20
)

var (
	ErrTruncated = errors.New("debug: truncated frame")
	ErrBadMagic  = errors.New("debug: bad magic")
	ErrTooLarge  = errors.New("debug: declared body too large")
)

// Dump writes a classic 16-byte-per-row hex dump. Keeping the offset column
// makes a pasted log usable: a colleague can point at "00000023" instead of
// counting bytes.
func Dump(w io.Writer, data []byte) error {
	for off := 0; off < len(data); off += 16 {
		end := off + 16
		if end > len(data) {
			end = len(data)
		}
		line := data[off:end]

		var b strings.Builder
		fmt.Fprintf(&b, "%08x  ", off)
		for i := 0; i < 16; i++ {
			if i < len(line) {
				fmt.Fprintf(&b, "%02x ", line[i])
			} else {
				b.WriteString("   ")
			}
			if i == 7 {
				b.WriteByte(' ')
			}
		}
		b.WriteString(" |")
		for _, c := range line {
			if c >= 0x20 && c < 0x7f {
				b.WriteByte(c)
			} else {
				b.WriteByte('.')
			}
		}
		b.WriteString("|\n")
		if _, err := io.WriteString(w, b.String()); err != nil {
			return err
		}
	}
	return nil
}

// FrameInfo is the envelope as seen by a log reader. Version is reported but
// not rejected: an unknown version is exactly what you want to see in a
// capture taken from an older or newer client.
type FrameInfo struct {
	Offset   int
	Version  uint8
	Flags    uint8
	Cmd      uint16
	Seq      uint32
	BodyLen  int
	Total    int
	Checksum uint32
}

// ParseFrame parses the frame starting at off and returns the offset of the
// next frame. It never skips bytes on its own; when the magic is wrong the
// caller decides whether to resynchronise or to declare corruption.
func ParseFrame(buf []byte, off int) (FrameInfo, int, error) {
	if off < 0 || off > len(buf) {
		return FrameInfo{}, off, fmt.Errorf("debug: offset %d out of range", off)
	}
	if off == len(buf) {
		return FrameInfo{}, off, io.EOF
	}
	rest := buf[off:]
	if len(rest) < HeaderSize {
		return FrameInfo{}, off, fmt.Errorf("%w: header %d/%d at %d", ErrTruncated, len(rest), HeaderSize, off)
	}
	if got := binary.BigEndian.Uint16(rest[0:2]); got != Magic {
		return FrameInfo{}, off, fmt.Errorf("%w: 0x%04x at %d", ErrBadMagic, got, off)
	}
	bodyLen := binary.BigEndian.Uint32(rest[10:14])
	if bodyLen > MaxBody {
		return FrameInfo{}, off, fmt.Errorf("%w: %d at %d", ErrTooLarge, bodyLen, off)
	}
	total := HeaderSize + int(bodyLen)
	if len(rest) < total {
		return FrameInfo{}, off, fmt.Errorf("%w: have %d need %d at %d", ErrTruncated, len(rest), total, off)
	}
	return FrameInfo{
		Offset:   off,
		Version:  rest[2],
		Flags:    rest[3],
		Cmd:      binary.BigEndian.Uint16(rest[4:6]),
		Seq:      binary.BigEndian.Uint32(rest[6:10]),
		BodyLen:  int(bodyLen),
		Total:    total,
		Checksum: binary.BigEndian.Uint32(rest[14:18]),
	}, off + total, nil
}

// Resync returns the first offset at or after from that could start a frame.
// It is intentionally a cheap byte scan; the caller must still parse and
// verify the candidate before trusting it.
func Resync(buf []byte, from int) int {
	if from < 0 {
		from = 0
	}
	for i := from; i+2 <= len(buf); i++ {
		if buf[i] == byte(Magic>>8) && buf[i+1] == byte(Magic&0xff) {
			return i
		}
	}
	return -1
}

// Record is one application-level log line. There is no Body field on
// purpose: command, sequence and length are enough to correlate a request
// with its response, while payloads may contain tokens or chat text.
type Record struct {
	Time    time.Time
	Dir     string // "C>S" or "S>C"
	Conn    string
	Cmd     uint16
	Seq     uint32
	BodyLen int
	Elapsed time.Duration
	Code    int32
}

func (r Record) String() string {
	return fmt.Sprintf("%s %s conn=%s cmd=0x%04x seq=%d len=%d cost=%s code=%d",
		r.Time.Format("15:04:05.000"), r.Dir, r.Conn, r.Cmd, r.Seq,
		r.BodyLen, r.Elapsed, r.Code)
}

// Sampler keeps full dumps bounded. Every Nth frame is allowed through, so
// the cost stays flat even when the connection is saturated.
type Sampler struct {
	every uint64
	n     atomic.Uint64
}

func NewSampler(every uint64) *Sampler {
	if every == 0 {
		every = 1
	}
	return &Sampler{every: every}
}

func (s *Sampler) Allow() bool {
	return s.n.Add(1)%s.every == 0
}

go test -race ./ch03/debug/