blob: 774f47bd009cea4f6b221ebfb9cac51f018abf50 [file] [log] [blame]
// 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 crostini
import (
"bytes"
"context"
"fmt"
"io"
"io/ioutil"
"os"
"path/filepath"
"time"
"chromiumos/tast/local/cryptohome"
"chromiumos/tast/local/syslog"
"chromiumos/tast/local/vm"
"chromiumos/tast/testing"
)
// RunCrostiniPostTest runs hooks that should run after every test but before
// the precondition closes (if it's going to) e.g. collecting logs from the
// container.
func RunCrostiniPostTest(ctx context.Context, p PreData) {
dir, ok := testing.ContextOutDir(ctx)
if !ok || dir == "" {
testing.ContextLog(ctx, "Failed to get name of directory")
return
}
// If we haven't connected to chrome successfully, then the
// test didn't get to do anything with the VM that could
// possibly have generated logs, and even if it did we
// couldn't access them, so bail out here.
if p.Chrome == nil {
testing.ContextLog(ctx, "Failed before connecting to chrome, no logs generated")
return
}
// Container logs require a running VM and container. If one
// hasn't been set, we can't fetch them.
if p.Container != nil {
trySaveContainerLogs(ctx, dir, p.Container)
if err := p.Container.Cleanup(ctx, "."); err != nil {
testing.ContextLog(ctx, "Failed to remove all files in home directory in the container: ", err)
}
} else {
testing.ContextLog(ctx, "No active container, can't get journalctl logs")
}
// LXC logs only require a running VM, so even if the
// container hasn't been set we can try to get a running VM
// and use that.
var machine *vm.VM
if p.Container != nil {
machine = p.Container.VM
} else {
machine2, err := vm.GetRunningVM(ctx, p.Chrome.NormalizedUser())
machine = machine2
if err != nil {
testing.ContextLog(ctx, "Failed to get running VM, won't get LXC logs: ", err)
}
}
if machine != nil {
writeLXCLogs(ctx, dir, machine)
}
// VM logs are stored on the host, so we don't need the VM to
// be running at all to get them.
trySaveVMLogs(ctx, dir, p.Chrome.NormalizedUser())
}
// When we run trySaveContainerLogs we only want to capture logs since we last
// ran i.e. from the test that just finished, not all logs since the start of
// the suite. Sadly, Debian's journalctl in stable is too old to support cursor
// files, so we have to parse a cursor out of the log stream and remember it
// between calls to trySaveContainerLogs.
var cursor string
// trySaveContainerLogs fetches new (i.e. since last time the function
// successfully ran) logs from the container and writes them to
// crostini_journalctl.txt
func trySaveContainerLogs(ctx context.Context, dir string, cont *vm.Container) {
if cont == nil {
testing.ContextLog(ctx, "No active container")
return
}
args := []string{"sudo", "journalctl", "--no-pager", "--show-cursor"}
if cursor != "" {
args = append(args, "--cursor")
args = append(args, cursor)
}
cmd := cont.Command(ctx, args...)
output, err := cmd.Output()
if err != nil {
testing.ContextLog(ctx, "Error running journalctl: ", err)
return
}
path := filepath.Join(dir, "crostini_journalctl.txt")
err = ioutil.WriteFile(path, output, 0644)
if err != nil {
testing.ContextLog(ctx, "Error writing journalctl to log: ", err)
return
}
cursorMarker := []byte("-- cursor: ")
pos := bytes.LastIndex(output, cursorMarker)
if pos == -1 {
testing.ContextLog(ctx, "No journalctl cursor found")
return
}
cursor = string(output[pos+len(cursorMarker):])
}
// Persistent reader for VM logs, keeps track of where it was up to.
// Internally it closes the old file and opens the new as logs get rotated, we
// never explicitly close it.
var logReader *syslog.LineReader
func newLogReader(ctx context.Context, user string) (*syslog.LineReader, error) {
ownerID, err := cryptohome.UserHash(ctx, user)
if err != nil {
return nil, err
}
path := "/run/daemon-store/crosvm/" + ownerID + "/log/" + vm.GetEncodedName(vm.DefaultVMName) + ".log"
// Only wait 1 second for the log file to exist, don't want to hang until
// timeout if it doesn't exist, instead we continue.
return syslog.NewLineReader(ctx, path, true,
&testing.PollOptions{Timeout: 1 * time.Second})
}
// trySaveVMLogs writes logs since the last call to the
// current test's output folder.
func trySaveVMLogs(ctx context.Context, dir, user string) {
if logReader == nil {
var err error
logReader, err = newLogReader(ctx, user)
if err != nil {
testing.ContextLog(ctx, "Error creating log reader: ", err)
return
}
}
path := filepath.Join(dir, "termina_logs.txt")
f, err := os.Create(path)
if err != nil {
testing.ContextLog(ctx, "Error creating file: ", err)
return
}
defer f.Close()
for {
line, err := logReader.ReadLine()
if err != nil {
if err != io.EOF {
testing.ContextLog(ctx, "Error reading file: ", err)
}
break
}
_, err = f.WriteString(line)
if err != nil {
testing.ContextLog(ctx, fmt.Sprintf("Error writing %s to file: ", line), err)
}
}
}
func writeLXCLogs(ctx context.Context, dir string, machine *vm.VM) {
testing.ContextLog(ctx, "Creating file")
path := filepath.Join(dir, "crostini_logs.txt")
f, err := os.Create(path)
if err != nil {
testing.ContextLog(ctx, "Error creating file: ", err)
return
}
defer f.Close()
f.WriteString("lxc info and lxc.log:\n")
cmd := machine.Command(ctx, "sh", "-c", "LXD_DIR=/mnt/stateful/lxd LXD_CONF=/mnt/stateful/lxd_conf lxc info penguin --show-log")
cmd.Stdout = f
cmd.Stderr = f
err = cmd.Run()
if err != nil {
testing.ContextLog(ctx, "Error getting lxc logs: ", err)
}
f.WriteString("\n\nconsole.log:\n")
cmd = machine.Command(ctx, "sh", "-c", "LXD_DIR=/mnt/stateful/lxd LXD_CONF=/mnt/stateful/lxd_conf lxc console penguin --show-log")
cmd.Stdout = f
cmd.Stderr = f
err = cmd.Run()
if err != nil {
testing.ContextLog(ctx, "Error getting boot logs: ", err)
}
}