diff --git a/book/src/SUMMARY.md b/book/src/SUMMARY.md index 1c65cf7de..a046e06fd 100644 --- a/book/src/SUMMARY.md +++ b/book/src/SUMMARY.md @@ -80,6 +80,7 @@ - [Custom Prometheus metrics](./libs/wasp/benchspy/prometheus_custom.md) - [To Loki or not to Loki?](./libs/wasp/benchspy/loki_dillema.md) - [Real world example](./libs/wasp/benchspy/real_world.md) + - [Debugging](./libs/wasp/benchspy/debugging.md) - [Reports](./libs/wasp/benchspy/reports/overview.md) - [Standard Report](./libs/wasp/benchspy/reports/standard_report.md) - [Adding new QueryExecutor](./libs/wasp/benchspy/reports/new_executor.md) diff --git a/book/src/libs/wasp/benchspy/debugging.md b/book/src/libs/wasp/benchspy/debugging.md new file mode 100644 index 000000000..85b05f14c --- /dev/null +++ b/book/src/libs/wasp/benchspy/debugging.md @@ -0,0 +1,3 @@ +# BenchSpy - Debugging + +If you run into any issues with `BenchSpy` it might help to lower the default logging level to either `debug` or `trace`. It's controlled by environment variable called `BENCHSPY_LOG_LEVEL`. \ No newline at end of file diff --git a/book/src/libs/wasp/benchspy/getting_started.md b/book/src/libs/wasp/benchspy/getting_started.md index 9f5152ff5..d530d35ba 100644 --- a/book/src/libs/wasp/benchspy/getting_started.md +++ b/book/src/libs/wasp/benchspy/getting_started.md @@ -11,4 +11,7 @@ The following examples assume you have access to the following applications: Since BenchSpy is tightly coupled with WASP, we highly recommend that you [get familiar with it first](../overview.md) if you haven't already. -Ready? [Let's get started!](./first_test.md) \ No newline at end of file +Ready? [Let's get started!](./first_test.md) + +> [!NOTE] +> You can `BENCHSPY_LOG_LEVEL` environment variable to control the log level. \ No newline at end of file diff --git a/wasp/benchspy/TO_DO.md b/wasp/benchspy/TO_DO.md index 825d9bee4..d1e0ab5e2 100644 --- a/wasp/benchspy/TO_DO.md +++ b/wasp/benchspy/TO_DO.md @@ -1,5 +1,5 @@ Known things to do: -- [ ] add logger +- [x] add logger - [x] add unit tests for prometheus - [x] add wasp test for prometheus only - [ ] add e2e OCRv2 test with CTFv2 diff --git a/wasp/benchspy/basic.go b/wasp/benchspy/basic.go index f466ab33f..41c49083f 100644 --- a/wasp/benchspy/basic.go +++ b/wasp/benchspy/basic.go @@ -34,9 +34,12 @@ func MustNewBasicData(commitOrTag string, generators ...*wasp.Generator) BasicDa } // NewBasicData creates a new BasicData instance using the provided commit or tag and a list of generators. -// It ensures that at least one generator is provided and that it is associated with a testing.T instance. +// It ensures that at least one generator is provided and that it is associated with a testing.T instance. // This function is essential for initializing test data configurations in a structured manner. func NewBasicData(commitOrTag string, generators ...*wasp.Generator) (*BasicData, error) { + L.Debug(). + Msg("Creating new basic data instance") + if len(generators) == 0 { return nil, errors.New("at least one generator is required") } @@ -60,12 +63,18 @@ func NewBasicData(commitOrTag string, generators ...*wasp.Generator) (*BasicData return nil, timeErr } + L.Debug(). + Msg("Basic data instance created successfully") + return b, nil } // FillStartEndTimes calculates the earliest start time and latest end time from generator schedules. // It updates the BasicData instance with these times, ensuring all segments have valid start and end times. func (b *BasicData) FillStartEndTimes() error { + L.Debug(). + Msg("Filling test start and end times for basic data instance based on generator schedules") + earliestTime := time.Now() var latestTime time.Time @@ -92,6 +101,10 @@ func (b *BasicData) FillStartEndTimes() error { b.TestStart = earliestTime b.TestEnd = latestTime + L.Debug(). + Str("Test start time", earliestTime.Format(time.RFC3339)). + Str("Test end time", latestTime.Format(time.RFC3339)). + Msg("Start and end times filled successfully") return nil } @@ -99,6 +112,8 @@ func (b *BasicData) FillStartEndTimes() error { // Validate checks the integrity of the BasicData fields, ensuring that the test start and end times are set, // and that at least one generator configuration is provided. It returns an error if any of these conditions are not met. func (b *BasicData) Validate() error { + L.Debug(). + Msg("Validating basic data instance") if b.TestStart.IsZero() { return errors.New("test start time is missing. We cannot query Loki without a time range. Please set it and try again") } @@ -110,6 +125,9 @@ func (b *BasicData) Validate() error { return errors.New("generator configs are missing. At least one is required. Please set them and try again") } + L.Debug(). + Msg("Basic data instance is valid") + return nil } @@ -118,7 +136,9 @@ func (b *BasicData) Validate() error { // returning an error if any discrepancies are found. This function is useful for ensuring // consistency between data reports before processing or comparison. func (b *BasicData) IsComparable(otherData BasicData) error { - // are all configs present? do they have the same schedule type? do they have the same segments? is call timeout the same? is rate limit timeout the same? + L.Debug(). + Msg("Checking if basic data instances are comparable") + if len(b.GeneratorConfigs) != len(otherData.GeneratorConfigs) { return fmt.Errorf("generator configs count is different. Expected %d, got %d", len(b.GeneratorConfigs), len(otherData.GeneratorConfigs)) } @@ -133,6 +153,9 @@ func (b *BasicData) IsComparable(otherData BasicData) error { } } + L.Debug(). + Msg("Basic data instances are comparable") + return nil } diff --git a/wasp/benchspy/direct.go b/wasp/benchspy/direct.go index abb980c67..3c78d20f1 100644 --- a/wasp/benchspy/direct.go +++ b/wasp/benchspy/direct.go @@ -39,19 +39,27 @@ func NewStandardDirectQueryExecutor(generator *wasp.Generator) (*DirectQueryExec // NewDirectQueryExecutor creates a new DirectQueryExecutor with the specified generator and query functions. // It initializes the executor with a kind name and prepares a map for query results, enabling efficient query execution. func NewDirectQueryExecutor(generator *wasp.Generator, queries map[string]DirectQueryFn) (*DirectQueryExecutor, error) { - g := &DirectQueryExecutor{ + ex := &DirectQueryExecutor{ KindName: string(StandardQueryExecutor_Direct), Generator: generator, Queries: queries, QueryResults: make(map[string]interface{}), } - return g, nil + L.Debug(). + Str("Generator", ex.GeneratorName()). + Int("Queries", len(queries)). + Msg("Creating new Direct query executor") + + return ex, nil } // GeneratorName returns the name of the generator associated with the query executor. // It is useful for identifying and categorizing results based on their generator type. func (g *DirectQueryExecutor) GeneratorName() string { + if g.Generator == nil { + return "" + } return g.Generator.Cfg.GenName } @@ -70,6 +78,10 @@ func (l *DirectQueryExecutor) Kind() string { // IsComparable checks if the given QueryExecutor is of the same type and has comparable configurations. // It returns an error if the types do not match or if the configurations are not comparable. func (g *DirectQueryExecutor) IsComparable(otherQueryExecutor QueryExecutor) error { + L.Debug(). + Str("Expected kind", g.KindName). + Msg("Checking if query executors are comparable") + otherType := reflect.TypeOf(otherQueryExecutor) if otherType != reflect.TypeOf(g) { @@ -82,7 +94,16 @@ func (g *DirectQueryExecutor) IsComparable(otherQueryExecutor QueryExecutor) err return errors.New("generators are not comparable") } - return g.compareQueries(otherGeneratorQueryExecutor.Queries) + queryErr := g.compareQueries(otherGeneratorQueryExecutor.Queries) + if queryErr != nil { + return queryErr + } + + L.Debug(). + Str("Kind", g.KindName). + Msg("Query executors are comparable") + + return nil } func (l *DirectQueryExecutor) compareQueries(other map[string]DirectQueryFn) error { @@ -104,6 +125,9 @@ func (l *DirectQueryExecutor) compareQueries(other map[string]DirectQueryFn) err // It ensures that a generator is set and at least one query is provided. // Returns an error if validation fails, helping to prevent execution issues. func (g *DirectQueryExecutor) Validate() error { + L.Debug(). + Msg("Validating Direct query executor") + if g.Generator == nil { return errors.New("generator is not set") } @@ -112,6 +136,9 @@ func (g *DirectQueryExecutor) Validate() error { return errors.New("at least one query is needed") } + L.Debug(). + Msg("Direct query executor is valid") + return nil } @@ -119,11 +146,21 @@ func (g *DirectQueryExecutor) Validate() error { // It validates the generator's data and aggregates responses before executing each query. // This function is essential for processing and retrieving results from multiple queries concurrently. func (g *DirectQueryExecutor) Execute(_ context.Context) error { + L.Info(). + Str("Generator", g.Generator.Cfg.GenName). + Int("Queries", len(g.Queries)). + Msg("Executing Direct queries") + if g.Generator == nil { return errors.New("generator is not set") } for queryName, queryFunction := range g.Queries { + L.Debug(). + Str("Generator", g.Generator.Cfg.GenName). + Str("Query", queryName). + Msg("Executing Direct query") + if g.Generator.GetData() == nil { return fmt.Errorf("generator %s has no data", g.Generator.Cfg.GenName) } @@ -148,8 +185,18 @@ func (g *DirectQueryExecutor) Execute(_ context.Context) error { } g.QueryResults[queryName] = results + + L.Debug(). + Str("Query", queryName). + Float64("Result", results). + Msg("Direct query executed successfully") } + L.Info(). + Str("Generator", g.Generator.Cfg.GenName). + Int("Queries", len(g.Queries)). + Msg("Direct queries executed successfully") + return nil } @@ -160,6 +207,9 @@ func (g *DirectQueryExecutor) TimeRange(_, _ time.Time) { } func (g *DirectQueryExecutor) generateStandardQueries() (map[string]DirectQueryFn, error) { + L.Debug(). + Msg("Generating standard Direct queries") + standardQueries := make(map[string]DirectQueryFn) for _, metric := range StandardLoadMetrics { @@ -170,6 +220,10 @@ func (g *DirectQueryExecutor) generateStandardQueries() (map[string]DirectQueryF standardQueries[string(metric)] = query } + L.Debug(). + Int("Queries", len(standardQueries)). + Msg("Standard queries Direct generated") + return standardQueries, nil } diff --git a/wasp/benchspy/log.go b/wasp/benchspy/log.go index f4295af64..b2044e0f2 100644 --- a/wasp/benchspy/log.go +++ b/wasp/benchspy/log.go @@ -1,6 +1,7 @@ package benchspy import ( + "fmt" "os" "github.com/rs/zerolog" @@ -28,5 +29,15 @@ func initDefaultLogging() { if err != nil { panic(err) } - L = log.Output(zerolog.ConsoleWriter{Out: os.Stderr}).Level(lvl) + + output := zerolog.ConsoleWriter{Out: os.Stderr} + output.FormatMessage = func(i interface{}) string { + return fmt.Sprintf("\033[38;5;136m%v \033[0m", i) // Dark gold color for message + } + + output.FormatFieldValue = func(i interface{}) string { + return fmt.Sprintf("\033[38;5;136m%v \033[0m", i) // Dark gold color for field value + } + + L = log.Output(output).Level(lvl) } diff --git a/wasp/benchspy/loki.go b/wasp/benchspy/loki.go index d6204f968..e167c7557 100644 --- a/wasp/benchspy/loki.go +++ b/wasp/benchspy/loki.go @@ -27,6 +27,11 @@ var ( // It initializes the executor with the specified generator name, queries, and Loki configuration. // This function is useful for setting up a query executor to interact with Loki for log data retrieval. func NewLokiQueryExecutor(generatorName string, queries map[string]string, lokiConfig *wasp.LokiConfig) *LokiQueryExecutor { + L.Debug(). + Str("Generator", generatorName). + Int("Queries", len(queries)). + Msg("Creating new Loki query executor") + return &LokiQueryExecutor{ KindName: string(StandardQueryExecutor_Loki), GeneratorNameString: generatorName, @@ -74,6 +79,10 @@ func (l *LokiQueryExecutor) Kind() string { // It compares the queries of both executors to ensure they are equivalent in structure and content. // This function is useful for validating compatibility between different query executors. func (l *LokiQueryExecutor) IsComparable(otherQueryExecutor QueryExecutor) error { + L.Debug(). + Str("Expected kind", l.KindName). + Msg("Checking if query executors are comparable") + otherType := reflect.TypeOf(otherQueryExecutor) if otherType != reflect.TypeOf(l) { @@ -85,13 +94,25 @@ func (l *LokiQueryExecutor) IsComparable(otherQueryExecutor QueryExecutor) error return fmt.Errorf("generator name is different. Expected %s, got %s", l.GeneratorNameString, otherAsLoki.GeneratorNameString) } - return l.compareQueries(otherQueryExecutor.(*LokiQueryExecutor).Queries) + queryErr := l.compareQueries(otherQueryExecutor.(*LokiQueryExecutor).Queries) + if queryErr != nil { + return queryErr + } + + L.Debug(). + Str("Kind", l.KindName). + Msg("Query executors are comparable") + + return nil } // Validate checks if the LokiQueryExecutor has valid queries and configuration. // It returns an error if no queries are set or if the configuration is missing, // ensuring that the executor is ready for execution. func (l *LokiQueryExecutor) Validate() error { + L.Debug(). + Msg("Validating Loki query executor") + if len(l.Queries) == 0 { return errors.New("there are no Loki queries, there's nothing to fetch. Please set them and try again") } @@ -102,6 +123,9 @@ func (l *LokiQueryExecutor) Validate() error { return errors.New("generator name is missing. Please set it and try again") } + L.Debug(). + Msg("Loki query executor is valid") + return nil } @@ -109,6 +133,11 @@ func (l *LokiQueryExecutor) Validate() error { // It requires a valid configuration and handles basic authentication if provided. // The function returns an error if any query execution fails or if the configuration is missing. func (l *LokiQueryExecutor) Execute(ctx context.Context) error { + L.Info(). + Str("Generator", l.GeneratorNameString). + Int("Queries", len(l.Queries)). + Msg("Executing Loki queries") + var basicAuth client.LokiBasicAuth if l.Config == nil { @@ -130,6 +159,12 @@ func (l *LokiQueryExecutor) Execute(ctx context.Context) error { errGroup, errCtx := errgroup.WithContext(ctx) for name, query := range l.Queries { + L.Debug(). + Str("Generator", l.GeneratorNameString). + Str("Query name", name). + Str("Query", query). + Msg("Executing Loki query") + errGroup.Go(func() error { queryParams := client.LokiQueryParams{ Query: query, @@ -158,8 +193,17 @@ func (l *LokiQueryExecutor) Execute(ctx context.Context) error { select { case resultCh <- resultMap: + L.Debug(). + Str("Generator", l.GeneratorNameString). + Str("Query name", name). + Msg("Loki query executed successfully") return nil case <-errCtx.Done(): + L.Debug(). + Str("Generator", l.GeneratorNameString). + Str("Query name", name). + Str("Upstream error", errCtx.Err().Error()). + Msg("Loki query execution cancelled") return errCtx.Err() // Allows goroutine to exit if timeout occurs } }) @@ -176,6 +220,11 @@ func (l *LokiQueryExecutor) Execute(ctx context.Context) error { } } + L.Info(). + Str("Generator", l.GeneratorNameString). + Int("Queries", len(l.Queries)). + Msg("Loki queries executed successfully") + return nil } @@ -270,6 +319,9 @@ func (l *LokiQueryExecutor) standardQuery(standardMetric StandardLoadMetric, tes } func (l *LokiQueryExecutor) generateStandardQueries(testName, generatorName, branch, commit string, startTime, endTime time.Time) (map[string]string, error) { + L.Debug(). + Msg("Generating standard Loki queries") + standardQueries := make(map[string]string) for _, metric := range StandardLoadMetrics { @@ -280,6 +332,10 @@ func (l *LokiQueryExecutor) generateStandardQueries(testName, generatorName, bra standardQueries[string(metric)] = query } + L.Debug(). + Int("Queries", len(standardQueries)). + Msg("Standard Loki queries generated") + return standardQueries, nil } diff --git a/wasp/benchspy/prometheus.go b/wasp/benchspy/prometheus.go index 19174df34..f21a32f23 100644 --- a/wasp/benchspy/prometheus.go +++ b/wasp/benchspy/prometheus.go @@ -55,6 +55,10 @@ type PrometheusQueryExecutor struct { // NewPrometheusQueryExecutor creates a new PrometheusResourceReporter, url should include basic auth if needed func NewPrometheusQueryExecutor(queries map[string]string, config *PrometheusConfig) (*PrometheusQueryExecutor, error) { + L.Debug(). + Int("Queries", len(queries)). + Msg("Creating new Prometheus query executor") + c, err := client.NewPrometheusClient(config.Url) if err != nil { return nil, errors.Wrapf(err, "failed to create Prometheus client") @@ -92,7 +96,16 @@ func NewStandardPrometheusQueryExecutor(startTime, endTime time.Time, config *Pr // Execute runs the defined Prometheus queries concurrently, collecting results and warnings. // It returns an error if any query fails, allowing for efficient data retrieval in reporting tasks. func (r *PrometheusQueryExecutor) Execute(ctx context.Context) error { + L.Info(). + Int("Queries", len(r.Queries)). + Msg("Executing Prometheus queries") + for name, query := range r.Queries { + L.Debug(). + Str("Query name", name). + Str("Query", query). + Msg("Executing Prometheus query") + result, warnings, queryErr := r.client.Query(ctx, query, r.EndTime) if queryErr != nil { return errors.Wrapf(queryErr, "failed to query Prometheus for %s", name) @@ -105,6 +118,10 @@ func (r *PrometheusQueryExecutor) Execute(ctx context.Context) error { r.QueryResults[name] = result } + L.Info(). + Int("Queries", len(r.Queries)). + Msg("Prometheus queries executed successfully") + return nil } @@ -123,6 +140,9 @@ func (l *PrometheusQueryExecutor) Kind() string { // Validate checks the PrometheusQueryExecutor for a valid client and ensures that at least one query is provided. // It returns an error if the client is nil or no queries are specified, helping to ensure proper configuration before execution. func (r *PrometheusQueryExecutor) Validate() error { + L.Debug(). + Msg("Validating Prometheus query executor") + if r.client == nil { return errors.New("prometheus client is nil") } @@ -131,12 +151,19 @@ func (r *PrometheusQueryExecutor) Validate() error { return errors.New("no queries provided") } + L.Debug(). + Msg("Prometheus query executor is valid") + return nil } // IsComparable checks if the provided QueryExecutor is of the same type as the receiver. // It returns an error if the types do not match, ensuring type safety for query comparisons. func (r *PrometheusQueryExecutor) IsComparable(other QueryExecutor) error { + L.Debug(). + Str("Expected kind", r.KindName). + Msg("Checking if query executors are comparable") + otherType := reflect.TypeOf(other) if otherType != reflect.TypeOf(r) { return fmt.Errorf("expected type %s, got %s", reflect.TypeOf(r), otherType) @@ -144,7 +171,16 @@ func (r *PrometheusQueryExecutor) IsComparable(other QueryExecutor) error { asPrometheusResourceReporter := other.(*PrometheusQueryExecutor) - return r.compareQueries(asPrometheusResourceReporter.Queries) + queryErr := r.compareQueries(asPrometheusResourceReporter.Queries) + if queryErr != nil { + return queryErr + } + + L.Debug(). + Str("Kind", r.KindName). + Msg("Query executors are comparable") + + return nil } func (r *PrometheusQueryExecutor) compareQueries(other map[string]string) error { @@ -176,8 +212,14 @@ func (r *PrometheusQueryExecutor) Warnings() map[string]v1.Warnings { // MustResultsAsValue retrieves the query results as a map of metric names to their corresponding values. // It ensures that the results are in a consistent format, making it easier to work with metrics in subsequent operations. func (r *PrometheusQueryExecutor) MustResultsAsValue() map[string]model.Value { + L.Debug(). + Msg("Casting query results to expected types") + results := make(map[string]model.Value) for name, result := range r.QueryResults { + L.Debug(). + Str("Query name", name). + Msg("Casting query result to expected type") var val model.Value switch v := result.(type) { case model.Matrix: @@ -206,6 +248,11 @@ func (r *PrometheusQueryExecutor) MustResultsAsValue() map[string]model.Value { panic(fmt.Sprintf("Unknown result type: %T", result)) } results[name] = val + + L.Debug(). + Str("Query name", name). + Str("Type", val.Type().String()). + Msg("Query result casted to expected type") } return results } @@ -238,6 +285,9 @@ func (r *PrometheusQueryExecutor) standardQuery(metric StandardResourceMetric, n } func (r *PrometheusQueryExecutor) generateStandardQueries(nameRegexPattern string, startTime, endTime time.Time) (map[string]string, error) { + L.Debug(). + Msg("Generating standard Prometheus queries") + standardQueries := make(map[string]string) for _, metric := range StandardResourceMetrics { @@ -248,6 +298,10 @@ func (r *PrometheusQueryExecutor) generateStandardQueries(nameRegexPattern strin standardQueries[string(metric)] = query } + L.Debug(). + Int("Queries", len(standardQueries)). + Msg("Standard Prometheus queries generated") + return standardQueries, nil } diff --git a/wasp/benchspy/report.go b/wasp/benchspy/report.go index 7f8ae0444..ec6b8f1f9 100644 --- a/wasp/benchspy/report.go +++ b/wasp/benchspy/report.go @@ -43,6 +43,12 @@ func (b *StandardReport) LoadLatest(testName string) error { // ResultsAs retrieves and casts results from a query executor to a specified type. // It returns a map of query names to their corresponding results, or an error if casting fails. func ResultsAs[Type any](newType Type, queryExecutor QueryExecutor, queryNames ...string) (map[string]Type, error) { + L.Debug(). + Str("Executor kind", queryExecutor.Kind()). + Str("Query names", strings.Join(queryNames, ", ")). + Str("New type", fmt.Sprintf("%T", newType)). + Msg("Casting query results to new type") + results := make(map[string]Type) var toTypeOrErr = func(result interface{}, queryName string) error { @@ -71,6 +77,12 @@ func ResultsAs[Type any](newType Type, queryExecutor QueryExecutor, queryNames . } } + L.Debug(). + Str("Executor kind", queryExecutor.Kind()). + Str("Query names", strings.Join(queryNames, ", ")). + Str("New type", fmt.Sprintf("%T", newType)). + Msg("Successfully casted query results to new type") + return results, nil } @@ -153,6 +165,15 @@ func calculateDiffPercentage(current, previous float64) float64 { // CompareDirectWithThresholds evaluates the current and previous reports against specified thresholds. // It checks for significant differences in metrics and returns any discrepancies found, aiding in performance analysis. func CompareDirectWithThresholds(medianThreshold, p95Threshold, maxThreshold, errorRateThreshold float64, currentReport, previousReport *StandardReport) (bool, map[string][]error) { + L.Info(). + Str("Current report", currentReport.CommitOrTag). + Str("Previous report", previousReport.CommitOrTag). + Float64("Median threshold", medianThreshold). + Float64("P95 threshold", p95Threshold). + Float64("Max threshold", maxThreshold). + Float64("Error rate threshold", errorRateThreshold). + Msg("Comparing Direct metrics with thresholds") + allCurrentResults := MustAllDirectResults(currentReport) allPreviousResults := MustAllDirectResults(previousReport) @@ -212,6 +233,12 @@ func CompareDirectWithThresholds(medianThreshold, p95Threshold, maxThreshold, er PrintStandardDirectMetrics(currentReport, previousReport) + L.Info(). + Str("Current report", currentReport.CommitOrTag). + Str("Previous report", previousReport.CommitOrTag). + Int("Number of meaningful differences", len(errors)). + Msg("Finished comparing Direct metrics with thresholds") + return len(errors) > 0, errors } @@ -248,6 +275,11 @@ func PrintStandardDirectMetrics(currentReport, previousReport *StandardReport) { // FetchData retrieves data for the report within the specified time range. // It validates the time range and executes queries in parallel, returning any errors encountered during execution. func (b *StandardReport) FetchData(ctx context.Context) error { + L.Info(). + Str("Test name", b.TestName). + Str("Reference", b.CommitOrTag). + Msg("Fetching data for standard report") + if b.TestStart.IsZero() || b.TestEnd.IsZero() { return errors.New("start and end times are not set") } @@ -279,6 +311,11 @@ func (b *StandardReport) FetchData(ctx context.Context) error { return err } + L.Info(). + Str("Test name", b.TestName). + Str("Reference", b.CommitOrTag). + Msg("Finished fetching data for standard report") + return nil } @@ -286,6 +323,10 @@ func (b *StandardReport) FetchData(ctx context.Context) error { // It validates the type of the other report and ensures that their basic data and query executors are comparable. // This function is useful for verifying report consistency before performing further analysis. func (b *StandardReport) IsComparable(otherReport Reporter) error { + L.Debug(). + Str("Expected type", "*StandardReport"). + Msg("Checking if reports are comparable") + if _, ok := otherReport.(*StandardReport); !ok { return fmt.Errorf("expected type %s, got %T", "*StandardReport", otherReport) } @@ -304,6 +345,9 @@ func (b *StandardReport) IsComparable(otherReport Reporter) error { } } + L.Debug(). + Msg("Reports are comparable") + return nil } @@ -360,6 +404,9 @@ func WithQueryExecutors(queryExecutors ...QueryExecutor) StandardReportOption { } func (c *standardReportConfig) validate() error { + L.Debug(). + Msg("Validating standard report configuration") + if len(c.executorTypes) == 0 && len(c.queryExecutors) == 0 { return errors.New("no standard executor types and no custom query executors are provided. At least one is needed") } @@ -391,6 +438,9 @@ func (c *standardReportConfig) validate() error { } } + L.Debug(). + Msg("Standard report configuration is valid") + return nil } @@ -398,6 +448,10 @@ func (c *standardReportConfig) validate() error { // It initializes necessary data and query executors, ensuring all configurations are validated. // This function is essential for generating reports that require specific data sources and execution strategies. func NewStandardReport(commitOrTag string, opts ...StandardReportOption) (*StandardReport, error) { + L.Info(). + Str("Reference", commitOrTag). + Msg("Creating new standard report") + config := standardReportConfig{} for _, opt := range opts { opt(&config) @@ -447,6 +501,12 @@ func NewStandardReport(commitOrTag string, opts ...StandardReportOption) (*Stand sr.LocalStorage.Directory = config.reportDirectory } + L.Info(). + Str("Reference", commitOrTag). + Str("Test name", sr.TestName). + Int("Number of query executors", len(sr.QueryExecutors)). + Msg("New standard report created") + return sr, nil } diff --git a/wasp/benchspy/storage.go b/wasp/benchspy/storage.go index b93c85b78..1dc71d041 100644 --- a/wasp/benchspy/storage.go +++ b/wasp/benchspy/storage.go @@ -35,6 +35,11 @@ func (l *LocalStorage) cleanTestName(testName string) string { // It organizes reports by test name and commit/tag, ensuring easy retrieval and management. // Returns the absolute path of the stored report or an error if the operation fails. func (l *LocalStorage) Store(testName, commitOrTag string, report interface{}) (string, error) { + L.Debug(). + Str("Test name", testName). + Str("Reference", commitOrTag). + Msg("Storing report on local storage") + l.defaultDirectoryIfEmpty() asJson, err := json.MarshalIndent(report, "", " ") if err != nil { @@ -66,6 +71,12 @@ func (l *LocalStorage) Store(testName, commitOrTag string, report interface{}) ( return reportFilePath, nil } + L.Info(). + Str("Test name", testName). + Str("Reference", commitOrTag). + Str("Report path", abs). + Msg("Report stored successfully") + return abs, nil } @@ -81,12 +92,20 @@ func (l *LocalStorage) Load(testName, commitOrTag string, report interface{}) er var ref string if commitOrTag == "" { + L.Info(). + Str("Test name", testName). + Msg("Loading latest report from local storage") + var refErr error ref, refErr = l.findRef(cleanTestName) if refErr != nil { return refErr } } else { + L.Info(). + Str("Test name", testName). + Str("Reference", commitOrTag). + Msg("Loading report from local storage") ref = commitOrTag } @@ -102,6 +121,12 @@ func (l *LocalStorage) Load(testName, commitOrTag string, report interface{}) er return errors.Wrapf(err, "failed to decode file %s", reportFilePath) } + L.Info(). + Str("Test name", testName). + Str("Reference", ref). + Str("Report path", reportFilePath). + Msg("Report loaded successfully") + return nil } @@ -123,6 +148,14 @@ func (l *LocalStorage) findAllGitlikeReferences(cleanTestName string, entries [] } func (l *LocalStorage) findLatestGitRef(refs []string) (string, error) { + L.Debug(). + Int("References found", len(refs)). + Msg("Finding latest report based on Git history") + + L.Trace(). + Str("References", strings.Join(refs, ", ")). + Msg("Resolving references to commit hashes") + var ref string // Find git root cmd := exec.Command("git", "rev-parse", "--show-toplevel") @@ -140,6 +173,14 @@ func (l *LocalStorage) findLatestGitRef(refs []string) (string, error) { cmd.Dir = gitRoot if out, err := cmd.Output(); err == nil { resolvedRefs[ref] = strings.TrimSpace(string(out)) + L.Trace(). + Str("Reference", ref). + Str("Resolved", resolvedRefs[ref]). + Msg("Reference resolved to commit hash") + } else { + L.Warn(). + Str("Reference", ref). + Msg("Failed to resolve reference to commit hash") } } @@ -149,6 +190,10 @@ func (l *LocalStorage) findLatestGitRef(refs []string) (string, error) { commitRefs = append(commitRefs, hash) } + L.Debug(). + Str("Commits found", strings.Join(commitRefs, ", ")). + Msg("Finding latest commit among resolved references") + args := append([]string{"rev-list", "--topo-order", "--date-order", "--max-count=1"}, commitRefs...) cmd = exec.Command("git", args...) cmd.Dir = gitRoot @@ -168,6 +213,11 @@ func (l *LocalStorage) findLatestGitRef(refs []string) (string, error) { } } + L.Debug(). + Str("Latest commit", latestCommit). + Str("Original ref", ref). + Msg("Found original reference for latest commit") + if !foundOriginal { return "", fmt.Errorf("no file found for latest commit %s. This should never happen", latestCommit) } @@ -176,6 +226,10 @@ func (l *LocalStorage) findLatestGitRef(refs []string) (string, error) { } func (l *LocalStorage) findRef(cleanTestName string) (string, error) { + L.Debug(). + Str("Test name", cleanTestName). + Msg("Finding available reports in local storage") + entries, err := os.ReadDir(l.Directory) if err != nil { return "", errors.Wrap(err, "failed to read storage directory") @@ -186,6 +240,11 @@ func (l *LocalStorage) findRef(cleanTestName string) (string, error) { return "", refErr } + L.Debug(). + Str("Test name", cleanTestName). + Int("References found", len(refs)). + Msg("Found available reports in local storage") + switch len(refs) { case 0: return "", fmt.Errorf("no reports found in directory %s", l.Directory) diff --git a/wasp/examples/go.mod b/wasp/examples/go.mod index 34ebcee13..b79ee28f3 100644 --- a/wasp/examples/go.mod +++ b/wasp/examples/go.mod @@ -9,7 +9,7 @@ require ( github.com/go-resty/resty/v2 v2.15.3 github.com/montanaflynn/stats v0.7.1 github.com/prometheus/common v0.60.0 - github.com/smartcontractkit/chainlink-testing-framework/wasp v1.50.1 + github.com/smartcontractkit/chainlink-testing-framework/wasp v1.50.4 github.com/stretchr/testify v1.9.0 go.uber.org/ratelimit v0.3.1 nhooyr.io/websocket v1.8.10