Skip to content

Commit

Permalink
Add sizes to mc admin trace (#4949)
Browse files Browse the repository at this point in the history 
```
Regular trace:

2024-06-03T14:18:37.303 [STORAGE] storage.ReadXL 127.0.0.1:9001 e:\data\distxl\s1\d3 warp-benchmark-bucket pz9WSPPj/4.TnpU8KEot9t4zl66.rnd 538.3µs 1003 B

With -v:

127.0.0.1:9001  [STORAGE storage.ReadXL] [2024-06-03T14:14:51.680] e:\data\distxl\s1\d3 warp-benchmark-bucket yvhiOPYp/117.hjDOOH6KmAhtC0Ty.rnd total-errs-availability=0 total-errs-timeout=0 0s 1003 B

With -stats

Duration: 21s ∙∙●
Call                            Count           RPM     Avg Time        Min Time        Max Time        Avg TTFB        Max TTFB        Avg Size        Errors
storage.ReadXL                  15808 (67.2%)   44344.8 429µs           0s              69.9984ms       0s              0s              1.2 KiB         0
storage.Delete                  3088 (13.1%)    8662.5  2.056ms         9.7075ms        305.0662ms      0s              0s              -               3

http stats:

Duration: 14s ∙∙●
Call                            Count           RPM     Avg Time        Min Time        Max Time        Avg TTFB        Max TTFB        Avg Size        Errors
s3.GetObject                    4532 (44.1%)    19502.8 1.121ms         267.5µs         67.9369ms       1.098ms         67.9369ms       ↓77 B ↑1000 B   0
s3.HeadObject                   3028 (29.4%)    13030.6 1.031ms         506.8µs         62.9893ms       0s              0s              ↓77 B           0
s3.PutObject                    1711 (16.6%)    7363.1  21.109ms        2.5496ms        181.8214ms      9µs             10.6771ms       ↓1.3 KiB ↑0 B   0
s3.DeleteObject                 1008 (9.8%)     4337.8  56.204ms        1.5859ms        411.1034ms      1.185ms         175.1619ms      ↓77 B ↑4 B      0
s3.DeleteMultipleObjects        1 (0.0%)        4.3     316.358ms       316.3584ms      316.3584ms      315.306ms       315.3055ms      ↓23 KiB ↑24 KiB 0

```

Backwards compatible, but will start displaying non-zero after: minio/minio#19851 and  minio/minio#19864
  • Loading branch information
@klauspost
klauspost authored Jun 5, 2024
1 parent 3cfa864 commit 3997483
Show file tree
Hide file tree
Showing 4 changed files with 95 additions and 38 deletions.
125 changes: 91 additions & 34 deletions cmd/admin-trace.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (
"hash/fnv"
"net/http"
"net/url"
"os"
"path"
"sort"
"strconv"
Expand All @@ -41,7 +42,9 @@ import (
"github.com/minio/madmin-go/v3"
"github.com/minio/mc/pkg/probe"
"github.com/minio/pkg/v3/console"
"github.com/muesli/reflow/truncate"
"github.com/olekukonko/tablewriter"
"golang.org/x/term"
)

var adminTraceFlags = []cli.Flag{
Expand Down Expand Up @@ -582,6 +585,7 @@ type shortTraceMsg struct {
StatusCode int `json:"statusCode"`
StatusMsg string `json:"statusMsg"`
Type string `json:"type"`
Size int64 `json:"size,omitempty"`
Error string `json:"error"`
Extra map[string]string `json:"extra"`
trcType madmin.TraceType
Expand Down Expand Up @@ -650,6 +654,7 @@ func shortTrace(ti madmin.ServiceTraceInfo) shortTraceMsg {
s.Duration = t.Duration
s.StatusMsg = t.Message
s.Extra = t.Custom
s.Size = t.Bytes

switch t.TraceType {
case madmin.TraceS3, madmin.TraceInternal:
Expand Down Expand Up @@ -703,10 +708,15 @@ func (s shortTraceMsg) String() string {
console.Colorize("ErrStatus", s.Error),
console.Colorize("HeaderValue", s.Duration))
} else {
fmt.Fprintf(b, "[%s] %s %s %s %2s", console.Colorize("RespStatus", strings.ToUpper(s.trcType.String())), console.Colorize("FuncName", s.FuncName),
sz := ""
if s.Size != 0 {
sz = fmt.Sprintf(" %s", humanize.IBytes(uint64(s.Size)))
}
fmt.Fprintf(b, "[%s] %s %s %s %2s%s", console.Colorize("RespStatus", strings.ToUpper(s.trcType.String())), console.Colorize("FuncName", s.FuncName),
hostStr,
s.Path,
console.Colorize("HeaderValue", s.Duration))
console.Colorize("HeaderValue", s.Duration),
sz)
}
return b.String()
}
Expand Down Expand Up @@ -839,10 +849,14 @@ func (t traceMessage) String() string {
fmt.Fprintf(b, "%s %s [%s] %s%s", nodeNameStr, console.Colorize("Request", fmt.Sprintf("[%s %s]", strings.ToUpper(trc.TraceType.String()), trc.FuncName)), trc.Time.Local().Format(traceTimeFormat), trc.Message, extra)
return b.String()
default:
sz := ""
if trc.Bytes != 0 {
sz = fmt.Sprintf(" %s", humanize.IBytes(uint64(trc.Bytes)))
}
if trc.Error != "" {
fmt.Fprintf(b, "%s %s [%s] %s%s err='%s' %s", nodeNameStr, console.Colorize("Request", fmt.Sprintf("[%s %s]", strings.ToUpper(trc.TraceType.String()), trc.FuncName)), trc.Time.Local().Format(traceTimeFormat), trc.Path, extra, console.Colorize("ErrStatus", trc.Error), trc.Duration)
fmt.Fprintf(b, "%s %s [%s] %s%s err='%s' %s%s", nodeNameStr, console.Colorize("Request", fmt.Sprintf("[%s %s]", strings.ToUpper(trc.TraceType.String()), trc.FuncName)), trc.Time.Local().Format(traceTimeFormat), trc.Path, extra, console.Colorize("ErrStatus", trc.Error), trc.Duration, sz)
} else {
fmt.Fprintf(b, "%s %s [%s] %s%s %s", nodeNameStr, console.Colorize("Request", fmt.Sprintf("[%s %s]", strings.ToUpper(trc.TraceType.String()), trc.FuncName)), trc.Time.Local().Format(traceTimeFormat), trc.Path, extra, trc.Duration)
fmt.Fprintf(b, "%s %s [%s] %s%s %s%s", nodeNameStr, console.Colorize("Request", fmt.Sprintf("[%s %s]", strings.ToUpper(trc.TraceType.String()), trc.FuncName)), trc.Time.Local().Format(traceTimeFormat), trc.Path, extra, trc.Duration, sz)
}
return b.String()
}
Expand Down Expand Up @@ -903,6 +917,7 @@ type statItem struct {
MaxTTFB time.Duration `json:"maxTTFB,omitempty"`
MaxDur time.Duration `json:"maxDuration"`
MinDur time.Duration `json:"minDuration"`
Size int64 `json:"size"`
}

type statTrace struct {
Expand Down Expand Up @@ -951,6 +966,7 @@ func (s *statTrace) add(t madmin.ServiceTraceInfo) {
if t.Trace.Error != "" {
got.Errors++
}
got.Size += t.Trace.Bytes
if t.Trace.HTTP != nil {
got.CallStatsCount++
got.CallStats.Rx += t.Trace.HTTP.CallStats.InputBytes
Expand All @@ -966,9 +982,10 @@ func (s *statTrace) add(t madmin.ServiceTraceInfo) {
func initTraceStatsUI(maxEntries int, traces <-chan madmin.ServiceTraceInfo) *traceStatsUI {
s := spinner.New()
s.Spinner = spinner.Points
s.Spinner.FPS = time.Second / 4
s.Spinner.FPS = time.Second / 2
s.Style = lipgloss.NewStyle().Foreground(lipgloss.Color("205"))
console.SetColor("metrics-duration", color.New(color.FgWhite))
console.SetColor("metrics-size", color.New(color.FgGreen))
console.SetColor("metrics-dur", color.New(color.FgGreen))
console.SetColor("metrics-dur-med", color.New(color.FgYellow))
console.SetColor("metrics-dur-high", color.New(color.FgRed))
Expand Down Expand Up @@ -1043,17 +1060,8 @@ func (m *traceStatsUI) View() string {
table.SetRowSeparator("")
table.SetHeaderLine(false)
table.SetBorder(false)
table.SetTablePadding("\t") // pad with tabs
table.SetTablePadding(" ") // pad with tabs
table.SetNoWhiteSpace(true)
addRow := func(s string) {
table.Append([]string{s})
}
_ = addRow
addRowF := func(format string, vals ...interface{}) {
s := fmt.Sprintf(format, vals...)
table.Append([]string{s})
}
_ = addRowF
var entries []statItem
m.current.mu.Lock()
totalCnt := 0
Expand All @@ -1076,20 +1084,34 @@ func (m *traceStatsUI) View() string {
if m.maxEntries > 0 && len(entries) > m.maxEntries {
entries = entries[:m.maxEntries]
}

table.Append([]string{
hasTTFB := false
for _, e := range entries {
if e.TTFB > 0 {
hasTTFB = true
break
}
}
t := []string{
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"),
console.Colorize("metrics-top-title", "Min Time"),
console.Colorize("metrics-top-title", "Max Time"),
console.Colorize("metrics-top-title", "Avg TTFB"),
console.Colorize("metrics-top-title", "Max TTFB"),
}
if hasTTFB {
t = append(t,
console.Colorize("metrics-top-title", "Avg TTFB"),
console.Colorize("metrics-top-title", "Max TTFB"),
)
}
t = append(t,
console.Colorize("metrics-top-title", "Avg Size"),
console.Colorize("metrics-top-title", "Rate"),
console.Colorize("metrics-top-title", "Errors"),
console.Colorize("metrics-top-title", "RX Avg"),
console.Colorize("metrics-top-title", "TX Avg"),
})
)

table.Append(t)
for _, v := range entries {
if v.Count <= 0 {
continue
Expand Down Expand Up @@ -1121,27 +1143,62 @@ func (m *traceStatsUI) View() string {
maxColor = "metrics-dur-med"
}

rx := "-"
tx := "-"
sz := "-"
rate := "-"
if v.Size > 0 && v.Count > 0 {
sz = humanize.IBytes(uint64(v.Size) / uint64(v.Count))
rate = fmt.Sprintf("%s/m", humanize.IBytes(uint64(float64(v.Size)/dur.Minutes())))
}
if v.CallStatsCount > 0 {
rx = humanize.IBytes(uint64(v.CallStats.Rx / v.CallStatsCount))
tx = humanize.IBytes(uint64(v.CallStats.Tx / v.CallStatsCount))
var s, r []string
if v.CallStats.Rx > 0 {
s = append(s, fmt.Sprintf("↓%s", humanize.IBytes(uint64(v.CallStats.Rx/v.CallStatsCount))))
r = append(r, fmt.Sprintf("↓%s", humanize.IBytes(uint64(float64(v.CallStats.Rx)/dur.Minutes()))))
}
if v.CallStats.Tx > 0 {
s = append(s, fmt.Sprintf("↑%s", humanize.IBytes(uint64(v.CallStats.Tx/v.CallStatsCount))))
r = append(r, fmt.Sprintf("↑%s", humanize.IBytes(uint64(float64(v.CallStats.Tx)/dur.Minutes()))))
}
if len(s) > 0 {
sz = strings.Join(s, " ")
rate = strings.Join(r, " ") + "/m"
}
}
table.Append([]string{
if sz != "-" {
sz = console.Colorize("metrics-size", sz)
rate = console.Colorize("metrics-size", rate)
}

t := []string{
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())),
console.Colorize(avgColor, fmt.Sprintf("%v", avg.Round(time.Microsecond))),
console.Colorize(minColor, v.MinDur),
console.Colorize(maxColor, v.MaxDur),
console.Colorize(avgColor, fmt.Sprintf("%v", avgTTFB.Round(time.Microsecond))),
console.Colorize(maxColor, v.MaxTTFB),
errs,
rx,
tx,
})
}
if hasTTFB {
t = append(t,
console.Colorize(avgColor, fmt.Sprintf("%v", avgTTFB.Round(time.Microsecond))),
console.Colorize(maxColor, v.MaxTTFB))
}
t = append(t, sz,
rate,
errs)
table.Append(t)
}
table.Render()
return s.String()
if globalTermWidth <= 10 {
return s.String()
}
w := globalTermWidth
if nw, _, e := term.GetSize(int(os.Stdout.Fd())); e == nil {
w = nw
}
split := strings.Split(s.String(), "\n")
for i, line := range split {
split[i] = truncate.StringWithTail(line, uint(w), "»")
}
return strings.Join(split, "\n")
}
2 changes: 1 addition & 1 deletion cmd/main.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -117,7 +117,7 @@ func Main(args []string) error {

// Fetch terminal size, if not available, automatically
// set globalQuiet to true on non-window.
if w, h, e := term.GetSize(int(os.Stdin.Fd())); e != nil {
if w, h, e := term.GetSize(int(os.Stdout.Fd())); e != nil {
globalQuiet = runtime.GOOS != "windows"
} else {
globalTermWidth, globalTermHeight = w, h
Expand Down
2 changes: 1 addition & 1 deletion go.mod
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ require (
github.com/charmbracelet/lipgloss v0.10.0
github.com/golang-jwt/jwt/v4 v4.5.0
github.com/juju/ratelimit v1.0.2
github.com/minio/madmin-go/v3 v3.0.51
github.com/minio/madmin-go/v3 v3.0.55-0.20240603092915-420a67132c32
github.com/minio/pkg/v3 v3.0.0
github.com/minio/selfupdate v0.6.0
github.com/muesli/reflow v0.3.0
Expand Down
4 changes: 2 additions & 2 deletions go.sum
View file
Original file line number Diff line number Diff line change
Expand Up @@ -130,8 +130,8 @@ github.com/minio/colorjson v1.0.7 h1:n69M42mIuQHdzbsxlmwji1zxDypaw4o39rHjAmX4Dh4
github.com/minio/colorjson v1.0.7/go.mod h1:9LGM5yybI+GuhSbuzAerbSgvFb4j8ux9NzyONR+NrAY=
github.com/minio/filepath v1.0.0 h1:fvkJu1+6X+ECRA6G3+JJETj4QeAYO9sV43I79H8ubDY=
github.com/minio/filepath v1.0.0/go.mod h1:/nRZA2ldl5z6jT9/KQuvZcQlxZIMQoFFQPvEXx9T/Bw=
github.com/minio/madmin-go/v3 v3.0.51 h1:brGOvDP8KvoHb/bdzCHUPFCbTtrN8o507uPHZpyuinM=
github.com/minio/madmin-go/v3 v3.0.51/go.mod h1:IFAwr0XMrdsLovxAdCcuq/eoL4nRuMVQQv0iubJANQw=
github.com/minio/madmin-go/v3 v3.0.55-0.20240603092915-420a67132c32 h1:9se7/S4AlN2k/B1E7A8m1m07DM3p0JnIOzVhDuAV2PI=
github.com/minio/madmin-go/v3 v3.0.55-0.20240603092915-420a67132c32/go.mod h1:IFAwr0XMrdsLovxAdCcuq/eoL4nRuMVQQv0iubJANQw=
github.com/minio/md5-simd v1.1.2 h1:Gdi1DZK69+ZVMoNHRXJyNcxrMA4dSxoYHZSQbirFg34=
github.com/minio/md5-simd v1.1.2/go.mod h1:MzdKDxYpY2BT9XQFocsiZf/NKVtR7nkE4RoEpN+20RM=
github.com/minio/minio-go/v7 v7.0.70 h1:1u9NtMgfK1U42kUxcsl5v0yj6TEOPR497OAQxpJnn2g=
Expand Down

0 comments on commit 3997483

Please sign in to comment.