mirror of
https://source.quilibrium.com/quilibrium/ceremonyclient.git
synced 2024-11-10 18:25:17 +00:00
468 lines
14 KiB
Go
468 lines
14 KiB
Go
// Copyright 2021 The LevelDB-Go and Pebble Authors. All rights reserved. Use
|
|
// of this source code is governed by a BSD-style license that can be found in
|
|
// the LICENSE file.
|
|
|
|
package logs
|
|
|
|
import (
|
|
"bytes"
|
|
"fmt"
|
|
"math"
|
|
"os"
|
|
"path/filepath"
|
|
"regexp"
|
|
"testing"
|
|
"time"
|
|
|
|
"github.com/cockroachdb/datadriven"
|
|
"github.com/cockroachdb/errors"
|
|
"github.com/stretchr/testify/require"
|
|
)
|
|
|
|
const (
|
|
compactionStartLine23_1 = `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [n5,pebble,s6] 1216510 [JOB 284925] compacting(default) L2 [442555] (4.2 M) + L3 [445853] (8.4 M)`
|
|
compactionStartLine = `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [n5,pebble,s6] 1216510 [JOB 284925] compacting(default) L2 [442555] (4.2MB) Score=1.01 + L3 [445853] (8.4MB) Score=0.99; OverlappingRatio: Single 8.03, Multi 25.05;`
|
|
|
|
compactionEndLine23_1 = `I211215 14:26:56.318543 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1886 ⋮ [n5,pebble,s6] 1216554 [JOB 284925] compacted(default) L2 [442555] (4.2 M) + L3 [445853] (8.4 M) -> L3 [445883 445887] (13 M), in 0.3s, output rate 42 M/s`
|
|
compactionEndLine = `I211215 14:26:56.318543 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1886 ⋮ [n5,pebble,s6] 1216554 [JOB 284925] compacted(default) L2 [442555] (4.2MB) Score=1.01 + L3 [445853] (8.4MB) Score=1.01 -> L3 [445883 445887] (13MB), in 0.3s, output rate 42MB/s`
|
|
|
|
compactionMultiLevelStartLine = `I211215 14:26:56.318543 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1886 ⋮ [n5,pebble,s6] 1216554 [JOB 11] compacting(default) [multilevel] L2 [250858] (2.1MB) Score=1.09 + L3 [247985 247989 247848] (17MB) Score=0.99 + L4 [250817 250834 238396] (28MB) Score=1.00; OverlappingRatio: Single 3.77, Multi 1.46;`
|
|
compactionMultiLevelEndline = `I211215 14:26:56.318543 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1886 ⋮ [n5,pebble,s6] 1216554 [JOB 11] compacted(default) [multilevel] L2 [250858] (2.1MB) Score=1.09 + L3 [247985 247989 247848] (17MB) Score=0.99 + L4 [250817 250834 238396] (28MB) Score=1.00 -> L4 [250859 250860 250861 250862 250863] (46MB), in 0.2s (0.2s total), output rate 185MB/s`
|
|
|
|
flushStartLine = `I211213 16:23:48.903751 21136 3@vendor/github.com/cockroachdb/pebble/event.go:599 ⋮ [n9,pebble,s8] 24 [JOB 10] flushing 2 memtables to L0`
|
|
|
|
flushEndLine23_1 = `I211213 16:23:49.134464 21136 3@vendor/github.com/cockroachdb/pebble/event.go:603 ⋮ [n9,pebble,s8] 26 [JOB 10] flushed 2 memtables to L0 [1535806] (1.3 M), in 0.2s, output rate 5.8 M/s`
|
|
flushEndLine = `I211213 16:23:49.134464 21136 3@vendor/github.com/cockroachdb/pebble/event.go:603 ⋮ [n9,pebble,s8] 26 [JOB 10] flushed 2 memtables to L0 [1535806] (1.3MB), in 0.2s, output rate 5.8MB/s`
|
|
|
|
readAmpLine23_1 = ` total 31766 188 G - 257 G 187 G 48 K 3.6 G 744 536 G 49 K 278 G 5 2.1`
|
|
readAmpLine = `total | 32K 188GB 0B | - | 257GB | 48K 187GB | 744 3.6GB | 49K 536GB | 278GB | 5 2.1`
|
|
|
|
compactionStartNoNodeStoreLine23_1 = `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [n?,pebble,s?] 1216510 [JOB 284925] compacting(default) L2 [442555] (4.2 M) + L3 [445853] (8.4 M)`
|
|
compactionStartNoNodeStoreLine = `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [n?,pebble,s?] 1216510 [JOB 284925] compacting(default) L2 [442555] (4.2 M) + L3 [445853] (8.4MB)`
|
|
flushStartNoNodeStoreLine = `I211213 16:23:48.903751 21136 3@vendor/github.com/cockroachdb/pebble/event.go:599 ⋮ [n?,pebble,s?] 24 [JOB 10] flushing 2 memtables to L0`
|
|
|
|
flushableIngestionLine23_1 = `I230831 04:13:28.824280 3780 3@pebble/event.go:685 ⋮ [n10,s10,pebble] 365 [JOB 226] flushed 6 ingested flushables L0:024334 (1.5 K) + L0:024339 (1.0 K) + L0:024335 (1.9 K) + L0:024336 (1.1 K) + L0:024337 (1.1 K) + L0:024338 (12 K) in 0.0s (0.0s total), output rate 67 M/s`
|
|
flushableIngestionLine = `I230831 04:13:28.824280 3780 3@pebble/event.go:685 ⋮ [n10,s10,pebble] 365 [JOB 226] flushed 6 ingested flushables L0:024334 (1.5KB) + L0:024339 (1.0KB) + L0:024335 (1.9KB) + L0:024336 (1.1KB) + L0:024337 (1.1KB) + L0:024338 (12KB) in 0.0s (0.0s total), output rate 67MB/s`
|
|
)
|
|
|
|
func TestCompactionLogs_Regex(t *testing.T) {
|
|
tcs := []struct {
|
|
name string
|
|
re *regexp.Regexp
|
|
line string
|
|
matches map[int]string
|
|
}{
|
|
{
|
|
name: "compaction start - sentinel",
|
|
re: sentinelPattern,
|
|
line: compactionStartLine23_1,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "compact",
|
|
sentinelPatternSuffixIdx: "ing",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction start - sentinel",
|
|
re: sentinelPattern,
|
|
line: compactionStartLine,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "compact",
|
|
sentinelPatternSuffixIdx: "ing",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction end - sentinel",
|
|
re: sentinelPattern,
|
|
line: compactionEndLine23_1,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "compact",
|
|
sentinelPatternSuffixIdx: "ed",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction end - sentinel",
|
|
re: sentinelPattern,
|
|
line: compactionEndLine,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "compact",
|
|
sentinelPatternSuffixIdx: "ed",
|
|
},
|
|
},
|
|
{
|
|
name: "flush start - sentinel",
|
|
re: sentinelPattern,
|
|
line: flushStartLine,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "flush",
|
|
sentinelPatternSuffixIdx: "ing",
|
|
},
|
|
},
|
|
{
|
|
name: "flush end - sentinel",
|
|
re: sentinelPattern,
|
|
line: flushEndLine23_1,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "flush",
|
|
sentinelPatternSuffixIdx: "ed",
|
|
},
|
|
},
|
|
{
|
|
name: "flush end - sentinel",
|
|
re: sentinelPattern,
|
|
line: flushEndLine,
|
|
matches: map[int]string{
|
|
sentinelPatternPrefixIdx: "flush",
|
|
sentinelPatternSuffixIdx: "ed",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction start",
|
|
re: compactionPattern,
|
|
line: compactionStartLine23_1,
|
|
matches: map[int]string{
|
|
compactionPatternJobIdx: "284925",
|
|
compactionPatternSuffixIdx: "ing",
|
|
compactionPatternTypeIdx: "default",
|
|
compactionPatternFromIdx: "2",
|
|
compactionPatternToIdx: "3",
|
|
compactionPatternLevels: "L2 [442555] (4.2 M) + L3 [445853] (8.4 M)",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction start",
|
|
re: compactionPattern,
|
|
line: compactionStartLine,
|
|
matches: map[int]string{
|
|
compactionPatternJobIdx: "284925",
|
|
compactionPatternSuffixIdx: "ing",
|
|
compactionPatternTypeIdx: "default",
|
|
compactionPatternFromIdx: "2",
|
|
compactionPatternToIdx: "3",
|
|
compactionPatternLevels: "L2 [442555] (4.2MB) Score=1.01 + L3 [445853] (8.4MB) Score=0.99",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction start multilevel",
|
|
re: compactionPattern,
|
|
line: compactionMultiLevelStartLine,
|
|
matches: map[int]string{
|
|
compactionPatternJobIdx: "11",
|
|
compactionPatternSuffixIdx: "ing",
|
|
compactionPatternTypeIdx: "default",
|
|
compactionPatternFromIdx: "2",
|
|
compactionPatternToIdx: "4",
|
|
compactionPatternLevels: "L2 [250858] (2.1MB) Score=1.09 + L3 [247985 247989 247848] (17MB) Score=0.99 + L4 [250817 250834 238396] (28MB) Score=1.00",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction start - no node / store",
|
|
re: compactionPattern,
|
|
line: compactionStartNoNodeStoreLine,
|
|
matches: map[int]string{
|
|
compactionPatternJobIdx: "284925",
|
|
compactionPatternSuffixIdx: "ing",
|
|
compactionPatternTypeIdx: "default",
|
|
compactionPatternFromIdx: "2",
|
|
compactionPatternToIdx: "3",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction end",
|
|
re: compactionPattern,
|
|
line: compactionEndLine,
|
|
matches: map[int]string{
|
|
compactionPatternJobIdx: "284925",
|
|
compactionPatternSuffixIdx: "ed",
|
|
compactionPatternTypeIdx: "default",
|
|
compactionPatternFromIdx: "2",
|
|
compactionPatternToIdx: "3",
|
|
compactionPatternBytesIdx: "13MB",
|
|
},
|
|
},
|
|
{
|
|
name: "compaction end",
|
|
re: compactionPattern,
|
|
line: compactionMultiLevelEndline,
|
|
matches: map[int]string{
|
|
compactionPatternJobIdx: "11",
|
|
compactionPatternSuffixIdx: "ed",
|
|
compactionPatternTypeIdx: "default",
|
|
compactionPatternFromIdx: "2",
|
|
compactionPatternToIdx: "4",
|
|
compactionPatternBytesIdx: "46MB",
|
|
},
|
|
},
|
|
{
|
|
name: "flush start",
|
|
re: flushPattern,
|
|
line: flushStartLine,
|
|
matches: map[int]string{
|
|
flushPatternJobIdx: "10",
|
|
flushPatternSuffixIdx: "ing",
|
|
flushPatternBytesIdx: "",
|
|
},
|
|
},
|
|
{
|
|
name: "flush start - no node / store",
|
|
re: flushPattern,
|
|
line: flushStartNoNodeStoreLine,
|
|
matches: map[int]string{
|
|
flushPatternJobIdx: "10",
|
|
flushPatternSuffixIdx: "ing",
|
|
flushPatternBytesIdx: "",
|
|
},
|
|
},
|
|
{
|
|
name: "flush end",
|
|
re: flushPattern,
|
|
line: flushEndLine,
|
|
matches: map[int]string{
|
|
flushPatternJobIdx: "10",
|
|
flushPatternSuffixIdx: "ed",
|
|
flushPatternBytesIdx: "1.3MB",
|
|
},
|
|
},
|
|
{
|
|
name: "read amp suffix",
|
|
re: readAmpPattern,
|
|
line: readAmpLine,
|
|
matches: map[int]string{
|
|
readAmpPatternValueIdx: "5",
|
|
},
|
|
},
|
|
{
|
|
name: "read amp suffix 23.1",
|
|
re: readAmpPattern,
|
|
line: readAmpLine23_1,
|
|
matches: map[int]string{
|
|
readAmpPatternValueIdx: "5",
|
|
},
|
|
},
|
|
{
|
|
name: "ingestion during flush job 23.1",
|
|
re: flushableIngestedPattern,
|
|
line: flushableIngestionLine23_1,
|
|
matches: map[int]string{
|
|
flushableIngestedPatternJobIdx: "226",
|
|
},
|
|
},
|
|
{
|
|
name: "ingestion during flush 23.1",
|
|
re: ingestedFilePattern,
|
|
line: flushableIngestionLine23_1,
|
|
matches: map[int]string{
|
|
// Just looking at the first match for these.
|
|
ingestedFilePatternLevelIdx: "0",
|
|
ingestedFilePatternFileIdx: "024334",
|
|
ingestedFilePatternBytesIdx: "1.5 K",
|
|
},
|
|
},
|
|
{
|
|
name: "ingestion during flush job",
|
|
re: flushableIngestedPattern,
|
|
line: flushableIngestionLine,
|
|
matches: map[int]string{
|
|
flushableIngestedPatternJobIdx: "226",
|
|
},
|
|
},
|
|
{
|
|
name: "ingestion during flush",
|
|
re: ingestedFilePattern,
|
|
line: flushableIngestionLine,
|
|
matches: map[int]string{
|
|
// Just looking at the first match for these.
|
|
ingestedFilePatternLevelIdx: "0",
|
|
ingestedFilePatternFileIdx: "024334",
|
|
ingestedFilePatternBytesIdx: "1.5KB",
|
|
},
|
|
},
|
|
}
|
|
|
|
for _, tc := range tcs {
|
|
t.Run(tc.name, func(t *testing.T) {
|
|
matches := tc.re.FindStringSubmatch(tc.line)
|
|
require.NotNil(t, matches)
|
|
for idx, want := range tc.matches {
|
|
require.Equal(t, want, matches[idx])
|
|
}
|
|
})
|
|
}
|
|
}
|
|
|
|
func TestParseLogContext(t *testing.T) {
|
|
testCases := []struct {
|
|
line string
|
|
timestamp string
|
|
node int
|
|
store int
|
|
}{
|
|
{
|
|
line: `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [n5,pebble,s6] foo`,
|
|
timestamp: "211215 14:26:56.012382",
|
|
node: 5,
|
|
store: 6,
|
|
},
|
|
{
|
|
line: `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [T?,n5,pebble,s6] foo`,
|
|
timestamp: "211215 14:26:56.012382",
|
|
node: 5,
|
|
store: 6,
|
|
},
|
|
{
|
|
line: `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [T15,n5,pebble,s6] foo`,
|
|
timestamp: "211215 14:26:56.012382",
|
|
node: 5,
|
|
store: 6,
|
|
},
|
|
{
|
|
line: `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [T1,n?,pebble,s6] foo`,
|
|
timestamp: "211215 14:26:56.012382",
|
|
node: -1,
|
|
store: 6,
|
|
},
|
|
{
|
|
line: `I211215 14:26:56.012382 51831533 3@vendor/github.com/cockroachdb/pebble/compaction.go:1845 ⋮ [n5,pebble,s?] foo`,
|
|
timestamp: "211215 14:26:56.012382",
|
|
node: 5,
|
|
store: -1,
|
|
},
|
|
}
|
|
for _, tc := range testCases {
|
|
t.Run("", func(t *testing.T) {
|
|
var b logEventCollector
|
|
require.NoError(t, parseLogContext(tc.line, &b))
|
|
expT, err := time.Parse(timeFmt, tc.timestamp)
|
|
require.NoError(t, err)
|
|
require.Equal(t, expT, b.ctx.timestamp)
|
|
require.Equal(t, tc.node, b.ctx.node)
|
|
require.Equal(t, tc.store, b.ctx.store)
|
|
})
|
|
}
|
|
}
|
|
|
|
func TestCompactionLogs(t *testing.T) {
|
|
dir := t.TempDir()
|
|
datadriven.Walk(t, "testdata", func(t *testing.T, path string) {
|
|
var c *logEventCollector
|
|
var logNum int
|
|
resetFn := func() {
|
|
c = newEventCollector()
|
|
logNum = 0
|
|
}
|
|
resetFn()
|
|
datadriven.RunTest(t, path, func(t *testing.T, td *datadriven.TestData) string {
|
|
switch td.Cmd {
|
|
case "log":
|
|
basename := fmt.Sprintf("%d.log", logNum)
|
|
logNum++
|
|
f, err := os.Create(filepath.Join(dir, basename))
|
|
if err != nil {
|
|
panic(err)
|
|
}
|
|
if _, err = f.WriteString(td.Input); err != nil {
|
|
panic(err)
|
|
}
|
|
_ = f.Close()
|
|
|
|
if err = parseLog(f.Name(), c); err != nil {
|
|
return err.Error()
|
|
}
|
|
return basename
|
|
|
|
case "summarize":
|
|
window := 1 * time.Minute
|
|
longRunning := time.Duration(math.MaxInt64)
|
|
|
|
var err error
|
|
for _, cmdArg := range td.CmdArgs {
|
|
switch cmdArg.Key {
|
|
case "window":
|
|
window, err = time.ParseDuration(cmdArg.Vals[0])
|
|
if err != nil {
|
|
panic(errors.Newf("could not parse window: %s", err))
|
|
}
|
|
|
|
case "long-running":
|
|
longRunning, err = time.ParseDuration(cmdArg.Vals[0])
|
|
if err != nil {
|
|
panic(errors.Newf("could not parse long-running: %s", err))
|
|
}
|
|
|
|
default:
|
|
panic(errors.Newf("unknown arg %q", cmdArg.Key))
|
|
}
|
|
}
|
|
|
|
a := newAggregator(window, longRunning, c.events, c.readAmps)
|
|
windows := a.aggregate()
|
|
|
|
var b bytes.Buffer
|
|
for _, w := range windows {
|
|
b.WriteString(w.String())
|
|
}
|
|
|
|
return b.String()
|
|
|
|
case "reset":
|
|
resetFn()
|
|
return ""
|
|
|
|
default:
|
|
return fmt.Sprintf("unknown command %q", td.Cmd)
|
|
}
|
|
})
|
|
})
|
|
}
|
|
|
|
func TestParseInputBytes(t *testing.T) {
|
|
testCases := []struct {
|
|
s string
|
|
want uint64
|
|
}{
|
|
// Test both 23.1 and current formats.
|
|
{
|
|
"(10 B)",
|
|
10,
|
|
},
|
|
{
|
|
"(10B)",
|
|
10,
|
|
},
|
|
{
|
|
"(10 M)",
|
|
10 << 20,
|
|
},
|
|
{
|
|
"(10MB)",
|
|
10 << 20,
|
|
},
|
|
{
|
|
"(10 M) + (20 M)",
|
|
30 << 20,
|
|
},
|
|
{
|
|
"(10MB) + (20MB)",
|
|
30 << 20,
|
|
},
|
|
{
|
|
"(10 M) + (20 M) + (30 M)",
|
|
60 << 20,
|
|
},
|
|
{
|
|
"(10MB) + (20MB) + (30MB)",
|
|
60 << 20,
|
|
},
|
|
{
|
|
"foo",
|
|
0,
|
|
},
|
|
}
|
|
for _, tc := range testCases {
|
|
t.Run(tc.s, func(t *testing.T) {
|
|
got, err := sumInputBytes(tc.s)
|
|
require.NoError(t, err)
|
|
require.Equal(t, tc.want, got)
|
|
})
|
|
}
|
|
}
|