src/go.chromium.org/tast-tests/cros/remote/bundles/cros/intel/dark_resume_functionality_with_timeout.go

// Copyright 2022 The ChromiumOS Authors
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

package intel

import (
	"context"
	"fmt"
	"regexp"
	"strings"
	"time"

	"go.chromium.org/tast-tests/cros/common/servo"
	"go.chromium.org/tast-tests/cros/remote/firmware"
	"go.chromium.org/tast-tests/cros/remote/firmware/fixture"
	"go.chromium.org/tast-tests/cros/remote/firmware/reporters"
	"go.chromium.org/tast-tests/cros/remote/powercontrol"
	"go.chromium.org/tast/core/ctxutil"
	"go.chromium.org/tast/core/dut"
	"go.chromium.org/tast/core/errors"
	"go.chromium.org/tast/core/ssh"
	"go.chromium.org/tast/core/ssh/linuxssh"
	"go.chromium.org/tast/core/testing"
	"go.chromium.org/tast/core/testing/hwdep"
)

func init() {
	testing.AddTest(&testing.Test{
		Func:         DarkResumeFunctionalityWithTimeout,
		LacrosStatus: testing.LacrosVariantUnneeded,
		Desc:         "Verifies dark resume feature functionality with wakeup-timeout parameter",
		Contacts:     []string{"intel.chrome.automation.team@intel.com", "ambalavanan.m.m@intel.com"},
		BugComponent: "b:157291",
		SoftwareDeps: []string{"chrome", "reboot"},
		ServiceDeps:  []string{"tast.cros.security.BootLockboxService"},
		Attr:         []string{"group:intel-sleep"},
		Vars:         []string{"servo"},
		HardwareDeps: hwdep.D(hwdep.X86(), hwdep.ChromeEC()),
		Fixture:      fixture.NormalMode,
		Timeout:      15 * time.Minute,
	})
}

