blob: 7b74a19faaaad8aa8b9e7ce072b76527896f1296 [file] [log] [blame]
// Copyright 2019 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 memoryuser contains common code to run multifaceted memory tests
// with Chrome, ARC, and VMs.
package memoryuser
import (
"context"
"fmt"
"io/ioutil"
"os"
"path/filepath"
"time"
"github.com/shirou/gopsutil/v3/mem"
"chromiumos/tast/common/perf"
"chromiumos/tast/common/testexec"
"chromiumos/tast/ctxutil"
"chromiumos/tast/errors"
"chromiumos/tast/fsutil"
"chromiumos/tast/local/arc"
"chromiumos/tast/local/chrome"
"chromiumos/tast/local/memory/kernelmeter"
"chromiumos/tast/local/upstart"
"chromiumos/tast/local/wpr"
"chromiumos/tast/testing"
)
// TestEnv is a struct containing the data to be used across the test.
type TestEnv struct {
wpr *wpr.WPR
cr *chrome.Chrome
arc *arc.ARC
tconn *chrome.TestConn
p *perf.Values
vm bool
outDir string
}
// MemoryTask describes a memory-consuming task to perform.
// This allows various types of activities, such as ARC, Chrome, and VMs, to be defined
// using the same setup and run in parallel.
type MemoryTask interface {
// Run performs the memory-related task.
Run(ctx context.Context, testEnv *TestEnv) error
// Close closes any initialized data and connections for the memory-related task.
Close(ctx context.Context, testEnv *TestEnv)
// String returns a string describing the memory-related task.
String() string
// NeedVM returns a bool indicating whether the task needs a VM
NeedVM() bool
}
// logCmd logs the output of the provided command into a file every 5 seconds.
func logCmd(ctx context.Context, outfile, cmdStr string, args ...string) {
file, err := os.Create(outfile)
if err != nil {
testing.ContextLogf(ctx, "Failed to create log file %s: %v", outfile, err)
return
}
defer file.Close()
for {
if err := testing.Sleep(ctx, 5*time.Second); err != nil {
return
}
fmt.Fprintf(file, "%s\n", time.Now())
cmd := testexec.CommandContext(ctx, cmdStr, args...)
cmd.Stdout = file
cmd.Stderr = file
if err := cmd.Run(); err != nil {
testing.ContextLogf(ctx, "Command %s failed: %v", cmdStr, err)
return
}
}
}
// copyMemdLogs copies the memd log files into the output directory of the test.
func copyMemdLogs(outDir string) error {
const inputDir = "/var/log/memd"
files, err := ioutil.ReadDir(inputDir)
if err != nil {
return errors.Wrap(err, "cannot read memd")
}
for _, file := range files {
inputFile := filepath.Join(inputDir, file.Name())
if err = fsutil.CopyFile(inputFile, filepath.Join(outDir, file.Name())); err != nil {
return errors.Wrap(err, "cannot copy memd file")
}
}
return nil
}
// prepareMemdLogging restarts memd and removes old memd log files.
func prepareMemdLogging(ctx context.Context) error {
if err := upstart.RestartJob(ctx, "memd"); err != nil {
return errors.Wrap(err, "cannot restart memd")
}
const clipFilesPattern = "/var/log/memd/memd.clip*.log"
// Remove any clip files from /var/log/memd.
files, err := filepath.Glob(clipFilesPattern)
if err != nil {
return errors.Wrapf(err, "cannot list %v", clipFilesPattern)
}
for _, file := range files {
if err = os.Remove(file); err != nil {
return errors.Wrapf(err, "cannot remove %v", file)
}
}
return nil
}
// resetAndLogStats logs the VM stats from the provided kernelmeter with the identifying label,
// then resets the meter.
func resetAndLogStats(ctx context.Context, meter *kernelmeter.Meter, label string) {
defer meter.Reset()
stats, err := meter.VMStats()
if err != nil {
testing.ContextLogf(ctx, "Metrics: %s: could not log stats for test: %v", label, err)
return
}
testing.ContextLogf(ctx, "Metrics: %s: total page fault count %d", label, stats.PageFault.Count)
testing.ContextLogf(ctx, "Metrics: %s: average page fault rate %.1f pf/second", label, stats.PageFault.AverageRate)
testing.ContextLogf(ctx, "Metrics: %s: max page fault rate %.1f pf/second", label, stats.PageFault.MaxRate)
testing.ContextLogf(ctx, "Metrics: %s: total swap-in count %d", label, stats.SwapIn.Count)
testing.ContextLogf(ctx, "Metrics: %s: average swap-in rate %.1f swaps/second", label, stats.SwapIn.AverageRate)
testing.ContextLogf(ctx, "Metrics: %s: max swap-in rate %.1f swaps/second", label, stats.SwapIn.MaxRate)
testing.ContextLogf(ctx, "Metrics: %s: total swap-out count %d", label, stats.SwapOut.Count)
testing.ContextLogf(ctx, "Metrics: %s: average swap-out rate %.1f swaps/second", label, stats.SwapOut.AverageRate)
testing.ContextLogf(ctx, "Metrics: %s: max swap-out rate %.1f swaps/second", label, stats.SwapOut.MaxRate)
testing.ContextLogf(ctx, "Metrics: %s: total OOM count %d", label, stats.OOM.Count)
if swapInfo, err := mem.SwapMemory(); err == nil {
testing.ContextLogf(ctx, "Metrics: %s: free swap %v MiB", label, (swapInfo.Total-swapInfo.Used)/(1<<20))
}
if availableMiB, _, _, err := kernelmeter.ChromeosLowMem(); err == nil {
testing.ContextLogf(ctx, "Metrics: %s: available %v MiB", label, availableMiB)
}
if m, err := kernelmeter.MemInfo(); err == nil {
testing.ContextLogf(ctx, "Metrics: %s: free %v MiB, anon %v MiB, file %v MiB", label, m.Free, m.Anon, m.File)
}
}
// setPerfValues sets values for perf metrics from kernelmeter data
func setPerfValues(meter *kernelmeter.Meter, values *perf.Values, label string) error {
stats, err := meter.VMStats()
if err != nil {
return errors.Wrapf(err, "cannot compute page fault stats (%s)", label)
}
totalPageFaultCountMetric := perf.Metric{
Name: "tast_total_page_fault_count_" + label,
Unit: "count",
Direction: perf.SmallerIsBetter,
}
averagePageFaultRateMetric := perf.Metric{
Name: "tast_average_page_fault_rate_" + label,
Unit: "faults_per_second",
Direction: perf.SmallerIsBetter,
}
maxPageFaultRateMetric := perf.Metric{
Name: "tast_max_page_fault_rate_" + label,
Unit: "faults_per_second",
Direction: perf.SmallerIsBetter,
}
totalSwapInCountMetric := perf.Metric{
Name: "tast_total_swap_in_count_" + label,
Unit: "count",
Direction: perf.SmallerIsBetter,
}
averageSwapInRateMetric := perf.Metric{
Name: "tast_average_swap_in_rate_" + label,
Unit: "swaps_per_second",
Direction: perf.SmallerIsBetter,
}
maxSwapInRateMetric := perf.Metric{
Name: "tast_max_swap_in_rate_" + label,
Unit: "swaps_per_second",
Direction: perf.SmallerIsBetter,
}
totalSwapOutCountMetric := perf.Metric{
Name: "tast_total_swap_out_count_" + label,
Unit: "count",
Direction: perf.SmallerIsBetter,
}
averageSwapOutRateMetric := perf.Metric{
Name: "tast_average_swap_out_rate_" + label,
Unit: "swaps_per_second",
Direction: perf.SmallerIsBetter,
}
maxSwapOutRateMetric := perf.Metric{
Name: "tast_max_swap_out_rate_" + label,
Unit: "swaps_per_second",
Direction: perf.SmallerIsBetter,
}
totalOOMCountMetric := perf.Metric{
Name: "tast_total_oom_count_" + label,
Unit: "count",
Direction: perf.SmallerIsBetter,
}
values.Set(totalPageFaultCountMetric, float64(stats.PageFault.Count))
values.Set(averagePageFaultRateMetric, stats.PageFault.AverageRate)
values.Set(maxPageFaultRateMetric, stats.PageFault.MaxRate)
values.Set(totalSwapInCountMetric, float64(stats.SwapIn.Count))
values.Set(averageSwapInRateMetric, stats.SwapIn.AverageRate)
values.Set(maxSwapInRateMetric, stats.SwapIn.MaxRate)
values.Set(totalSwapOutCountMetric, float64(stats.SwapOut.Count))
values.Set(averageSwapOutRateMetric, stats.SwapOut.AverageRate)
values.Set(maxSwapOutRateMetric, stats.SwapOut.MaxRate)
values.Set(totalOOMCountMetric, float64(stats.OOM.Count))
return nil
}
// initChrome starts the Chrome browser.
func initChrome(ctx context.Context, p *RunParameters, te *TestEnv) error {
var opts []chrome.Option
var err error
if p.ExistingChrome != nil {
te.cr = p.ExistingChrome
if p.WPRArchivePath != "" {
return errors.New("WPR can not be used with ExistingChrome")
}
return nil
}
if p.WPRArchivePath != "" {
te.wpr, err = wpr.New(ctx, p.WPRMode, p.WPRArchivePath)
if err != nil {
return errors.Wrap(err, "cannot start WPR")
}
opts = append(opts, te.wpr.ChromeOptions...)
}
if p.UseARC {
opts = append(opts, chrome.ARCEnabled())
}
te.cr, err = chrome.New(ctx, opts...)
if err != nil {
return errors.Wrap(err, "cannot start chrome")
}
return nil
}
// newTestEnv creates a new TestEnv, creating new Chrome, ARC, ARC UI Automator device,
// and VM instances to use.
func newTestEnv(ctx context.Context, outDir string, p *RunParameters) (*TestEnv, error) {
te := &TestEnv{
vm: false,
outDir: outDir,
p: p.ExistingPerfValues,
}
if te.p == nil {
te.p = perf.NewValues()
}
// Schedule closure of partially-initialized struct.
toClose := te
defer func() {
if toClose != nil {
toClose.Close(ctx, p)
}
}()
if err := initChrome(ctx, p, te); err != nil {
return nil, errors.Wrap(err, "failed to connect to Chrome")
}
var err error
if p.UseARC {
if p.ExistingARC != nil {
te.arc = p.ExistingARC
} else if te.arc, err = arc.New(ctx, outDir); err != nil {
return nil, errors.Wrap(err, "failed to start ARC")
}
}
if te.tconn, err = te.cr.TestAPIConn(ctx); err != nil {
return nil, errors.Wrap(err, "creating test API connection failed")
}
toClose = nil
return te, nil
}
func startVM(ctx context.Context, te *TestEnv) error {
if te.vm {
return nil
}
testing.ContextLog(ctx, "Waiting for crostini to install (typically ~ 3 mins) and mount sshfs")
if err := te.tconn.Call(ctx, nil, `tast.promisify(chrome.autotestPrivate.runCrostiniInstaller)`); err != nil {
return errors.Wrap(err, "autotestPrivate.runCrostiniInstaller failed")
}
te.vm = true
return nil
}
// runTask runs a MemoryTask.
func runTask(ctx, taskCtx context.Context, task MemoryTask, te *TestEnv) error {
taskMeter := kernelmeter.New(ctx)
defer taskMeter.Close(ctx)
if task.NeedVM() {
if err := startVM(ctx, te); err != nil {
return errors.Wrap(err, "failed to start VM")
}
}
if err := task.Run(taskCtx, te); err != nil {
return errors.Wrapf(err, "failed to run memory task %s", task.String())
}
resetAndLogStats(ctx, taskMeter, task.String())
return nil
}
// RunParameters contains the configurable parameters for RunTest.
type RunParameters struct {
// WPRMode is the mode to start WPR.
WPRMode wpr.Mode
// WPRArchivePath is the full path to an archive for WPR. If set, WPR is used
// and Chrome sends its traffic through WPR. Otherwise, Chrome uses live
// sites.
WPRArchivePath string
// UseARC indicates whether Chrome should be started with ARC enabled.
UseARC bool
// ParallelTasks indicates whether the memory tasks should be run in parallel
ParallelTasks bool
// ExistingChrome indicates that we should use this Chrome instance instead
// of creating a new one.
ExistingChrome *chrome.Chrome
// ExistingARC indicates that we should use this ARC instance instead of
// creating a new one. ExistingChrome and UseARC must be set.
ExistingARC *arc.ARC
// ExistingPerfValues indicates that we should use this perf.Values instead
// of creating a new one. The caller is responsible calling
// perf.Values.Save().
ExistingPerfValues *perf.Values
}
// Close closes the Chrome, ARC, and WPR instances used in the TestEnv.
func (te *TestEnv) Close(ctx context.Context, p *RunParameters) {
if te.vm {
if err := te.tconn.Call(ctx, nil, `tast.promisify(chrome.autotestPrivate.runCrostiniUninstaller)`); err != nil {
testing.ContextLog(ctx, "Running autotestPrivate.runCrostiniInstaller failed: ", err)
}
}
if te.arc != nil && p.ExistingARC == nil {
te.arc.Close(ctx)
te.arc = nil
}
if te.cr != nil && p.ExistingChrome == nil {
te.cr.Close(ctx)
te.cr = nil
}
if te.wpr != nil {
te.wpr.Close(ctx)
te.wpr = nil
}
}
// RunTest creates a new TestEnv and then runs ARC, Chrome, and VM tasks in parallel.
// It also logs memory and cpu usage throughout the test, and copies output from /var/log/memd and /var/log/vmlog
// when finished.
// All passed-in tasks will be closed automatically.
func RunTest(ctx context.Context, outDir string, tasks []MemoryTask, p *RunParameters) (errRet error) {
if p == nil {
p = &RunParameters{}
}
testEnv, err := newTestEnv(ctx, outDir, p)
if err != nil {
return errors.Wrap(err, "failed creating the test environment")
}
defer testEnv.Close(ctx, p)
if err = prepareMemdLogging(ctx); err != nil {
return errors.Wrap(err, "failed to prepare memd logging")
}
go logCmd(ctx, filepath.Join(outDir, "memory_use.txt"), "cat", "/proc/meminfo")
go logCmd(ctx, filepath.Join(outDir, "cpu_use.txt"), "iostat", "-c")
testMeter := kernelmeter.New(ctx)
defer testMeter.Close(ctx)
taskCtx, taskCancel := ctxutil.Shorten(ctx, 5*time.Second)
defer taskCancel()
if p.ParallelTasks {
ch := make(chan struct{}, len(tasks))
for _, task := range tasks {
go func(task MemoryTask) {
defer func() {
task.Close(ctx, testEnv)
ch <- struct{}{}
}()
err = runTask(ctx, taskCtx, task, testEnv)
if err != nil {
testing.ContextLog(ctx, "Failed to run task: ", err)
if errRet == nil {
errRet = errors.Wrap(err, "failed to run task")
}
}
}(task)
}
for i := 0; i < len(tasks); i++ {
select {
case <-ctx.Done():
return errors.Wrap(ctx.Err(), "tasks didn't complete")
case <-ch:
}
}
} else {
for _, task := range tasks {
err = runTask(ctx, taskCtx, task, testEnv)
if err != nil {
return errors.Wrap(err, "failed to run task")
}
}
}
const vmlog = "/var/log/vmlog/vmlog.LATEST"
if err := fsutil.CopyFile(vmlog, filepath.Join(outDir, filepath.Base(vmlog))); err != nil {
return errors.Wrapf(err, "failed to copy %v", vmlog)
}
if err = copyMemdLogs(outDir); err != nil {
return errors.Wrap(err, "failed to get memd files")
}
setPerfValues(testMeter, testEnv.p, "full_test")
resetAndLogStats(ctx, testMeter, "full test")
if p.ExistingPerfValues == nil {
if err = testEnv.p.Save(outDir); err != nil {
return errors.Wrap(err, "cannot save perf data")
}
}
// NB: errRet can be set by goroutines above, so don't override it if they
// had an error. Those errors are also logged, so if we have an early return
// because of another error, they should still be diagnosable.
return errRet
}