From 7649578edd1d93d7802e15b5089a1ff465bbc5bf Mon Sep 17 00:00:00 2001 From: Chengxuan Xing Date: Fri, 10 Nov 2023 13:01:59 +0000 Subject: [PATCH 1/3] add report builder Signed-off-by: Chengxuan Xing --- .gitignore | 1 + cmd/run.go | 12 +- go.sum | 6 - internal/conf/conf.go | 6 +- internal/perf/perf.go | 53 +++++---- internal/util/report_builder.go | 197 ++++++++++++++++++++++++++++++-- 6 files changed, 233 insertions(+), 42 deletions(-) diff --git a/.gitignore b/.gitignore index 92f7f07..aeaf3e4 100644 --- a/.gitignore +++ b/.gitignore @@ -2,6 +2,7 @@ main .DS_Store ffperf/ffperf ff-perf.log +ffperf-report.html .vscode dist/ *.iml diff --git a/cmd/run.go b/cmd/run.go index d754775..e67c0ae 100644 --- a/cmd/run.go +++ b/cmd/run.go @@ -28,6 +28,7 @@ import ( "github.com/hyperledger/firefly-perf-cli/internal/perf" "github.com/hyperledger/firefly-perf-cli/internal/server" "github.com/hyperledger/firefly-perf-cli/internal/types" + "github.com/hyperledger/firefly-perf-cli/internal/util" "github.com/hyperledger/firefly/pkg/core" "github.com/pkg/errors" log "github.com/sirupsen/logrus" @@ -65,17 +66,22 @@ Executes a instance within a performance test suite to generate synthetic load a log.Warn("both the \"instance-name\" and \"instance-index\" flags were provided, using \"instance-name\"") } - instance, err := selectInstance(config) + instanceConfig, err := selectInstance(config) if err != nil { return err } - runnerConfig, err := generateRunnerConfigFromInstance(instance, config) + runnerConfig, err := generateRunnerConfigFromInstance(instanceConfig, config) if err != nil { return err } - perfRunner = perf.New(runnerConfig) + configYaml, err := yaml.Marshal(instanceConfig) + if err != nil { + return err + } + + perfRunner = perf.New(runnerConfig, util.NewReportForTestInstance(string(configYaml), instanceName)) httpServer = server.NewHttpServer() return nil diff --git a/go.sum b/go.sum index b506040..6d3972b 100644 --- a/go.sum +++ b/go.sum @@ -173,12 +173,6 @@ github.com/hashicorp/hcl v1.0.0 h1:0Anlzjpi4vEasTeNFn2mLJgTSwt0+6sfsiTG8qcWGx4= github.com/hashicorp/hcl v1.0.0/go.mod h1:E5yfLk+7swimpb2L/Alb/PJmXilQ/rhwaUYs4T20WEQ= github.com/hyperledger/firefly v1.2.0 h1:No82vzsur3TODU0giIECDcMnWQ/8BRGoYo7QK/avr4A= github.com/hyperledger/firefly v1.2.0/go.mod h1:tmpTfSjX/NIa7xHTtTb36S48X9+3nNutY7ZxLt3lgCU= -github.com/hyperledger/firefly-common v1.2.13 h1:4pGL8LusXoijeoxM9J36fzBq4jvZpZbGjpQqgempXMk= -github.com/hyperledger/firefly-common v1.2.13/go.mod h1:17lOH4YufiPy82LpKm8fPa/YXJ0pUyq01zK1CmklJwM= -github.com/hyperledger/firefly-common v1.2.14 h1:HON9GJZXvrL0l2AG5DWHSGiBh05hElgFS5lm1OPR83M= -github.com/hyperledger/firefly-common v1.2.14/go.mod h1:17lOH4YufiPy82LpKm8fPa/YXJ0pUyq01zK1CmklJwM= -github.com/hyperledger/firefly-common v1.2.15 h1:WdNB65IJvIyiOhVW3nxB3sQKqtJbdJ7ie0PJIM11CSU= -github.com/hyperledger/firefly-common v1.2.15/go.mod h1:17lOH4YufiPy82LpKm8fPa/YXJ0pUyq01zK1CmklJwM= github.com/hyperledger/firefly-common v1.2.16 h1:cVSaxKycOb+/oT2wExbrzxr68aVKQObeBOLaiJ0mTLg= github.com/hyperledger/firefly-common v1.2.16/go.mod h1:17lOH4YufiPy82LpKm8fPa/YXJ0pUyq01zK1CmklJwM= github.com/ianlancetaylor/demangle v0.0.0-20181102032728-5e5cf60278f6/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc= diff --git a/internal/conf/conf.go b/internal/conf/conf.go index d05bc93..17a3998 100644 --- a/internal/conf/conf.go +++ b/internal/conf/conf.go @@ -81,7 +81,7 @@ type InstanceConfig struct { MaxTimePerAction time.Duration `json:"maxTimePerAction,omitempty" yaml:"maxTimePerAction,omitempty"` MaxActions int64 `json:"maxActions,omitempty" yaml:"maxActions,omitempty"` RampLength time.Duration `json:"rampLength,omitempty" yaml:"rampLength,omitempty"` - SkipMintConfirmations bool `json:"skipMintConfirmations,omitempty" yaml:"skipMintConfirmations,omitempty"` + SkipMintConfirmations bool `json:"skipMintConfirmations" yaml:"skipMintConfirmations"` DelinquentAction string `json:"delinquentAction,omitempty" yaml:"delinquentAction,omitempty"` PerWorkerSigningKeyPrefix string `json:"perWorkerSigningKeyPrefix,omitempty" yaml:"perWorkerSigningKeyPrefix,omitempty"` } @@ -121,8 +121,8 @@ type TokenConfig struct { type ContractOptions struct { Address string `json:"address" yaml:"address"` - Channel string `json:"channel" yaml:"channel"` - Chaincode string `json:"chaincode" yaml:"chaincode"` + Channel string `json:"channel,omitempty" yaml:"channel,omitempty"` + Chaincode string `json:"chaincode,omitempty" yaml:"chaincode,omitempty"` } type FireFlyWsConfig struct { diff --git a/internal/perf/perf.go b/internal/perf/perf.go index 29572db..844540d 100644 --- a/internal/perf/perf.go +++ b/internal/perf/perf.go @@ -156,21 +156,23 @@ type inflightTest struct { var mintStartingBalance int type perfRunner struct { - bfr chan int - cfg *conf.RunnerConfig - client *resty.Client - ctx context.Context - shutdown context.CancelFunc - stopping bool + bfr chan int + cfg *conf.RunnerConfig + client *resty.Client + ctx context.Context + shutdown context.CancelFunc + stopping bool + startTime int64 endSendTime int64 endTime int64 startRampTime int64 endRampTime int64 - sendTime *util.Latency - receiveTime *util.Latency - totalTime *util.Latency + reportBuilder *util.Report + sendTime *util.Latency + receiveTime *util.Latency + totalTime *util.Latency msgTimeMap map[string]*inflightTest rampSummary int64 @@ -196,7 +198,7 @@ type SubscriptionInfo struct { Job fftypes.FFEnum } -func New(config *conf.RunnerConfig) PerfRunner { +func New(config *conf.RunnerConfig, reportBuilder *util.Report) PerfRunner { if config.LogLevel != "" { if level, err := log.ParseLevel(config.LogLevel); err == nil { log.SetLevel(level) @@ -234,6 +236,7 @@ func New(config *conf.RunnerConfig) PerfRunner { startTime: startTime, endTime: endTime, poolName: poolName, + reportBuilder: reportBuilder, sendTime: &util.Latency{}, receiveTime: &util.Latency{}, totalTime: &util.Latency{}, @@ -514,8 +517,22 @@ perfLoop: pr.stopping = true measuredActions := pr.totalSummary measuredTime := time.Since(time.Unix(pr.startTime, 0)).Seconds() - measuredTps := pr.calculateCurrentTps(true) - measuredSendTps := pr.calculateSendTps() + + testNames := make([]string, len(pr.cfg.Tests)) + for _, t := range pr.cfg.Tests { + testNames = append(testNames, t.Name.String()) + } + testNameString := testNames[0] + if len(testNames) > 1 { + testNameString = strings.Join(testNames[:], ",") + } + tps := util.GenerateTPS(measuredActions, pr.startTime, pr.endSendTime) + pr.reportBuilder.AddTestRunMetrics(testNameString, measuredActions, measuredTime, tps, pr.totalTime) + err = pr.reportBuilder.GenerateHTML() + + if err != nil { + log.Errorf("failed to generate performance report: %+v", err) + } // we sleep on shutdown / completion to allow for Prometheus metrics to be scraped one final time // After 30 seconds workers should be completed, so we check for delinquent messages @@ -538,8 +555,8 @@ perfLoop: log.Infof(" - Prometheus metric actions_submitted_total = %f\n", getMetricVal(totalActionsCounter)) log.Infof(" - Test duration (secs): %2f", measuredTime) log.Infof(" - Measured actions: %d", measuredActions) - log.Infof(" - Measured send TPS: %2f", measuredSendTps) - log.Infof(" - Measured throughput: %2f", measuredTps) + log.Infof(" - Measured send TPS: %2f", tps.SendRate) + log.Infof(" - Measured throughput: %2f", tps.Throughput) log.Infof(" - Measured send duration: %s", pr.sendTime) log.Infof(" - Measured event receiving duration: %s", pr.receiveTime) log.Infof(" - Measured total duration: %s", pr.totalTime) @@ -1352,14 +1369,6 @@ func (pr *perfRunner) calculateCurrentTps(logValue bool) float64 { } return currentTps } -func (pr *perfRunner) calculateSendTps() float64 { - measuredActions := pr.totalSummary - sendDuration := time.Duration((pr.endSendTime - pr.startTime) * int64(time.Second)) - durationSec := sendDuration.Seconds() - sendTps := float64(measuredActions) / durationSec - log.Infof("Send TPS: %v Measured Actions: %v Duration: %v", sendTps, measuredActions, durationSec) - return sendTps -} func (pr *perfRunner) ramping() bool { if time.Now().Before(time.Unix(pr.endRampTime, 0)) { diff --git a/internal/util/report_builder.go b/internal/util/report_builder.go index 919a5a3..aa44e93 100644 --- a/internal/util/report_builder.go +++ b/internal/util/report_builder.go @@ -2,17 +2,189 @@ package util import ( "fmt" + "html/template" + "os" "sync" "time" + + log "github.com/sirupsen/logrus" ) -type Summary struct { - Latency *Latency `json:"latency"` - TPS *TPS `json:"tps"` - ResultCount *TPS `json:"resultCount"` +type TestRunMetrics struct { + Name string + TotalActions string + Duration string + SendRate string + MinLatency string + MaxLatency string + AvgLatency string + Throughput string +} +type Report struct { + RunnerConfig string + TestInstanceName string + TestRuns []TestRunMetrics } -type SystemUnderTest struct { +func (r *Report) GenerateHTML() error { + htmlTemplate := ` + + + + + + HyperLedger Firefly Performance Report + + + + +
+ Firefly +
+
+

Test runner configuration

+ + 
+{{.RunnerConfig}}
+
+ +
+ +
+

Test metrics

+

+ Test instance:{{.TestInstanceName}} +

+
+ + + + + + + + + + + + {{range .TestRuns}} + + + + + + + + + + + {{end}} +
Test nameTest duration (secs)ActionsSend TPSMin LatencyMax LatencyAvg LatencyThroughput
{{.Name}}{{.TotalActions}}{{.Duration}}{{.SendRate}}{{.MinLatency}}{{.MaxLatency}}{{.AvgLatency}}{{.Throughput}}
+
+
+ + +` + // Execute the template + tmpl, err := template.New("template").Parse(htmlTemplate) + if err != nil { + return err + } + + // Create or open the output file + outputFile, err := os.Create("ffperf-report.html") + if err != nil { + return err + } + defer outputFile.Close() + + // Write the HTML output to the file + err = tmpl.Execute(outputFile, r) + if err != nil { + return err + } + + return nil +} + +func (r *Report) AddTestRunMetrics(name string, totalActions int64, duration float64, tps *TPS, lt *Latency) { + r.TestRuns = append(r.TestRuns, TestRunMetrics{ + Name: name, + TotalActions: fmt.Sprintf("%d", totalActions), + Duration: fmt.Sprintf("%f", duration), + SendRate: fmt.Sprintf("%f", tps.SendRate), + Throughput: fmt.Sprintf("%f", tps.Throughput), + MinLatency: lt.Min().String(), + MaxLatency: lt.Max().String(), + AvgLatency: lt.Avg().String(), + }) +} + +func NewReportForTestInstance(runnerConfig string, instanceName string) *Report { + return &Report{ + RunnerConfig: runnerConfig, + TestInstanceName: instanceName, + TestRuns: make([]TestRunMetrics, 0), + } } type TPS struct { @@ -20,9 +192,18 @@ type TPS struct { Throughput float64 `json:"throughput"` } -type ResultCount struct { - TotalCount int64 `json:"totalCount"` - RetryCount int64 `json:"retryCount"` +func GenerateTPS(totalActions int64, startTime int64, endSendTime int64) *TPS { + sendDuration := time.Duration((endSendTime - startTime) * int64(time.Second)) + sendDurationSec := sendDuration.Seconds() + sendRate := float64(totalActions) / sendDurationSec + + totalDurationSec := time.Since(time.Unix(startTime, 0)).Seconds() + throughput := float64(totalActions) / totalDurationSec + log.Infof("Send rate: %f, Throughput: %f, Measured Actions: %v Duration: %v (Send duration: %v)", sendRate, throughput, totalActions, sendDurationSec, totalDurationSec) + return &TPS{ + SendRate: sendRate, + Throughput: throughput, + } } type Latency struct { From 07422e0e310124443b997ab7f763eb62e2767fcd Mon Sep 17 00:00:00 2001 From: Chengxuan Xing Date: Fri, 10 Nov 2023 13:08:53 +0000 Subject: [PATCH 2/3] duration as duration string Signed-off-by: Chengxuan Xing --- internal/perf/perf.go | 4 ++-- internal/util/report_builder.go | 6 +++--- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/internal/perf/perf.go b/internal/perf/perf.go index 844540d..5fbb1c3 100644 --- a/internal/perf/perf.go +++ b/internal/perf/perf.go @@ -516,7 +516,7 @@ perfLoop: pr.stopping = true measuredActions := pr.totalSummary - measuredTime := time.Since(time.Unix(pr.startTime, 0)).Seconds() + measuredTime := time.Since(time.Unix(pr.startTime, 0)) testNames := make([]string, len(pr.cfg.Tests)) for _, t := range pr.cfg.Tests { @@ -553,7 +553,7 @@ perfLoop: log.Infof(" - Prometheus metric incomplete_events_total = %f\n", getMetricVal(incompleteEventsCounter)) log.Infof(" - Prometheus metric delinquent_msgs_total = %f\n", getMetricVal(delinquentMsgsCounter)) log.Infof(" - Prometheus metric actions_submitted_total = %f\n", getMetricVal(totalActionsCounter)) - log.Infof(" - Test duration (secs): %2f", measuredTime) + log.Infof(" - Test duration: %s", measuredTime) log.Infof(" - Measured actions: %d", measuredActions) log.Infof(" - Measured send TPS: %2f", tps.SendRate) log.Infof(" - Measured throughput: %2f", tps.Throughput) diff --git a/internal/util/report_builder.go b/internal/util/report_builder.go index aa44e93..88d3078 100644 --- a/internal/util/report_builder.go +++ b/internal/util/report_builder.go @@ -118,7 +118,7 @@ func (r *Report) GenerateHTML() error { - + @@ -166,11 +166,11 @@ func (r *Report) GenerateHTML() error { return nil } -func (r *Report) AddTestRunMetrics(name string, totalActions int64, duration float64, tps *TPS, lt *Latency) { +func (r *Report) AddTestRunMetrics(name string, totalActions int64, duration time.Duration, tps *TPS, lt *Latency) { r.TestRuns = append(r.TestRuns, TestRunMetrics{ Name: name, TotalActions: fmt.Sprintf("%d", totalActions), - Duration: fmt.Sprintf("%f", duration), + Duration: fmt.Sprintf("%s", duration), SendRate: fmt.Sprintf("%f", tps.SendRate), Throughput: fmt.Sprintf("%f", tps.Throughput), MinLatency: lt.Min().String(), From 8f04508802d8674f4d6ff42e9b1020c0d930f227 Mon Sep 17 00:00:00 2001 From: Chengxuan Xing Date: Fri, 10 Nov 2023 13:30:57 +0000 Subject: [PATCH 3/3] remove comma Signed-off-by: Chengxuan Xing --- internal/perf/perf.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/internal/perf/perf.go b/internal/perf/perf.go index 5fbb1c3..10d3458 100644 --- a/internal/perf/perf.go +++ b/internal/perf/perf.go @@ -519,8 +519,8 @@ perfLoop: measuredTime := time.Since(time.Unix(pr.startTime, 0)) testNames := make([]string, len(pr.cfg.Tests)) - for _, t := range pr.cfg.Tests { - testNames = append(testNames, t.Name.String()) + for i, t := range pr.cfg.Tests { + testNames[i] = t.Name.String() } testNameString := testNames[0] if len(testNames) > 1 {
Test nameTest duration (secs)Test duration Actions Send TPS Min Latency