add console log to debug output

Author: prezha

pkg/drivers/kvm/domain.go

@@ -70,7 +70,14 @@ func closeDomain(dom *libvirt.Domain, conn *libvirt.Connect) error {
 func (d *Driver) defineDomain() (*libvirt.Domain, error) {
 	tmpl := template.Must(template.New("domain").Parse(domainTmpl))
 	var domainXML bytes.Buffer
-	if err := tmpl.Execute(&domainXML, d); err != nil {
+	dlog := struct {
+		Driver
+		ConsoleLogPath string
+	}{
+		Driver:         *d,
+		ConsoleLogPath: consoleLogPath(*d),
+	}
+	if err := tmpl.Execute(&domainXML, dlog); err != nil {
 		return nil, errors.Wrap(err, "executing domain xml")
 	}
 	conn, err := getConnection(d.ConnectionURI)

pkg/drivers/kvm/domain_definition_x86.go

@@ -55,6 +55,7 @@ const domainTmpl = `
       <source file='{{.DiskPath}}'/>
       <target dev='hda' bus='virtio'/>
     </disk>
+    <controller type='virtio-serial'/>
     <interface type='network'>
       <source network='{{.PrivateNetwork}}'/>
       <model type='virtio'/>
@@ -65,10 +66,14 @@ const domainTmpl = `
     </interface>
     <serial type='pty'>
       <target port='0'/>
+      <log file='{{.ConsoleLogPath}}' append='on'/>
     </serial>
     <console type='pty'>
       <target type='serial' port='0'/>
     </console>
+    <console type='pty'>
+      <target type="virtio" port="1"/>
+    </console>
     <rng model='virtio'>
       <backend model='random'>/dev/random</backend>
     </rng>

pkg/drivers/kvm/kvm.go

@@ -314,18 +314,36 @@ func (d *Driver) Start() error {
 		log.Debugf("starting domain XML:\n%s", domXML)
 	}
 
+	// libvirt/qemu creates a console log file owned by root:root and permissions 0600,
+	// so we pre-create it (and close it immediately), just to be able to read it later
+	logPath := consoleLogPath(*d)
+	f, err := os.Create(logPath)
+	if err != nil {
+		log.Debugf("failed to create console log file %q: %v", logPath, err)
+	} else {
+		f.Close()
+	}
+	// ensure console log file is cleaned up
+	defer func() {
+		if _, err := os.Stat(logPath); err == nil {
+			if err := os.Remove(logPath); err != nil {
+				log.Debugf("failed removing console log file %q: %v", logPath, err)
+			}
+		}
+	}()
+
 	if err := dom.Create(); err != nil {
 		return errors.Wrap(err, "creating domain")
 	}
 
 	log.Info("waiting for domain to start...")
-	if err := d.waitForDomainState(state.Running, 1*time.Minute); err != nil {
+	if err := d.waitForDomainState(state.Running, 30*time.Second); err != nil {
 		return errors.Wrap(err, "waiting for domain to start")
 	}
 	log.Info("domain is now running")
 
 	log.Info("waiting for IP...")
-	if err := d.waitForStaticIP(conn, 2*time.Minute); err != nil {
+	if err := d.waitForStaticIP(conn, 90*time.Second); err != nil {
 		return errors.Wrap(err, "waiting for IP")
 	}
 
@@ -337,6 +355,12 @@ func (d *Driver) Start() error {
 	return nil
 }
 
+// consoleLogPath returns the path to the console log file for the given machine name.
+func consoleLogPath(d Driver) string {
+	// return fmt.Sprintf("%s-console.log", machineName)
+	return d.ResolveStorePath("console.log")
+}
+
 // waitForDomainState waits maxTime for the domain to reach a target state.
 func (d *Driver) waitForDomainState(targetState state.State, maxTime time.Duration) error {
 	query := func() error {
@@ -353,11 +377,27 @@ func (d *Driver) waitForDomainState(targetState state.State, maxTime time.Durati
 		return fmt.Errorf("last domain state: %q", currentState.String())
 	}
 	if err := retry.Local(query, maxTime); err != nil {
+		dumpConsoleLogs(consoleLogPath(*d))
 		return fmt.Errorf("timed out waiting %v for domain to reach %q state: %w", maxTime, targetState.String(), err)
 	}
 	return nil
 }
 
+// dumpConsoleLogs prints out the console log.
+func dumpConsoleLogs(logPath string) {
+	if _, err := os.Stat(logPath); err != nil {
+		log.Debugf("failed checking console log file %q: %v", logPath, err)
+		return
+	}
+
+	data, err := os.ReadFile(logPath)
+	if err != nil {
+		log.Debugf("failed dumping console log file %q: %v", logPath, err)
+		return
+	}
+	log.Debugf("console log:\n%s", data)
+}
+
 // waitForStaticIP waits for IP address of domain that has been created & starting and then makes that IP static.
 func (d *Driver) waitForStaticIP(conn *libvirt.Connect, maxTime time.Duration) error {
 	query := func() error {
@@ -376,6 +416,7 @@ func (d *Driver) waitForStaticIP(conn *libvirt.Connect, maxTime time.Duration) e
 		return nil
 	}
 	if err := retry.Local(query, maxTime); err != nil {
+		dumpConsoleLogs(consoleLogPath(*d))
 		return fmt.Errorf("domain %s didn't return IP after %v", d.MachineName, maxTime)
 	}