diff --git a/Makefile b/Makefile index 2e46080a..5279e5e9 100644 --- a/Makefile +++ b/Makefile @@ -10,6 +10,7 @@ BUILD_VERSIONS_DEBUG = $(shell jq -r '.versions|map("build-\(.)-debug")[]' ${TAR STORE_MOD_VERSIONS = $(shell jq -r '.versions|map("store-mod-\(.)")[]' ${TARGETS}) TEST_VERSIONS = $(shell jq -r '.versions|map("test-\(.)")[]' ${TARGETS}) COVERAGE_VERSIONS = $(shell jq -r '.versions|map("coverage-\(.)")[]' ${TARGETS}) +BENCHMARK_VERSIONS = $(shell jq -r '.versions|map("benchmark-\(.)")[]' ${TARGETS}) BRANCH := $(shell git rev-parse --abbrev-ref HEAD) COMMIT := $(shell git log -1 --format='%H') @@ -56,6 +57,11 @@ $(TEST_VERSIONS): go test -v -failfast -race -count=1 \ -tags $(shell echo $@ | sed -e 's/test-/sdk_/g' -e 's/-/_/g'),muslc \ ./... + +$(BENCHMARK_VERSIONS): + go test -v -failfast -bench=. -run=^# -benchmem -count=1 \ + -tags $(shell echo $@ | sed -e 's/benchmark-/sdk_/g' -e 's/-/_/g'),muslc \ + ./... $(COVERAGE_VERSIONS): go test -v -failfast -coverprofile=coverage.out -covermode=atomic -count=1\ diff --git a/cmd/tracelistener/main.go b/cmd/tracelistener/main.go index a456cc69..52467f20 100644 --- a/cmd/tracelistener/main.go +++ b/cmd/tracelistener/main.go @@ -82,7 +82,7 @@ func main() { if ca.existingDatabasePath != "" { importer := bulk.Importer{ Path: ca.existingDatabasePath, - TraceWatcher: watcher, + TraceWatcher: &watcher, Processor: dpi, Logger: logger, Database: di, diff --git a/cmd/tracestats/main.go b/cmd/tracestats/main.go new file mode 100644 index 00000000..96ad0a9b --- /dev/null +++ b/cmd/tracestats/main.go @@ -0,0 +1,112 @@ +package main + +import ( + "bufio" + "encoding/csv" + "encoding/json" + "fmt" + "os" + "strconv" + + "github.com/allinbits/tracelistener/tracelistener" +) + +type traceInfo struct { + BlockHeight uint64 + KeyLength uint64 + ValueLength uint64 + Length uint64 +} + +type traceInfos []traceInfo + +func (ti traceInfos) CSV() [][]string { + ret := make([][]string, 0, 1+len(ti)) // add 1 row for title + + ret = append(ret, []string{"block_height", "key_lengt", "value_length", "length"}) + + for _, t := range ti { + ret = append(ret, []string{ + strconv.FormatUint(t.BlockHeight, 10), + strconv.FormatUint(t.KeyLength, 10), + strconv.FormatUint(t.ValueLength, 10), + strconv.FormatUint(t.Length, 10), + }) + } + + return ret +} + +func main() { + fname := os.Args[1] + + rows, err := loadTestFile(fname) + if err != nil { + panic(err) + } + + ti, err := getTraceInfo(rows) + if err != nil { + panic(err) + } + + o, err := os.OpenFile("tracestats.csv", os.O_CREATE|os.O_APPEND|os.O_RDWR, 0755) + if err != nil { + panic(err) + } + + defer func() { + if err := o.Close(); err != nil { + panic(err) + } + }() + + w := csv.NewWriter(o) + for _, record := range ti.CSV() { + if err := w.Write(record); err != nil { + panic(err) + } + } +} + +func getTraceInfo(traces []string) (traceInfos, error) { + ret := make([]traceInfo, 0, len(traces)) + + for _, t := range traces { + tr := tracelistener.TraceOperation{} + if err := json.Unmarshal([]byte(t), &tr); err != nil { + return nil, err + } + + ret = append(ret, traceInfo{ + BlockHeight: tr.Metadata.BlockHeight, + KeyLength: uint64(len(tr.Key)), + ValueLength: uint64(len(tr.Value)), + Length: uint64(len(t)), + }) + } + + return ret, nil +} + +func loadTestFile(fname string) ([]string, error) { + file, err := os.Open(fname) + if err != nil { + return nil, fmt.Errorf("cannot open file %s, %w", fname, err) + } + + scanner := bufio.NewScanner(file) + buf := make([]byte, 1000000) // a very high capacity + scanner.Buffer(buf, 1000000) + + ret := []string{} + for scanner.Scan() { + ret = append(ret, scanner.Text()) + } + + if err := scanner.Err(); err != nil { + return nil, fmt.Errorf("scanning error, %w", err) + } + + return ret, nil +} diff --git a/tracelistener/benchmark_test.go b/tracelistener/benchmark_test.go new file mode 100644 index 00000000..5ac11657 --- /dev/null +++ b/tracelistener/benchmark_test.go @@ -0,0 +1,176 @@ +package tracelistener_test + +import ( + "bufio" + "context" + "fmt" + "io" + "os" + "syscall" + "testing" + + "github.com/allinbits/tracelistener/tracelistener" + "github.com/containerd/fifo" + "go.uber.org/zap" +) + +func setup(b *testing.B) (io.ReadWriteCloser, string) { + b.Helper() + f, err := os.CreateTemp("", "test_data") + if err != nil { + panic(err) + } + + err = f.Close() + if err != nil { + panic(err) + } + + dataChan := make(chan tracelistener.TraceOperation) + errChan := make(chan error) + l := zap.NewNop() + tw := tracelistener.TraceWatcher{ + DataSourcePath: f.Name(), + WatchedOps: []tracelistener.Operation{ + tracelistener.WriteOp, + tracelistener.DeleteOp, + }, + DataChan: dataChan, + ErrorChan: errChan, + Logger: l.Sugar(), + } + + go func() { + // drain data channel + for range dataChan { + } + }() + + go func() { + tw.Watch() + }() + + ff, err := fifo.OpenFifo(context.Background(), f.Name(), syscall.O_WRONLY, 0655) + if err != nil { + panic(err) + } + + return ff, f.Name() +} + +func runBenchmark(b *testing.B, amount int, kind string) { + fileWriter, fifoName := setup(b) + defer func() { + if err := fileWriter.Close(); err != nil { + panic(err) + } + }() + + b.ResetTimer() + + for i := 0; i < amount; i++ { + err := loadTest(b, i, fileWriter, kind) + if err != nil { + panic(err) + } + } + + os.Remove(fifoName) +} + +func BenchmarkTracelistenerRealTraces(b *testing.B) { + b.Log("reading test traces file...") + lines, err := loadTestFile(b) + if err != nil { + b.Fatal(err) + } + b.Log("finished reading test traces file!") + + fileWriter, fifoName := setup(b) + defer func() { + if err := fileWriter.Close(); err != nil { + panic(err) + } + }() + + b.ResetTimer() + + for _, line := range lines { + fmt.Fprintf(fileWriter, line+"\n") + } + + os.Remove(fifoName) +} + +func BenchmarkTraceListenerKindWrite(b *testing.B) { + runBenchmark(b, b.N, "write") +} + +func BenchmarkTraceListener100KKindWrite(b *testing.B) { + runBenchmark(b, 100000, "write") +} + +func BenchmarkTraceListener1MKindWrite(b *testing.B) { + runBenchmark(b, 1000000, "write") +} + +func BenchmarkTraceListener1MKindIterRange(b *testing.B) { + runBenchmark(b, 1000000, "IterRange") +} + +func BenchmarkTraceListener10MKindWrite(b *testing.B) { + runBenchmark(b, 10000000, "write") +} + +func loadTest(b *testing.B, height int, ff io.Writer, kind string) error { + b.Helper() + + // trace := tracelistener.TraceOperation{ + // Operation: string(tracelistener.WriteOp), + // Key: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, + // Value: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, + // BlockHeight: uint64(height), + // TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + // } + // data, err := json.Marshal(trace) + // if err != nil { + // return err + // } + + // println(string(data)) + + s := `{"operation":"%s","key":"aGVsbG8K","value":"aGVsbG8K","block_height":158284,"tx_hash":"A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB","SuggestedProcessor":""}` + + fmt.Fprintf(ff, s+"\n", kind) + + return nil +} + +func loadTestFile(b *testing.B) ([]string, error) { + b.Helper() + + fname := os.Getenv("TRACELISTENER_BENCH_TRACEFILE") + if fname == "" { + return nil, fmt.Errorf("TRACELISTENER_BENCH_TRACEFILE environment variable not defined") + } + + file, err := os.Open(fname) + if err != nil { + return nil, fmt.Errorf("cannot open file %s, %w", fname, err) + } + + scanner := bufio.NewScanner(file) + buf := make([]byte, 1000000) // a very high capacity + scanner.Buffer(buf, 1000000) + + ret := []string{} + for scanner.Scan() { + ret = append(ret, scanner.Text()) + } + + if err := scanner.Err(); err != nil { + return nil, fmt.Errorf("scanning error, %w", err) + } + + return ret, nil +} diff --git a/tracelistener/bulk/bulkimport.go b/tracelistener/bulk/bulkimport.go index bef3481e..156a87e5 100644 --- a/tracelistener/bulk/bulkimport.go +++ b/tracelistener/bulk/bulkimport.go @@ -25,7 +25,7 @@ import ( type Importer struct { Path string - TraceWatcher tracelistener.TraceWatcher + TraceWatcher *tracelistener.TraceWatcher Processor tracelistener.DataProcessor Logger *zap.SugaredLogger Database *database.Instance @@ -41,7 +41,7 @@ func ImportableModulesList() []string { return ml } -func (i Importer) validateModulesList() error { +func (i *Importer) validateModulesList() error { for _, m := range i.Modules { if _, ok := tracelistener.SupportedSDKModuleList[tracelistener.SDKModuleName(m)]; !ok { return fmt.Errorf("unknown bulk import module %s", m) @@ -155,14 +155,16 @@ func (i *Importer) Do() error { for ; ii.Valid(); ii.Next() { to := tracelistener.TraceOperation{ - Operation: tracelistener.WriteOp.String(), - Key: ii.Key(), - Value: ii.Value(), - BlockHeight: uint64(latestBlockHeight), + Operation: tracelistener.WriteOp.String(), + Key: ii.Key(), + Value: ii.Value(), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: uint64(latestBlockHeight), + }, SuggestedProcessor: tracelistener.SDKModuleName(key.Name()), } - if err := i.TraceWatcher.ParseOperation(to); err != nil { + if err := i.TraceWatcher.ParseOperation(&to); err != nil { return fmt.Errorf("cannot parse operation %v, %w", to, err) } diff --git a/tracelistener/processor/auth_test.go b/tracelistener/processor/auth_test.go index 1dc4e93f..f4c32d5a 100644 --- a/tracelistener/processor/auth_test.go +++ b/tracelistener/processor/auth_test.go @@ -77,9 +77,11 @@ func TestAuthProcess(t *testing.T) { Sequence: 11, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("cosmos1xrnner9s783446"), - BlockHeight: 1, + Operation: string(tracelistener.WriteOp), + Key: []byte("cosmos1xrnner9s783446"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + }, }, false, 1, @@ -92,9 +94,11 @@ func TestAuthProcess(t *testing.T) { Sequence: 11, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("cosmos1xrnner9s783446"), - BlockHeight: 1, + Operation: string(tracelistener.WriteOp), + Key: []byte("cosmos1xrnner9s783446"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + }, }, true, 0, diff --git a/tracelistener/processor/bank_test.go b/tracelistener/processor/bank_test.go index e989c79f..82af4bca 100644 --- a/tracelistener/processor/bank_test.go +++ b/tracelistener/processor/bank_test.go @@ -75,9 +75,11 @@ func TestBankProcess(t *testing.T) { Amount: 500, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("cosmos1xrnner9s783446yz3hhshpr5fpz6wzcwkvwv5j"), - BlockHeight: 101, + Operation: string(tracelistener.WriteOp), + Key: []byte("cosmos1xrnner9s783446yz3hhshpr5fpz6wzcwkvwv5j"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 101, + }, }, false, 1, diff --git a/tracelistener/processor/datamarshaler/impl_v42.go b/tracelistener/processor/datamarshaler/impl_v42.go index 7c10a832..df330022 100644 --- a/tracelistener/processor/datamarshaler/impl_v42.go +++ b/tracelistener/processor/datamarshaler/impl_v42.go @@ -64,14 +64,14 @@ func (d DataMarshaler) Bank(data tracelistener.TraceOperation) (models.BalanceRo "operation", data.Operation, "address", hAddr, "new_balance", coins.String(), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) return models.BalanceRow{ Address: hAddr, Amount: coins.String(), Denom: coins.Denom, - BlockHeight: data.BlockHeight, + BlockHeight: data.Metadata.BlockHeight, }, nil } @@ -129,8 +129,8 @@ func (d DataMarshaler) Auth(data tracelistener.TraceOperation) (models.AuthRow, "address", hAddr, "sequence_number", acc.GetSequence(), "account_number", acc.GetAccountNumber(), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) return models.AuthRow{ @@ -176,15 +176,15 @@ func (d DataMarshaler) Delegations(data tracelistener.TraceOperation) (models.De "delegator", delegator, "validator", validator, "amount", delegation.Shares.String(), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) return models.DelegationRow{ Delegator: delegator, Validator: validator, Amount: delegation.Shares.String(), - BlockHeight: data.BlockHeight, + BlockHeight: data.Metadata.BlockHeight, }, nil } @@ -356,8 +356,8 @@ func (d DataMarshaler) UnbondingDelegations(data tracelistener.TraceOperation) ( "delegator", delegator, "validator", validator, "entries", string(entries), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) var entriesStore models.UnbondingDelegationEntries @@ -402,9 +402,9 @@ func (d DataMarshaler) Validators(data tracelistener.TraceOperation) (models.Val d.l.Debugw("new validator write", "operator_address", v.OperatorAddress, - "height", data.BlockHeight, - "txHash", data.TxHash, - "cons pub key type", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, + "cons pub key type", data.Metadata.TxHash, "cons pub key", val, "key", k, ) diff --git a/tracelistener/processor/datamarshaler/impl_v44.go b/tracelistener/processor/datamarshaler/impl_v44.go index 73ee7f45..221632cd 100644 --- a/tracelistener/processor/datamarshaler/impl_v44.go +++ b/tracelistener/processor/datamarshaler/impl_v44.go @@ -93,15 +93,15 @@ func (d DataMarshaler) Bank(data tracelistener.TraceOperation) (models.BalanceRo "operation", data.Operation, "address", hAddr, "new_balance", coins.String(), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) return models.BalanceRow{ Address: hAddr, Amount: coins.String(), Denom: coins.Denom, - BlockHeight: data.BlockHeight, + BlockHeight: data.Metadata.BlockHeight, }, nil } @@ -160,8 +160,8 @@ func (d DataMarshaler) Auth(data tracelistener.TraceOperation) (models.AuthRow, "address", hAddr, "sequence_number", acc.GetSequence(), "account_number", acc.GetAccountNumber(), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) return models.AuthRow{ @@ -219,15 +219,15 @@ func (d DataMarshaler) Delegations(data tracelistener.TraceOperation) (models.De "delegator", delegator, "validator", validator, "amount", delegation.Shares.String(), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) return models.DelegationRow{ Delegator: delegator, Validator: validator, Amount: delegation.Shares.String(), - BlockHeight: data.BlockHeight, + BlockHeight: data.Metadata.BlockHeight, }, nil } @@ -421,8 +421,8 @@ func (d DataMarshaler) UnbondingDelegations(data tracelistener.TraceOperation) ( "delegator", delegator, "validator", validator, "entries", string(entries), - "height", data.BlockHeight, - "txHash", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, ) var entriesStore models.UnbondingDelegationEntries @@ -469,9 +469,9 @@ func (d DataMarshaler) Validators(data tracelistener.TraceOperation) (models.Val d.l.Debugw("new validator write", "operator_address", v.OperatorAddress, - "height", data.BlockHeight, - "txHash", data.TxHash, - "cons pub key type", data.TxHash, + "height", data.Metadata.BlockHeight, + "txHash", data.Metadata.TxHash, + "cons pub key type", data.Metadata.TxHash, "cons pub key", val, "key", k, ) diff --git a/tracelistener/processor/delegation_test.go b/tracelistener/processor/delegation_test.go index 8f2371a5..919f28bb 100644 --- a/tracelistener/processor/delegation_test.go +++ b/tracelistener/processor/delegation_test.go @@ -89,10 +89,12 @@ func TestDelegationProcess(t *testing.T) { Shares: 100, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), - BlockHeight: 1, - TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + Operation: string(tracelistener.WriteOp), + Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + }, }, false, 1, @@ -103,10 +105,11 @@ func TestDelegationProcess(t *testing.T) { Shares: 100, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), - BlockHeight: 1, - TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + Operation: string(tracelistener.WriteOp), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + }, }, true, 0, diff --git a/tracelistener/processor/delegations.go b/tracelistener/processor/delegations.go index 8155c652..cc1df5d0 100644 --- a/tracelistener/processor/delegations.go +++ b/tracelistener/processor/delegations.go @@ -104,7 +104,7 @@ func (b *delegationsProcessor) Process(data tracelistener.TraceOperation) error Delegator: res.Delegator, Validator: res.Validator, Amount: res.Amount, - BlockHeight: data.BlockHeight, + BlockHeight: data.Metadata.BlockHeight, } return nil diff --git a/tracelistener/processor/processor.go b/tracelistener/processor/processor.go index 4283e565..a239a0a3 100644 --- a/tracelistener/processor/processor.go +++ b/tracelistener/processor/processor.go @@ -196,7 +196,7 @@ func (p *Processor) Flush() error { func (p *Processor) lifecycle() { for data := range p.writeChan { - if data.BlockHeight != p.lastHeight && data.BlockHeight != 0 { + if data.Metadata.BlockHeight != p.lastHeight && data.Metadata.BlockHeight != 0 { if err := p.Flush(); err != nil { p.errorsChan <- fmt.Errorf("error while flushing caches, %w", err) continue @@ -204,7 +204,7 @@ func (p *Processor) lifecycle() { p.l.Infow("processed new block", "height", p.lastHeight) - p.lastHeight = data.BlockHeight + p.lastHeight = data.Metadata.BlockHeight } processorList := p.moduleProcessors diff --git a/tracelistener/processor/processor_test.go b/tracelistener/processor/processor_test.go index 9a9a9764..9944c411 100644 --- a/tracelistener/processor/processor_test.go +++ b/tracelistener/processor/processor_test.go @@ -120,10 +120,12 @@ func TestLifecycle(t *testing.T) { "no error when queueing new message accepted by the processor", nil, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("key"), - Value: []byte("key"), - BlockHeight: 0, + Operation: string(tracelistener.WriteOp), + Key: []byte("key"), + Value: []byte("key"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + }, }, func(_ tracelistener.TraceOperation) error { return nil @@ -135,10 +137,12 @@ func TestLifecycle(t *testing.T) { "error when queueing new message accepted by the processor", nil, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("key"), - Value: []byte("key"), - BlockHeight: 0, + Operation: string(tracelistener.WriteOp), + Key: []byte("key"), + Value: []byte("key"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 0, + }, }, func(_ tracelistener.TraceOperation) error { return fmt.Errorf("oh no, error") @@ -150,17 +154,21 @@ func TestLifecycle(t *testing.T) { "new message, block different re: last height", []tracelistener.TraceOperation{ { - Operation: string(tracelistener.WriteOp), - Key: []byte("key"), - Value: []byte("key"), - BlockHeight: 0, + Operation: string(tracelistener.WriteOp), + Key: []byte("key"), + Value: []byte("key"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 0, + }, }, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("key"), - Value: []byte("key"), - BlockHeight: 1, + Operation: string(tracelistener.WriteOp), + Key: []byte("key"), + Value: []byte("key"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + }, }, func(_ tracelistener.TraceOperation) error { return nil diff --git a/tracelistener/processor/unbonding_delegation_test.go b/tracelistener/processor/unbonding_delegation_test.go index 2442f19e..5a329180 100644 --- a/tracelistener/processor/unbonding_delegation_test.go +++ b/tracelistener/processor/unbonding_delegation_test.go @@ -83,10 +83,12 @@ func TestUnbondingDelegationProcess(t *testing.T) { }, }, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), - BlockHeight: 1, - TxHash: "066050E449C3450F943FC6227F155C19EF5C14653F268E9BAFEFE93DF9B3EDAD", + Operation: string(tracelistener.WriteOp), + Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + TxHash: "066050E449C3450F943FC6227F155C19EF5C14653F268E9BAFEFE93DF9B3EDAD", + }, }, false, 1, @@ -95,10 +97,12 @@ func TestUnbondingDelegationProcess(t *testing.T) { "Invalid addresses - error", datamarshaler.TestUnbondingDelegation{}, tracelistener.TraceOperation{ - Operation: string(tracelistener.WriteOp), - Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), - BlockHeight: 1, - TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + Operation: string(tracelistener.WriteOp), + Key: []byte("AtdlV8qD6o6J2shsj9acpI+9Opd/e5uTqZIi7NK5i3y9"), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 1, + TxHash: "A5CF62609D62ADDE56816681B6191F5F0252D2800FC2C312EB91D962AB7A97CB", + }, }, true, 0, diff --git a/tracelistener/processor/unbonding_delegation_v42_test.go b/tracelistener/processor/unbonding_delegation_v42_test.go index 1c0b9cf6..a380ddf0 100644 --- a/tracelistener/processor/unbonding_delegation_v42_test.go +++ b/tracelistener/processor/unbonding_delegation_v42_test.go @@ -22,10 +22,12 @@ func versionSpecificUnbondingDelegationsProcessTests() []unbondingDelegationsPro Validator: "cosmosvaloper19xawgvgn887e9gef5vkzkemwh33mtgwa6haa7s", }, tracelistener.TraceOperation{ - Operation: string(tracelistener.DeleteOp), - Key: []byte("QXRkbFY4cUQ2bzZKMnNoc2o5YWNwSSs5T3BkL2U1dVRxWklpN05LNWkzeTk="), - Value: []byte("Ci1jb3Ntb3MxeHJubmVyOXM3ODM0NDZ5ejNoaHNocHI1ZnB6Nnd6Y3drdnd2NWoSNGNvc21vc3ZhbG9wZXIxOXhhd2d2Z244ODdlOWdlZjV2a3prZW13aDMzbXRnd2E2aGFhN3MaHAiYIBILCICSuMOY/v///wEaBDEwMDAiBDExMDA="), - BlockHeight: 0, + Operation: string(tracelistener.DeleteOp), + Key: []byte("QXRkbFY4cUQ2bzZKMnNoc2o5YWNwSSs5T3BkL2U1dVRxWklpN05LNWkzeTk="), + Value: []byte("Ci1jb3Ntb3MxeHJubmVyOXM3ODM0NDZ5ejNoaHNocHI1ZnB6Nnd6Y3drdnd2NWoSNGNvc21vc3ZhbG9wZXIxOXhhd2d2Z244ODdlOWdlZjV2a3prZW13aDMzbXRnd2E2aGFhN3MaHAiYIBILCICSuMOY/v///wEaBDEwMDAiBDExMDA="), + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 0, + }, }, false, 1, diff --git a/tracelistener/processor/unbonding_delegation_v44_test.go b/tracelistener/processor/unbonding_delegation_v44_test.go index 67e3185d..2e871384 100644 --- a/tracelistener/processor/unbonding_delegation_v44_test.go +++ b/tracelistener/processor/unbonding_delegation_v44_test.go @@ -29,10 +29,12 @@ func versionSpecificUnbondingDelegationsProcessTests() []unbondingDelegationsPro Validator: "cosmosvaloper19xawgvgn887e9gef5vkzkemwh33mtgwa6haa7s", }, tracelistener.TraceOperation{ - Operation: string(tracelistener.DeleteOp), - Key: []byte("QXRkbFY4cUQ2bzZKMnNoc2o5YWNwSSs5T3BkL2U1dVRxWklpN05LNWkzeTk="), - Value: []byte{}, - BlockHeight: 0, + Operation: string(tracelistener.DeleteOp), + Key: []byte("QXRkbFY4cUQ2bzZKMnNoc2o5YWNwSSs5T3BkL2U1dVRxWklpN05LNWkzeTk="), + Value: []byte{}, + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 0, + }, }, false, 0, @@ -49,8 +51,10 @@ func versionSpecificUnbondingDelegationsProcessTests() []unbondingDelegationsPro 0x33, // prefix 9, 118, 97, 108, 105, 100, 97, 116, 111, 114, 9, 100, 101, 108, 101, 103, 97, 116, 111, 114, }, - Value: []byte{}, - BlockHeight: 0, + Value: []byte{}, + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 0, + }, }, false, 1, diff --git a/tracelistener/trace.go b/tracelistener/trace.go index ba42333b..5139b3d9 100644 --- a/tracelistener/trace.go +++ b/tracelistener/trace.go @@ -1,60 +1,49 @@ package tracelistener -import ( - "encoding/json" - "fmt" -) +// Copy deep-copies to to a new instances of TraceOperation, +// useful when sending over data down the processing pipeline. +func (to *TraceOperation) Copy() TraceOperation { + ret := *to -const ( - metadataBlockHeight = "blockHeight" - metadataTxHash = "txHash" -) + // Explicitly copy key and value slices to new + // slice instances to avoid aliasing. + ret.Key = make([]byte, len(to.Key)) + copy(ret.Key, to.Key) -type TraceOperation struct { - Operation string `json:"operation"` - Key []byte `json:"key"` - Value []byte `json:"value"` - BlockHeight uint64 `json:"block_height"` - TxHash string `json:"tx_hash"` + ret.Value = make([]byte, len(to.Value)) + copy(ret.Value, to.Value) - // SuggestedProcessor signals to the trace processor that - // what SDK module this trace comes from. - SuggestedProcessor SDKModuleName + return ret } -func (t TraceOperation) String() string { - return fmt.Sprintf(`[%s] "%v" -> "%v"`, t.Operation, string(t.Key), string(t.Value)) +// Reset resets to to an empty state. +// Useful when storing it in a sync.Pool. +func (to *TraceOperation) Reset() { + to.Operation = "" + to.Key = to.Key[:0] + to.Value = to.Value[:0] + to.Metadata.BlockHeight = 0 + to.Metadata.TxHash = "" + to.SuggestedProcessor = "" } -type traceOperationInter struct { - Operation string `json:"operation"` - Key []byte `json:"key"` - Value []byte `json:"value"` - Metadata map[string]interface{} `json:"metadata"` +// TraceMetadata holds circumstantial information about a trace, +// like the block height at which it was generated, and optionally a +// the block hash that generated it. +type TraceMetadata struct { + BlockHeight uint64 `json:"blockHeight"` + TxHash string `json:"txHash"` } -func (t *TraceOperation) UnmarshalJSON(bytes []byte) error { - toi := traceOperationInter{} - - if err := json.Unmarshal(bytes, &toi); err != nil { - return err - } - - if toi.Metadata == nil { - t.BlockHeight = 0 - } else { - if data, ok := toi.Metadata[metadataBlockHeight]; ok { - t.BlockHeight = uint64(data.(float64)) - } - - if data, ok := toi.Metadata[metadataTxHash]; ok { - t.TxHash = data.(string) - } - } - - t.Operation = toi.Operation - t.Key = toi.Key - t.Value = toi.Value +// TraceOperation represents a Cosmos SDK store operation, parsed from +// JSON lines produced by the SDK's "--trace-store" CLI flag. +type TraceOperation struct { + Operation string `json:"operation"` + Key []byte `json:"key"` + Value []byte `json:"value"` + Metadata TraceMetadata `json:"metadata"` - return nil + // SuggestedProcessor signals to the trace processor that + // what SDK module this trace comes from. + SuggestedProcessor SDKModuleName } diff --git a/tracelistener/trace_test.go b/tracelistener/trace_test.go index e389bb60..d4afffbd 100644 --- a/tracelistener/trace_test.go +++ b/tracelistener/trace_test.go @@ -84,10 +84,12 @@ func TestTraceOperation_UnmarshalJSON(t1 *testing.T) { "operation with block height", opWithBlockHeight, tracelistener.TraceOperation{ - Operation: "write", - Key: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, - Value: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, - BlockHeight: 42, + Operation: "write", + Key: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, + Value: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, + Metadata: tracelistener.TraceMetadata{ + BlockHeight: 42, + }, }, false, }, @@ -98,7 +100,9 @@ func TestTraceOperation_UnmarshalJSON(t1 *testing.T) { Operation: "write", Key: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, Value: []byte{0x68, 0x65, 0x6c, 0x6c, 0x6f, 0xa}, - TxHash: "hash", + Metadata: tracelistener.TraceMetadata{ + TxHash: "hash", + }, }, false, }, diff --git a/tracelistener/tracelistener.go b/tracelistener/tracelistener.go index b9100412..8bd3b4ed 100644 --- a/tracelistener/tracelistener.go +++ b/tracelistener/tracelistener.go @@ -1,12 +1,13 @@ package tracelistener import ( - "bytes" "encoding/json" "fmt" "math" "reflect" + "sync" "time" + "unsafe" models "github.com/allinbits/demeris-backend-models/tracelistener" "github.com/nxadm/tail" @@ -58,8 +59,8 @@ var SupportedSDKModuleList = map[SDKModuleName]struct{}{ // Info: https://github.com/cockroachdb/cockroach/issues/49256 const dbPlaceholderLimit = 65535 -// Operation is a kind of operations a TraceWatcher observes. -type Operation []byte +// Operation represents the kind of Cosmos SDK store operation a TraceWatcher observes. +type Operation string // String implements fmt.Stringer on Operation. func (o Operation) String() string { @@ -68,16 +69,21 @@ func (o Operation) String() string { var ( // WriteOp is a write trace operation - WriteOp Operation = []byte("write") + WriteOp Operation = Operation(writeOpStr) // DeleteOp is a write trace operation - DeleteOp Operation = []byte("delete") + DeleteOp Operation = Operation(deleteOpStr) // ReadOp is a write trace operation - ReadOp Operation = []byte("read") + ReadOp Operation = Operation(readOpStr) // IterRangeOp is a write trace operation - IterRangeOp Operation = []byte("iterRange") + IterRangeOp Operation = Operation(iterRangeOp) + + writeOpStr = "write" + deleteOpStr = "delete" + readOpStr = "read" + iterRangeOp = "iterRange" ) // WritebackOp represents a unit of database writeback operated by a processor. @@ -243,9 +249,17 @@ type TraceWatcher struct { DataChan chan<- TraceOperation ErrorChan chan<- error Logger *zap.SugaredLogger + + toPool sync.Pool } func (tr *TraceWatcher) Watch() { + tr.toPool = sync.Pool{ + New: func() interface{} { + return &TraceOperation{} + }, + } + errorHappened := false for { // infinite cycle, if something goes wrong in reading the fifo we restart the cycle if errorHappened { @@ -263,44 +277,55 @@ func (tr *TraceWatcher) Watch() { } for line := range t.Lines { - if line.Err != nil { - tr.ErrorChan <- fmt.Errorf("line reading error, line %v, error %w", line, err) - break // restart the reading loop - } + tr.handleLine(line) + } + } +} - tr.Logger.Debugw("new line read from reader", "line", line.Text) +func unsafeGetBytes(s string) []byte { + return (*[0x7fff0000]byte)(unsafe.Pointer( + (*reflect.StringHeader)(unsafe.Pointer(&s)).Data), + )[:len(s):len(s)] +} - lineBytes := []byte(line.Text) +func (tr *TraceWatcher) handleLine(line *tail.Line) { + if line.Err != nil { + tr.ErrorChan <- fmt.Errorf("line reading error, line %v, error %w", line, line.Err) + return + } - // Log line used to trigger Grafana alerts. - // Do not modify or remove without changing the corresponding dashboards - tr.Logger.Infow("Probe", "c", "trace", "s", len(lineBytes)) + tr.Logger.Debugw("new line read from reader", "line", line.Text) - if !tr.mustConsiderData(lineBytes) { - continue - } + lineBytes := unsafeGetBytes(line.Text) - to := TraceOperation{} - if err := json.Unmarshal(lineBytes, &to); err != nil { - tr.ErrorChan <- fmt.Errorf("failed unmarshaling, %w, data: %s", err, line.Text) - continue - } + // Log line used to trigger Grafana alerts. + // Do not modify or remove without changing the corresponding dashboards + tr.Logger.Infow("Probe", "c", "trace", "s", len(lineBytes)) - if err := tr.ParseOperation(to); err != nil { - tr.ErrorChan <- fmt.Errorf("failed parsing operation, %w, data: %s", err, line.Text) - continue - } + to := tr.toPool.Get().(*TraceOperation) + to.Reset() + defer func() { + tr.toPool.Put(to) + }() - tr.Logger.Infow("trace processed", - "kind", to.Operation, - "block_height", to.BlockHeight, - "tx_hash", to.TxHash, - ) - } + if err := json.Unmarshal(lineBytes, &to); err != nil { + tr.ErrorChan <- fmt.Errorf("failed unmarshaling, %w, data: %s", err, line.Text) + return } + + if err := tr.ParseOperation(to); err != nil { + tr.ErrorChan <- fmt.Errorf("failed parsing operation, %w, data: %s", err, line.Text) + return + } + + tr.Logger.Infow("trace processed", + "kind", to.Operation, + "block_height", to.Metadata.BlockHeight, + "tx_hash", to.Metadata.TxHash, + ) } -func (tr *TraceWatcher) ParseOperation(data TraceOperation) error { +func (tr *TraceWatcher) ParseOperation(data *TraceOperation) error { if !tr.mustConsiderOperation(data) { return nil } @@ -310,28 +335,16 @@ func (tr *TraceWatcher) ParseOperation(data TraceOperation) error { return nil } - go func() { - tr.DataChan <- data - }() + // Happy path has been taken, locally copy data contents and pass + // them to the database writing goroutine. + go func(op TraceOperation) { + tr.DataChan <- op + }(data.Copy()) return nil } -func (tr *TraceWatcher) mustConsiderData(b []byte) bool { - if tr.WatchedOps == nil || len(tr.WatchedOps) == 0 { - return true - } - - for _, op := range tr.WatchedOps { - if bytes.Contains(b, op) { - return true - } - } - - return false -} - -func (tr *TraceWatcher) mustConsiderOperation(op TraceOperation) bool { +func (tr *TraceWatcher) mustConsiderOperation(op *TraceOperation) bool { if tr.WatchedOps == nil || len(tr.WatchedOps) == 0 { return true }