| // Copyright 2020 The Chromium OS 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 graphics contains graphics-related utility functions for local tests. |
| package graphics |
| |
| import ( |
| "context" |
| "fmt" |
| "io/ioutil" |
| "os" |
| "path/filepath" |
| "regexp" |
| "strconv" |
| "strings" |
| "time" |
| |
| "chromiumos/tast/common/perf" |
| "chromiumos/tast/common/testexec" |
| "chromiumos/tast/errors" |
| "chromiumos/tast/local/chrome" |
| "chromiumos/tast/local/chrome/metrics" |
| "chromiumos/tast/testing" |
| ) |
| |
| // collectGPUPerformanceCounters gathers the use time for each of a given set of |
| // Performance Monitoring Units (PMUs), if available, providing them in a map |
| // indexed by the name of the associated Command Streamer (CS): RCS for Renderer/3D, |
| // VCS for the Fixed-Function Video (decoding and encoding), and VECS for Video |
| // Enhancement CS. The resulting map also provides an accurate hardware elapsed |
| // time counter, and the amount of time the GPU spent in sleep mode (RC6 mode). |
| // If the hardware/kernel doesn't provide PMU event monitoring, the returned |
| // counters will be nil. |
| func collectGPUPerformanceCounters(ctx context.Context, interval time.Duration) (counters map[string]time.Duration, megaPeriods int64, err error) { |
| var perfCounters = []struct { |
| filePath string |
| eventName string |
| outputName string |
| }{ |
| // "actual-frequency" is NOT a frequency, but an accumulation of cycles. |
| {"/sys/devices/i915/events/actual-frequency", "i915/actual-frequency/", "megaperiod"}, |
| {"/sys/devices/i915/events/rcs0-busy", "i915/rcs0-busy/", "rcs"}, |
| {"/sys/devices/i915/events/vcs0-busy", "i915/vcs0-busy/", "vcs"}, |
| {"/sys/devices/i915/events/vecs0-busy", "i915/vecs0-busy/", "vecs"}, |
| {"/sys/devices/i915/events/rc6-residency", "i915/rc6-residency/", "rc6"}, |
| } |
| |
| var eventsToCollect []string |
| for _, perfCounter := range perfCounters { |
| if _, err := os.Stat(perfCounter.filePath); err == nil { |
| eventsToCollect = append(eventsToCollect, perfCounter.eventName) |
| } |
| } |
| |
| if len(eventsToCollect) == 0 { |
| return nil, 0, nil |
| } |
| |
| // Run the command e.g. `perf stat -e i915/vcs0-busy/ -- sleep 2` |
| cmd := testexec.CommandContext(ctx, |
| "/usr/bin/perf", "stat", "-e", strings.Join(eventsToCollect, ","), "--", "sleep", |
| strconv.FormatInt(int64(interval/time.Second), 10)) |
| _, stderr, err := cmd.SeparatedOutput() |
| if err != nil { |
| return nil, 0, errors.Wrap(err, "error while measuring perf counters") |
| } |
| perfOutput := string(stderr) |
| |
| // A sample multiple counter output perfOutput could be e.g.: |
| // Performance counter stats for 'system wide': |
| // |
| // 8215 M i915/actual-frequency/ |
| // 2001181274 ns i915/rc6-residency/ |
| // 17188646693 ns i915/rcs0-busy/ |
| // 11937916640 ns i915/vcs0-busy/ |
| // 12894570939 ns i915/vecs0-busy/ |
| // |
| // 25.001367738 seconds time elapsed |
| counters = make(map[string]time.Duration) |
| |
| regexps := make(map[string]*regexp.Regexp) |
| for _, perfCounter := range perfCounters { |
| regexps[perfCounter.outputName] = regexp.MustCompile(`([0-9]+ ns)\s*` + regexp.QuoteMeta(perfCounter.eventName)) |
| } |
| // Add and extra regexp for the overall time elapsed. |
| regexps["total"] = regexp.MustCompile("([0-9]+[.][0-9]+ s)econds time elapsed") |
| |
| perfLines := strings.Split(perfOutput, "\n") |
| for _, line := range perfLines { |
| for name, r := range regexps { |
| submatch := r.FindStringSubmatch(line) |
| if submatch == nil { |
| continue |
| } |
| // ParseDuration() cannot parse whitespaces in the input string. |
| counters[name], err = time.ParseDuration(strings.Replace(string(submatch[1]), " ", "", -1)) |
| if err != nil { |
| dir, ok := testing.ContextOutDir(ctx) |
| if !ok { |
| return nil, 0, errors.New("failed to retrieve output directory") |
| } |
| const outFile = "perf_stat_output.log" |
| if err := ioutil.WriteFile(filepath.Join(dir, outFile), stderr, 0644); err != nil { |
| testing.ContextLogf(ctx, "Failed to dump perf output to %s: %v", outFile, err) |
| } |
| return nil, 0, errors.Wrapf(err, "error parsing perf output, see %s if present", outFile) |
| } |
| } |
| } |
| |
| // Run and extra regexp pass for the GPU actual-frequency. This information is |
| // provided as a number-of-accumulated mega cycles over the total time, see |
| // https://patchwork.freedesktop.org/patch/339667/. |
| regexpCycles := regexp.MustCompile(`([0-9]+)\s*M\s*` + "i915/actual-frequency/") |
| for _, line := range perfLines { |
| submatch := regexpCycles.FindStringSubmatch(line) |
| if submatch == nil { |
| continue |
| } |
| if megaPeriods, err = strconv.ParseInt(submatch[1], 10, 64); err != nil { |
| return nil, 0, errors.Wrapf(err, "error parsing perf output (%s)", perfOutput) |
| } |
| break |
| } |
| |
| return counters, megaPeriods, nil |
| } |
| |
| // collectPackagePerformanceCounters gathers the amount of cycles the Package |
| // was in each of a given C-States, providing also the total amount of cycles |
| // elapsed. If the hardware/kernel doesn't provide this type of event monitoring |
| // or if the reference TSC (Time Stamp Counter) is not available, the returned |
| // counter map will be nil, but this is not considered an error. |
| func collectPackagePerformanceCounters(ctx context.Context, interval time.Duration) (counters map[string]int64, err error) { |
| var perfCounters = []struct { |
| filePath string |
| eventName string |
| outputName string |
| necessary bool |
| }{ |
| {"/sys/devices/cstate_pkg/events/c1-residency", "cstate_pkg/c1-residency/", "c1", false}, |
| {"/sys/devices/cstate_pkg/events/c2-residency", "cstate_pkg/c2-residency/", "c2", false}, |
| {"/sys/devices/cstate_pkg/events/c3-residency", "cstate_pkg/c3-residency/", "c3", false}, |
| {"/sys/devices/cstate_pkg/events/c4-residency", "cstate_pkg/c4-residency/", "c4", false}, |
| {"/sys/devices/cstate_pkg/events/c5-residency", "cstate_pkg/c5-residency/", "c5", false}, |
| {"/sys/devices/cstate_pkg/events/c6-residency", "cstate_pkg/c6-residency/", "c6", false}, |
| {"/sys/devices/cstate_pkg/events/c7-residency", "cstate_pkg/c7-residency/", "c7", false}, |
| {"/sys/devices/cstate_pkg/events/c8-residency", "cstate_pkg/c8-residency/", "c8", false}, |
| {"/sys/devices/cstate_pkg/events/c9-residency", "cstate_pkg/c9-residency/", "c9", false}, |
| {"/sys/devices/cstate_pkg/events/c10-residency", "cstate_pkg/c10-residency/", "c10", false}, |
| // TSC (Time StampCounter) is necessary to give dimension to all others. |
| {"/sys/devices/msr/events/tsc", "msr/tsc/", "tsc", true}, |
| } |
| |
| var eventsToCollect []string |
| for _, perfCounter := range perfCounters { |
| if _, err := os.Stat(perfCounter.filePath); err == nil { |
| eventsToCollect = append(eventsToCollect, perfCounter.eventName) |
| } else if perfCounter.necessary { |
| return nil, nil |
| } |
| } |
| // The TSC event will be present. |
| if len(eventsToCollect) <= 1 { |
| return nil, nil |
| } |
| |
| // Run the command e.g. `perf stat -C 1 -e msr/tsc/,cstate_pkg/c2-residency/ -- sleep 2` |
| // Limit the collection to the first core ("-C 0") otherwise the results would |
| // add the TSC counters in each CPU. |
| cmd := testexec.CommandContext(ctx, |
| "/usr/bin/perf", "stat", "-C", "0", "-e", strings.Join(eventsToCollect, ","), "--", "sleep", |
| strconv.FormatInt(int64(interval/time.Second), 10)) |
| _, stderr, err := cmd.SeparatedOutput() |
| if err != nil { |
| return nil, errors.Wrap(err, "error while measuring perf counters") |
| } |
| perfOutput := string(stderr) |
| |
| // A sample multiple counter output perfOutput could be e.g.: |
| // Performance counter stats for 'CPU(s) 0': |
| // |
| // 1017226860 cstate_pkg/c2-residency/ |
| // 596249316 cstate_pkg/c3-residency/ |
| // 7153458 cstate_pkg/c6-residency/ |
| // 870845664 cstate_pkg/c7-residency/ |
| // 3182648118 cstate_pkg/c8-residency/ |
| // 0 cstate_pkg/c9-residency/ |
| // 0 cstate_pkg/c10-residency/ |
| // 5994345394 msr/tsc/ |
| // |
| // 2.001372100 seconds time elapsed |
| counters = make(map[string]int64) |
| |
| regexps := make(map[string]*regexp.Regexp) |
| for _, perfCounter := range perfCounters { |
| regexps[perfCounter.outputName] = regexp.MustCompile(`([0-9]+)\s*` + regexp.QuoteMeta(perfCounter.eventName)) |
| } |
| |
| perfLines := strings.Split(perfOutput, "\n") |
| for _, line := range perfLines { |
| for name, r := range regexps { |
| submatch := r.FindStringSubmatch(line) |
| if submatch == nil { |
| continue |
| } |
| counters[name], err = strconv.ParseInt(submatch[1], 10, 64) |
| if err != nil { |
| return nil, errors.Wrap(err, "error parsing perf output") |
| } |
| } |
| } |
| return counters, nil |
| } |
| |
| func reportMetric(name, unit string, value float64, direction perf.Direction, p *perf.Values) { |
| p.Set(perf.Metric{ |
| Name: name, |
| Unit: unit, |
| Direction: direction, |
| }, value) |
| } |
| |
| func parseAndReportCounter(ctx context.Context, counters map[string]time.Duration, counterName string, p *perf.Values) { |
| if counter, ok := counters[counterName]; ok && counter.Seconds() != 0 { |
| usage := 100 * counter.Seconds() / counters["total"].Seconds() |
| testing.ContextLogf(ctx, "%s: %f%%", counterName, usage) |
| reportMetric(fmt.Sprintf("%s_usage", counterName), "percent", usage, perf.SmallerIsBetter, p) |
| } |
| } |
| |
| // MeasureGPUCounters measures GPU usage for a period of time t into p. |
| func MeasureGPUCounters(ctx context.Context, t time.Duration, p *perf.Values) error { |
| testing.ContextLog(ctx, "Measuring GPU usage for ", t) |
| counters, megaPeriods, err := collectGPUPerformanceCounters(ctx, t) |
| if err != nil { |
| return errors.Wrap(err, "error collecting graphics performance counters") |
| } |
| if counters == nil { |
| return nil |
| } |
| if counters["total"].Milliseconds() == 0 { |
| return errors.New("total elapsed time counter is zero") |
| } |
| |
| if megaPeriods != 0 { |
| frequencyMHz := float64(megaPeriods) / counters["total"].Seconds() |
| testing.ContextLogf(ctx, "Average frequency: %fMHz", frequencyMHz) |
| reportMetric("frequency", "MHz", frequencyMHz, perf.SmallerIsBetter, p) |
| } |
| parseAndReportCounter(ctx, counters, "rcs", p) |
| parseAndReportCounter(ctx, counters, "vcs", p) |
| parseAndReportCounter(ctx, counters, "vecs", p) |
| parseAndReportCounter(ctx, counters, "rc6", p) |
| |
| return nil |
| } |
| |
| // MeasurePackageCStateCounters measures the Package C-State residencies for a |
| // period of time t into p. Package C-States counters report how many cycles the |
| // package was in a given state, with a larger index corresponding to deeper |
| // sleep states. The total elapsed cycles is available under the first CPU's TSC |
| // (Time Stamp Counter) register. The "active " state, which would be c0, is the |
| // remaining cycles. See e.g. https://en.wikichip.org/wiki/acpi/c-states. |
| func MeasurePackageCStateCounters(ctx context.Context, t time.Duration, p *perf.Values) error { |
| testing.ContextLog(ctx, "Measuring Package C-State residency for ", t) |
| counters, err := collectPackagePerformanceCounters(ctx, t) |
| if err != nil { |
| return errors.Wrap(err, "error collecting C-State performance counters") |
| } |
| if counters == nil { |
| return nil |
| } |
| // "tsc" (Time Stamp Counter register) is a special entry because is the |
| // amount of cycles elapsed and gives a reference for all the C-States |
| // counters. We don't report it. |
| var accu int64 |
| for name, value := range counters { |
| if name == "tsc" { |
| continue |
| } |
| accu += value |
| |
| cStatePercent := 100 * float64(value) / float64(counters["tsc"]) |
| testing.ContextLogf(ctx, "%s: %f%%", name, cStatePercent) |
| reportMetric(name, "percent", cStatePercent, perf.BiggerIsBetter, p) |
| } |
| // The amount of cycles not in any sleep state is the active state, "c0". |
| c0Percent := 100 * float64(counters["tsc"]-accu) / float64(counters["tsc"]) |
| testing.ContextLogf(ctx, "c0: %f%%", c0Percent) |
| reportMetric("c0", "percent", c0Percent, perf.SmallerIsBetter, p) |
| |
| return nil |
| } |
| |
| // UpdatePerfMetricFromHistogram takes a snapshot of histogramName and |
| // calculates the average difference with initHistogram. The result is then |
| // logged to perfValues with metricName. |
| func UpdatePerfMetricFromHistogram(ctx context.Context, tconn *chrome.TestConn, histogramName string, initHistogram *metrics.Histogram, perfValues *perf.Values, metricName string) error { |
| laterHistogram, err := metrics.GetHistogram(ctx, tconn, histogramName) |
| if err != nil { |
| return errors.Wrap(err, "failed to get later histogram") |
| } |
| histogramDiff, err := laterHistogram.Diff(initHistogram) |
| if err != nil { |
| return errors.Wrap(err, "failed diffing histograms") |
| } |
| // Some devices don't have hardware decode acceleration, so the histogram diff |
| // will be empty, this is not an error condition. |
| if len(histogramDiff.Buckets) > 0 { |
| decodeMetric := perf.Metric{ |
| Name: metricName, |
| Unit: "ms", |
| Direction: perf.SmallerIsBetter, |
| Multiple: true, |
| } |
| |
| numHistogramSamples := float64(histogramDiff.TotalCount()) |
| var average float64 |
| // Walk the buckets of histogramDiff, append the central value of the |
| // histogram bucket as many times as bucket entries to perfValues, and |
| // calculate the average on the fly for debug printout purposes. This average |
| // is a discrete approximation to the statistical average of the samples |
| // underlying the histogramDiff histograms. |
| for _, bucket := range histogramDiff.Buckets { |
| bucketMidpoint := float64(bucket.Max+bucket.Min) / 2.0 |
| for i := 0; i < int(bucket.Count); i++ { |
| perfValues.Append(decodeMetric, bucketMidpoint) |
| } |
| average += bucketMidpoint * float64(bucket.Count) / numHistogramSamples |
| } |
| testing.ContextLog(ctx, histogramName, ": histogram:", histogramDiff.String(), "; average: ", average) |
| } |
| return nil |
| } |