diff --git a/virtcontainers/clh.go b/virtcontainers/clh.go index b3c3d20e04..07bd97c2b3 100644 --- a/virtcontainers/clh.go +++ b/virtcontainers/clh.go @@ -6,10 +6,10 @@ package virtcontainers import ( - "bytes" "context" "encoding/json" "fmt" + "io/ioutil" "net" "net/http" "os" @@ -61,7 +61,6 @@ const ( clhAPISocket = "clh-api.sock" clhLogFile = "clh.log" virtioFsSocket = "virtiofsd.sock" - clhSerial = "serial-tty.log" supportedMajorVersion = 0 supportedMinorVersion = 5 defaultClhPath = "/usr/local/bin/cloud-hypervisor" @@ -120,7 +119,6 @@ type cloudHypervisor struct { APIClient clhClient version CloudHypervisorVersion vmconfig chclient.VmConfig - cmdOutput bytes.Buffer virtiofsd Virtiofsd store persistapi.PersistDriver } @@ -290,13 +288,8 @@ func (clh *cloudHypervisor) createSandbox(ctx context.Context, id string, networ // set the serial console to the cloud hypervisor if clh.config.Debug { - serialPath, err := clh.serialPath(clh.id) - if err != nil { - return err - } clh.vmconfig.Serial = chclient.ConsoleConfig{ - Mode: cctFILE, - File: serialPath, + Mode: cctTTY, } } else { @@ -372,17 +365,12 @@ func (clh *cloudHypervisor) startSandbox(timeout int) error { var strErr string strErr, pid, err := clh.LaunchClh() if err != nil { - return fmt.Errorf("failed to launch cloud-hypervisor: %s, error messages from log: %s", err, strErr) - } - clh.state.PID = pid - - if err := clh.waitVMM(clhTimeout); err != nil { - clh.Logger().WithField("error", err).WithField("output", clh.cmdOutput.String()).Warn("cloud-hypervisor init failed") if shutdownErr := clh.virtiofsd.Stop(); shutdownErr != nil { clh.Logger().WithField("error", shutdownErr).Warn("error shutting down Virtiofsd") } - return err + return fmt.Errorf("failed to launch cloud-hypervisor: '%s', hypervisor output:\n%s", err, strErr) } + clh.state.PID = pid if err := clh.bootVM(ctx); err != nil { return err @@ -775,18 +763,10 @@ func (clh *cloudHypervisor) vsockSocketPath(id string) (string, error) { return utils.BuildSocketPath(clh.store.RunVMStoragePath(), id, clhSocket) } -func (clh *cloudHypervisor) serialPath(id string) (string, error) { - return utils.BuildSocketPath(clh.store.RunVMStoragePath(), id, clhSerial) -} - func (clh *cloudHypervisor) apiSocketPath(id string) (string, error) { return utils.BuildSocketPath(clh.store.RunVMStoragePath(), id, clhAPISocket) } -func (clh *cloudHypervisor) logFilePath(id string) (string, error) { - return utils.BuildSocketPath(clh.store.RunVMStoragePath(), id, clhLogFile) -} - func (clh *cloudHypervisor) waitVMM(timeout uint) error { clhRunning, err := clh.isClhRunning(timeout) @@ -877,8 +857,6 @@ func (clh *cloudHypervisor) getAvailableVersion() error { func (clh *cloudHypervisor) LaunchClh() (string, int, error) { - errStr := "" - clhPath, err := clh.clhPath() if err != nil { return "", -1, err @@ -886,36 +864,54 @@ func (clh *cloudHypervisor) LaunchClh() (string, int, error) { args := []string{cscAPIsocket, clh.state.apiSocket} if clh.config.Debug { - - logfile, err := clh.logFilePath(clh.id) - if err != nil { - return "", -1, err - } - args = append(args, cscLogFile) - args = append(args, logfile) + args = append(args, "-vvv") } clh.Logger().WithField("path", clhPath).Info() clh.Logger().WithField("args", strings.Join(args, " ")).Info() - cmd := exec.Command(clhPath, args...) - cmd.Stdout = &clh.cmdOutput - cmd.Stderr = &clh.cmdOutput + cmdHypervisor := exec.Command(clhPath, args...) if clh.config.Debug { - cmd.Env = os.Environ() - cmd.Env = append(cmd.Env, "RUST_BACKTRACE=full") + cmdHypervisor.Env = os.Environ() + cmdHypervisor.Env = append(cmdHypervisor.Env, "RUST_BACKTRACE=full") + } + + hypervisoOutput, err := cmdHypervisor.StdoutPipe() + if err != nil { + return "", -1, err } + cmdHypervisor.Stderr = cmdHypervisor.Stdout - if err := utils.StartCmd(cmd); err != nil { - fmt.Println("Error starting cloudHypervisor", err) - if cmd.Process != nil { - cmd.Process.Kill() + err = utils.StartCmd(cmdHypervisor) + if err != nil { + return "Failed to start hypervisor", 0, errors.Errorf("Failed to start hypervisor: %s", err) + } + + if err := clh.waitVMM(clhTimeout); err != nil { + clh.Logger().WithField("error", err).Warn("cloud-hypervisor init failed") + var output string + + b, errRead := ioutil.ReadAll(hypervisoOutput) + if errRead != nil { + output = "failed to read hypervisor output to get error information" + } else { + output = string(b) + } + + return output, -1, err + } + + if clh.config.Debug { + cmdLogger := utils.NewProgramLogger("kata-hypervisor") + clh.Logger().Debugf("Starting process logger(%s) for hypervisor", cmdLogger) + if err := cmdLogger.StartLogger(hypervisoOutput); err != nil { + // Not critical to run a container, but output wont be logged + clh.Logger().Warnf("Failed start process logger(%s) %s", cmdLogger, err) } - return errStr, 0, err } - return errStr, cmd.Process.Pid, nil + return "", cmdHypervisor.Process.Pid, nil } //########################################################################### @@ -928,11 +924,11 @@ const ( cctOFF string = "Off" cctFILE string = "File" cctNULL string = "Null" + cctTTY string = "Tty" ) const ( cscAPIsocket string = "--api-socket" - cscLogFile string = "--log-file" ) //**************************************** diff --git a/virtcontainers/utils/utils.go b/virtcontainers/utils/utils.go index 85c554896a..b4e105f345 100644 --- a/virtcontainers/utils/utils.go +++ b/virtcontainers/utils/utils.go @@ -9,6 +9,7 @@ import ( "crypto/rand" "errors" "fmt" + "io" "os" "os/exec" "path/filepath" @@ -275,3 +276,23 @@ const ( MiB = KiB << 10 GiB = MiB << 10 ) + +// Binary to use to log program output +const LoggerBinryName = "systemd-cat" + +type ProgramLogger struct { + cmd *exec.Cmd +} + +func NewProgramLogger(loggerLabel string) ProgramLogger { + return ProgramLogger{cmd: exec.Command(LoggerBinryName, "-t", loggerLabel)} +} + +func (p *ProgramLogger) StartLogger(output io.ReadCloser) error { + p.cmd.Stdin = output + return StartCmd(p.cmd) +} + +func (p ProgramLogger) String() string { + return p.cmd.Path +}