func DarkResumeFunctionalityWithTimeout(ctx context.Context, s *testing.State) {
	cleanupCtx := ctx
	ctx, cancel := ctxutil.Shorten(ctx, 3*time.Minute)
	defer cancel()

	const (
		enableDarkResumeCommand  = "echo 0 > /var/lib/power_manager/disable_dark_resume"
		disableDarkResumeCommand = "echo 1 > /var/lib/power_manager/disable_dark_resume"
		restartPowerdCommand     = "restart powerd"
	)

	dut := s.DUT()

	firmwareHelper := s.FixtValue().(*fixture.Value).Helper
	if err := firmwareHelper.RequireServo(ctx); err != nil {
		s.Fatal("Failed to connect to servo: ", err)
	}

	eventReporter := firmwareHelper.Reporter
	if err := eventReporter.ClearEventlog(ctx); err != nil {
		s.Fatal("Failed to clear event log: ", err)
	}

	cmdRun := func(cmd string) {
		if err := dut.Conn().CommandContext(ctx, "bash", "-c", cmd).Run(); err != nil {
			s.Fatalf("Failed to execute %s command: %v", cmd, err)
		}
	}

	// This Coldboot is required to get uniform results and remove any flakiness.
	if err := powercontrol.PerformColdboot(ctx, dut, firmwareHelper.ServoProxy); err != nil {
		s.Fatal("Failed to perform coldboot: ", err)
	}

	// Performing chrome login.
	if err := powercontrol.ChromeOSLogin(ctx, dut, s.RPCHint()); err != nil {
		s.Fatal("Failed to login to chrome: ", err)
	}

	defer func(ctx context.Context) {
		if !dut.Connected(ctx) {
			if err := powercontrol.PowerOntoDUT(ctx, firmwareHelper.ServoProxy, dut); err != nil {
				s.Fatal("Failed to power-on DUT at cleanup: ", err)
			}
		}
		if err := dut.Conn().CommandContext(ctx, "sh", "-c", "umount /var/lib/power_manager && restart powerd").Run(ssh.DumpLogOnError); err != nil {
			s.Log("Failed to restore powerd settings: ", err)
		}
		cmdRun(disableDarkResumeCommand)
		cmdRun(restartPowerdCommand)
	}(cleanupCtx)

	s.Log("Overriding system suspend_to_idle setting. THIS WILL BREAK SUSPEND ON HALF OF DEVICES. FIX THIS TEST")
	if err := dut.Conn().CommandContext(ctx, "sh", "-c", fmt.Sprintf(
		"mkdir -p /tmp/power_manager && "+
			"echo 1 > /tmp/power_manager/suspend_to_idle && "+
			"mount --bind /tmp/power_manager /var/lib/power_manager && "+
			"restart powerd"),
	).Run(ssh.DumpLogOnError); err != nil {
		s.Fatal("Failed to set suspend to idle: ", err)
	}

	const expectedConfigValue = 0
	if err := powercontrol.VerifyPowerdConfigSuspendValue(ctx, dut, expectedConfigValue); err != nil {
		s.Fatal("Failed to verfiy power config value for S0ix: ", err)
	}

	cmdRun(enableDarkResumeCommand)
	cmdRun(restartPowerdCommand)

	darkResumeEnabledString := "Dark resume enabled"
	if err := verifyDarkResumeStatus(ctx, dut, darkResumeEnabledString); err != nil {
		s.Fatal("Failed to check dark resume enabled status before suspend: ", err)
	}

	isPowerPress := true
	// Perform dark resume suspend with servo ENTER key as wake source.
	if err := performDarkResumeSuspend(ctx, firmwareHelper, dut, !isPowerPress); err != nil {
		s.Fatal("Failed to perform dark resume suspend with ENTER key as wake source: ", err)
	}

	events, err := eventReporter.EventlogList(ctx)
	if err != nil {
		s.Fatal("Failed gathering events: ", err)
	}

	// requiredECEvents is expected list of EC events after suspend-resume.
	var requiredECEventsKeyPress = []string{"S0ix Enter",
		"S0ix Exit",
		`EC Event . Key Pressed|Wake Source . GPE`,
	}

	foundRequiredEvents := true
	if err := verifyElogToolList(ctx, requiredECEventsKeyPress, foundRequiredEvents, events); err != nil {
		s.Fatal("Failed to verify EC events of key press: ", err)
	}

	// Perform dark resume suspend with servo power button as wake source.
	if err := performDarkResumeSuspend(ctx, firmwareHelper, dut, isPowerPress); err != nil {
		s.Fatal("Failed to perform dark resume suspend with power button as wake source: ", err)
	}

	events, err = eventReporter.EventlogList(ctx)
	if err != nil {
		s.Fatal("Failed gathering events: ", err)
	}

	var requiredECEventsPowerButton = []string{"S0ix Enter",
		"S0ix Exit",
		`EC Event . Power Button|Wake Source . GPE`,
	}

	foundRequiredEvents = true
	if err := verifyElogToolList(ctx, requiredECEventsPowerButton, foundRequiredEvents, events); err != nil {
		s.Fatal("Failed to verify EC events of key press: ", err)
	}
}

// verifyDarkResumeStatus verifies dark resume status with provided matchString.
func verifyDarkResumeStatus(ctx context.Context, dut *dut.DUT, matchString string) error {
	const darkResumeStatusFile = "/var/log/power_manager/powerd.LATEST"
	return testing.Poll(ctx, func(ctx context.Context) error {
		out, err := linuxssh.ReadFile(ctx, dut.Conn(), darkResumeStatusFile)
		if err != nil {
			return errors.Wrap(err, "failed to execute dark resume status check command")
		}
		if !strings.Contains(string(out), matchString) {
			return errors.Errorf("failed to check for %q match in %q output", matchString, string(out))
		}
		return nil
	}, &testing.PollOptions{Timeout: 10 * time.Second})
}

// eventMessageContainsMatch verifies whether event log contains matching eventlog.
func eventMessageContainsMatch(ctx context.Context, events []reporters.Event, re *regexp.Regexp) bool {
	for _, event := range events {
		if re.MatchString(event.Message) {
			return true
		}
	}
	return false
}

