Skip to content

Commit

Permalink
Improve trace stats (#5095)
Browse files Browse the repository at this point in the history 
Allows traces to be replayed in stats mode from `mc admin trace -json ALIAS >trace.json`, using `mc admin trace -in=trace.json`. `.zst` are automatically decompressed.

This is replayed at full speed, since I don't really see any value in keeping original speed.

Add scrolling to stats. Up+Down+Home+End

Add 'r' to reset min/max stats.
  • Loading branch information
@klauspost
klauspost authored Dec 15, 2024
1 parent 1681e44 commit 86907df
Show file tree
Hide file tree
Showing 4 changed files with 164 additions and 26 deletions.
11 changes: 10 additions & 1 deletion cmd/admin-scanner-status.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ import (
"github.com/charmbracelet/lipgloss"
"github.com/dustin/go-humanize"
"github.com/fatih/color"
"github.com/klauspost/compress/zstd"
"github.com/minio/cli"
json "github.com/minio/colorjson"
"github.com/minio/madmin-go/v3"
Expand Down Expand Up @@ -211,7 +212,15 @@ func mainAdminScannerInfo(ctx *cli.Context) error {
}()
f, e := os.Open(inFile)
fatalIf(probe.NewError(e), "Unable to open input")
sc := bufio.NewReader(f)
defer f.Close()
in := io.Reader(f)
if strings.HasSuffix(inFile, ".zst") {
zr, e := zstd.NewReader(in)
fatalIf(probe.NewError(e), "Unable to open input")
defer zr.Close()
in = zr
}
sc := bufio.NewReader(in)
var lastTime time.Time
for {
b, e := sc.ReadBytes('\n')
Expand Down
109 changes: 92 additions & 17 deletions cmd/admin-trace.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,12 +18,15 @@
package cmd

import (
"bufio"
"bytes"
"context"
"fmt"
"hash/fnv"
"io"
"net/http"
"net/url"
"os"
"path"
"sort"
"strings"
Expand All @@ -33,6 +36,7 @@ import (
tea "github.com/charmbracelet/bubbletea"
"github.com/dustin/go-humanize"
"github.com/fatih/color"
"github.com/klauspost/compress/zstd"
"github.com/minio/cli"
json "github.com/minio/colorjson"
"github.com/minio/madmin-go/v3"
Expand Down Expand Up @@ -92,7 +96,7 @@ var adminTraceFlags = []cli.Flag{
cli.IntFlag{
Name: "stats-n",
Usage: "maximum number of stat entries",
Value: 30,
Value: 20,
Hidden: true,
},
cli.BoolFlag{
Expand All @@ -111,6 +115,10 @@ var adminTraceFlags = []cli.Flag{
Name: "filter-size",
Usage: "filter size, use with filter (see UNITS)",
},
cli.StringFlag{
Name: "in",
Usage: "read previously saved json from file and replay",
},
}

// traceCallTypes contains all call types and flags to apply when selected.
Expand Down Expand Up @@ -239,7 +247,7 @@ const traceTimeFormat = "2006-01-02T15:04:05.000"
var colors = []color.Attribute{color.FgCyan, color.FgWhite, color.FgYellow, color.FgGreen}

func checkAdminTraceSyntax(ctx *cli.Context) {
if len(ctx.Args()) != 1 {
if len(ctx.Args()) != 1 && len(ctx.String("in")) == 0 {
showCommandHelpAndExit(ctx, 1) // last argument is exit code
}
filterFlag := ctx.Bool("filter-request") || ctx.Bool("filter-response")
Expand Down Expand Up @@ -489,7 +497,6 @@ func mainAdminTrace(ctx *cli.Context) error {

verbose := ctx.Bool("verbose")
stats := ctx.Bool("stats")
aliasedURL := ctx.Args().Get(0)

console.SetColor("Stat", color.New(color.FgYellow))

Expand All @@ -510,23 +517,78 @@ func mainAdminTrace(ctx *cli.Context) error {
for _, c := range colors {
console.SetColor(fmt.Sprintf("Node%d", c), color.New(c))
}
// Create a new MinIO Admin Client
client, err := newAdminClient(aliasedURL)
if err != nil {
fatalIf(err.Trace(aliasedURL), "Unable to initialize admin client.")
return nil
}

var traceCh <-chan madmin.ServiceTraceInfo

ctxt, cancel := context.WithCancel(globalContext)
defer cancel()

opts, e := tracingOpts(ctx, ctx.StringSlice("call"))
fatalIf(probe.NewError(e), "Unable to start tracing")
if inFile := ctx.String("in"); inFile != "" {
stats = true
ch := make(chan madmin.ServiceTraceInfo, 1000)
traceCh = ch
go func() {
f, e := os.Open(inFile)
fatalIf(probe.NewError(e), "Unable to open input")
defer f.Close()
in := io.Reader(f)
if strings.HasSuffix(inFile, ".zst") {
zr, e := zstd.NewReader(in)
fatalIf(probe.NewError(e), "Unable to open input")
defer zr.Close()
in = zr
}
sc := bufio.NewReader(in)
for ctxt.Err() == nil {
b, e := sc.ReadBytes('\n')
if e == io.EOF {
break
}
var t shortTraceMsg
e = json.Unmarshal(b, &t)
if e != nil || t.Type == "Bootstrap" {
// Ignore bootstrap, since their times skews averages.
continue
}
ch <- madmin.ServiceTraceInfo{
Trace: madmin.TraceInfo{
TraceType: t.trcType, // TODO: Grab from string, once we can.
NodeName: t.Host,
FuncName: t.FuncName,
Time: t.Time,
Path: t.Path,
Duration: t.Duration,
Bytes: t.Size,
Message: t.StatusMsg,
Error: t.Error,
Custom: t.Extra,
HTTP: nil,
HealResult: nil,
},
Err: nil,
}
}
close(ch)
select {}
}()
} else {
// Create a new MinIO Admin Client
aliasedURL := ctx.Args().Get(0)

client, err := newAdminClient(aliasedURL)
if err != nil {
fatalIf(err.Trace(aliasedURL), "Unable to initialize admin client.")
return nil
}

mopts := matchingOpts(ctx)
opts, e := tracingOpts(ctx, ctx.StringSlice("call"))
fatalIf(probe.NewError(e), "Unable to start tracing")

// Start listening on all trace activity.
traceCh := client.ServiceTrace(ctxt, opts)
// Start listening on all trace activity.
traceCh = client.ServiceTrace(ctxt, opts)
}

mopts := matchingOpts(ctx)
if stats {
filteredTraces := make(chan madmin.ServiceTraceInfo, 1)
ui := tea.NewProgram(initTraceStatsUI(ctx.Bool("all"), ctx.Int("stats-n"), filteredTraces))
Expand All @@ -542,12 +604,14 @@ func mainAdminTrace(ctx *cli.Context) error {
filteredTraces <- t
}
}
ui.Send(tea.Quit())
}()
if _, e := ui.Run(); e != nil {
cancel()
if te != nil {
e = te
}
aliasedURL := ctx.Args().Get(0)
fatalIf(probe.NewError(e).Trace(aliasedURL), "Unable to fetch http trace statistics")
}
return nil
Expand Down Expand Up @@ -915,9 +979,10 @@ type statItem struct {
}

type statTrace struct {
Calls map[string]statItem `json:"calls"`
Started time.Time
mu sync.Mutex
Calls map[string]statItem `json:"calls"`
Oldest time.Time
Latest time.Time
mu sync.Mutex
}

func (s *statTrace) JSON() string {
Expand All @@ -942,6 +1007,16 @@ func (s *statTrace) add(t madmin.ServiceTraceInfo) {
id := t.Trace.FuncName
s.mu.Lock()
defer s.mu.Unlock()
if t.Trace.TraceType != madmin.TraceBootstrap {
// We can't use bootstrap to find start/end
ended := t.Trace.Time.Add(t.Trace.Duration)
if s.Oldest.IsZero() {
s.Oldest = ended
}
if ended.After(s.Latest) {
s.Latest = ended
}
}
got := s.Calls[id]
if got.Name == "" {
got.Name = id
Expand Down
11 changes: 10 additions & 1 deletion cmd/support-top-rcp.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ import (
"github.com/charmbracelet/bubbles/spinner"
tea "github.com/charmbracelet/bubbletea"
"github.com/charmbracelet/lipgloss"
"github.com/klauspost/compress/zstd"
"github.com/minio/cli"
json "github.com/minio/colorjson"
"github.com/minio/madmin-go/v3"
Expand Down Expand Up @@ -110,7 +111,15 @@ func mainSupportTopRPC(ctx *cli.Context) error {
}()
f, e := os.Open(inFile)
fatalIf(probe.NewError(e), "Unable to open input")
sc := bufio.NewReader(f)
defer f.Close()
in := io.Reader(f)
if strings.HasSuffix(inFile, ".zst") {
zr, e := zstd.NewReader(in)
fatalIf(probe.NewError(e), "Unable to open input")
defer zr.Close()
in = zr
}
sc := bufio.NewReader(in)
var lastTime time.Time
for {
b, e := sc.ReadBytes('\n')
Expand Down
59 changes: 52 additions & 7 deletions cmd/trace-stats-ui.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,7 @@ type traceStatsUI struct {
meter spinner.Model
quitting bool
maxEntries int
offset int
allFlag bool
}

Expand All @@ -60,6 +61,24 @@ func (m *traceStatsUI) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
case "q", "esc", "ctrl+c":
m.quitting = true
return m, tea.Quit
case "r":
// Reset min/max
m.current.mu.Lock()
defer m.current.mu.Unlock()
for k, si := range m.current.Calls {
si.MaxDur, si.MinDur = 0, 0
si.MaxTTFB = 0
m.current.Calls[k] = si
}
return m, nil
case "down":
m.offset++
case "up":
m.offset--
case "home":
m.offset = 0
case "end":
m.offset = len(m.current.Calls)
default:
return m, nil
}
Expand All @@ -74,8 +93,9 @@ func (m *traceStatsUI) Update(msg tea.Msg) (tea.Model, tea.Cmd) {
func (m *traceStatsUI) View() string {
var s strings.Builder

dur := m.current.Latest.Sub(m.current.Oldest)
s.WriteString(fmt.Sprintf("%s %s\n",
console.Colorize("metrics-top-title", "Duration: "+time.Since(m.current.Started).Round(time.Second).String()), m.meter.View()))
console.Colorize("metrics-top-title", "Duration: "+dur.Round(time.Second).String()), m.meter.View()))

// Set table header - akin to k8s style
// https://github.com/olekukonko/tablewriter#example-10---set-nowhitespace-and-tablepadding-option
Expand All @@ -99,7 +119,6 @@ func (m *traceStatsUI) View() string {
totalRX = 0
totalTX = 0
)
dur := time.Since(m.current.Started)
for _, v := range m.current.Calls {
totalCnt += v.Count
totalRX += v.CallStats.Rx
Expand All @@ -117,8 +136,22 @@ func (m *traceStatsUI) View() string {
}
return entries[i].Count > entries[j].Count
})

frontTrunc := false
endTrunc := false
m.offset = min(max(0, m.offset), len(entries))
offset := m.offset
if m.maxEntries > 0 && len(entries) > m.maxEntries {
entries = entries[:m.maxEntries]
entLeft := len(entries) - offset
if entLeft > m.maxEntries {
// Truncate both ends
entries = entries[offset : m.maxEntries+offset]
frontTrunc = offset > 0
endTrunc = true
} else {
entries = entries[len(entries)-m.maxEntries:]
frontTrunc = true
}
}
hasTTFB := false
for _, e := range entries {
Expand All @@ -141,8 +174,13 @@ func (m *traceStatsUI) View() string {
s.WriteString(console.Colorize("metrics-top-title", fmt.Sprintf("RPM : %0.1f\n", float64(totalCnt)/dur.Minutes())))
s.WriteString("-------------\n")

preCall := ""
if frontTrunc {
preCall = console.Colorize("metrics-error", "↑ ")
}

t := []string{
console.Colorize("metrics-top-title", "Call"),
preCall + console.Colorize("metrics-top-title", "Call"),
console.Colorize("metrics-top-title", "Count"),
console.Colorize("metrics-top-title", "RPM"),
console.Colorize("metrics-top-title", "Avg Time"),
Expand All @@ -162,7 +200,8 @@ func (m *traceStatsUI) View() string {
)

table.Append(t)
for _, v := range entries {

for i, v := range entries {
if v.Count <= 0 {
continue
}
Expand Down Expand Up @@ -221,8 +260,13 @@ func (m *traceStatsUI) View() string {
rate = console.Colorize("metrics-size", rate)
}

preCall = ""
if endTrunc && i == len(entries)-1 {
preCall = console.Colorize("metrics-error", "↓ ")
}

t := []string{
console.Colorize("metrics-title", metricsTitle(v.Name)),
preCall + console.Colorize("metrics-title", metricsTitle(v.Name)),
console.Colorize("metrics-number", fmt.Sprintf("%d ", v.Count)) +
console.Colorize("metrics-number-secondary", fmt.Sprintf("(%0.1f%%)", float64(v.Count)/float64(totalCnt)*100)),
console.Colorize("metrics-number", fmt.Sprintf("%0.1f", float64(v.Count)/dur.Minutes())),
Expand All @@ -242,6 +286,7 @@ func (m *traceStatsUI) View() string {
t = append(t, sz, rate, errs)
table.Append(t)
}

table.Render()
if globalTermWidth <= 10 {
return s.String()
Expand Down Expand Up @@ -293,7 +338,7 @@ func initTraceStatsUI(allFlag bool, maxEntries int, traces <-chan madmin.Service
console.SetColor("metrics-number", color.New(color.FgWhite))
console.SetColor("metrics-number-secondary", color.New(color.FgBlue))
console.SetColor("metrics-zero", color.New(color.FgWhite))
stats := &statTrace{Calls: make(map[string]statItem, 20), Started: time.Now()}
stats := &statTrace{Calls: make(map[string]statItem, 20)}
go func() {
for t := range traces {
stats.add(t)
Expand Down

0 comments on commit 86907df

Please sign in to comment.