// performDarkResumeSuspend perform powerd_dbus_suspend with disable_dark_resume and suspend_for_sec parameter.
// Checks and compare SLP and C10 package values before and after suspend.
// Wakes DUT with ENTER key/power button press via servo.
func performDarkResumeSuspend(ctx context.Context, firmwareHelper *firmware.Helper, dut *dut.DUT, isPowerPress bool) error {
	slpOpSetPre, pkgOpSetPre, err := powercontrol.SlpAndC10PackageValues(ctx, dut)
	if err != nil {
		return errors.Wrap(err, "failed to get SLP counter and C10 package values before suspend-resume")
	}

	testing.ContextLog(ctx, "Suspend DUT with dark resume command")
	cmd := dut.Conn().CommandContext(ctx, "powerd_dbus_suspend", "--disable_dark_resume=false", "--suspend_for_sec=10")
	if err := cmd.Start(); err != nil {
		return errors.Wrap(err, "failed to execute dark resume command")
	}
	cmd.Wait()

	sdCtx, cancel := context.WithTimeout(ctx, 40*time.Second)
	defer cancel()
	if err := dut.WaitUnreachable(sdCtx); err != nil {
		return errors.Wrap(err, "failed to wait DUT to become unreachable")
	}

	if err := powercontrol.WaitForSuspendState(ctx, firmwareHelper); err != nil {
		return errors.Wrap(err, "failed to verify EC power state after suspend")
	}

	if !isPowerPress {
		// Press on ENTER key via servo and wake DUT.
		testing.ContextLog(ctx, "Waking DUT with ENTER key press via servo")
		if err := wakeDUTWithEnterKeyPress(ctx, firmwareHelper, dut); err != nil {
			return errors.Wrap(err, "failed to press ENTER to wake DUT")
		}
	} else {
		// Press on power button via servo and wake DUT.
		testing.ContextLog(ctx, "Waking DUT with power button press via servo")
		if err := powercontrol.PowerOntoDUT(ctx, firmwareHelper.ServoProxy, dut); err != nil {
			return errors.Wrap(err, "failed to press power button to wake DUT")
		}
	}

	wtCtx, cancel := context.WithTimeout(ctx, 60*time.Second)
	defer cancel()
	if err := dut.WaitConnect(wtCtx); err != nil {
		return errors.Wrap(err, "failed to wait DUT to connect")
	}

	slpOpSetPost, pkgOpSetPost, err := powercontrol.SlpAndC10PackageValues(ctx, dut)
	if err != nil {
		return errors.Wrap(err, "failed to get SLP counter and C10 package values after suspend-resume")
	}

	if slpOpSetPre == slpOpSetPost {
		return errors.Errorf("failed: SLP counter value %q should be different from the one before suspend %q", slpOpSetPost, slpOpSetPre)
	}

	if slpOpSetPost == 0 {
		return errors.Errorf("failed SLP counter value must be non-zero, got: %q", slpOpSetPost)
	}

	if pkgOpSetPre == pkgOpSetPost {
		return errors.Errorf("failed: Package C10 value %q must be different from the one before suspend %q", pkgOpSetPost, pkgOpSetPre)
	}

	if pkgOpSetPost == "0x0" || pkgOpSetPost == "0" {
		return errors.New("Failed: Package C10 should be non-zero")
	}

	inDarkResumeString := "In dark resume"
	if err := verifyDarkResumeStatus(ctx, dut, inDarkResumeString); err != nil {
		return errors.Wrap(err, "failed to check dark resume enabled status after suspend")
	}
	return nil
}

// wakeDUTWithEnterKeyPress performs power normal press to wake DUT.
func wakeDUTWithEnterKeyPress(ctx context.Context, firmwareHelper *firmware.Helper, dut *dut.DUT) error {
	return testing.Poll(ctx, func(ctx context.Context) error {
		if err := firmwareHelper.Servo.KeypressWithDuration(ctx, servo.Enter, servo.DurPress); err != nil {
			return errors.Wrap(err, "failed to press ENTER to wake DUT")
		}
		waitCtx, cancel := context.WithTimeout(ctx, 30*time.Second)
		defer cancel()
		if err := dut.WaitConnect(waitCtx); err != nil {
			return errors.Wrap(err, "failed to wait connect DUT")
		}
		return nil
	}, &testing.PollOptions{Timeout: 2 * time.Minute})
}

func verifyElogToolList(ctx context.Context, ecEvents []string, foundRequiredEvents bool, events []reporters.Event) error {
	for _, requiredEvent := range ecEvents {
		reRequiredEvent := regexp.MustCompile(requiredEvent)
		if !eventMessageContainsMatch(ctx, events, reRequiredEvent) {
			foundRequiredEvents = false
			return errors.Errorf("unexpected events: want %q, got %q", ecEvents, events)
		}
	}
	if !foundRequiredEvents {
		return errors.New("failed as required event missing")
	}
	return nil
}