[pve-devel] [PATCH qemu-server] fix #4549: capture and bubble up qemu errors correctly

[Christoph Heiss <c.heiss@proxmox.com>]

See [0]. The issue is that currently, all messages from qemu get
directly sent to stdout by run_command(). In turn, this output was
missing from mail notifications.

Fix this by unifying it with the migration logging, properly capturing
the output and including it in the error message, which then gets
further passed on. Also has the benefit that messages from qemu are now
prefixed with 'QEMU: ' in all cases, making it more uniform.

As for phase2_start_local_cluster(), this now gets caught by the
`errfunc`, thus the special handling can be removed.

For `vzdump`, testing was done by manually setting a non-existent bridge
on a network interface. For (live-)migration, a bridge was created which
exists on the source node but not on the target. Both cases trigger an
qemu error when it tries to start up, very similarly to the bug report.

[0] https://bugzilla.proxmox.com/show_bug.cgi?id=4549

Signed-off-by: Christoph Heiss <c.heiss@proxmox.com>
---
 PVE/QemuMigrate.pm |  2 --
 PVE/QemuServer.pm  | 16 ++++++++--------
 2 files changed, 8 insertions(+), 10 deletions(-)

diff --git a/PVE/QemuMigrate.pm b/PVE/QemuMigrate.pm
index 09cc1d8..b1c28b3 100644
--- a/PVE/QemuMigrate.pm
+++ b/PVE/QemuMigrate.pm
@@ -998,8 +998,6 @@ sub phase2_start_local_cluster {
 	    my $drive = $1;
 	    my $volid = $2;
 	    $target_replicated_volumes->{$volid} = $drive;
-	} elsif ($line =~ m/^QEMU: (.*)$/) {
-	    $self->log('info', "[$self->{node}] $1\n");
 	}
     }, errfunc => sub {
 	my $line = shift;
diff --git a/PVE/QemuServer.pm b/PVE/QemuServer.pm
index c1d0fd2..8375b2a 100644
--- a/PVE/QemuServer.pm
+++ b/PVE/QemuServer.pm
@@ -5885,15 +5885,9 @@ sub vm_start_nolock {
 	timeout => $statefile ? undef : $start_timeout,
 	umask => 0077,
 	noerr => 1,
+	quiet => 1,
     );
 
-    # when migrating, prefix QEMU output so other side can pick up any
-    # errors that might occur and show the user
-    if ($migratedfrom) {
-	$run_params{quiet} = 1;
-	$run_params{logfunc} = sub { print "QEMU: $_[0]\n" };
-    }
-
     my %systemd_properties = (
 	Slice => 'qemu.slice',
 	KillMode => 'process',
@@ -5922,13 +5916,19 @@ sub vm_start_nolock {
 		$tpmpid = start_swtpm($storecfg, $vmid, $tpm, $migratedfrom);
 	    }
 
+	    # '\r\n' needs to be used as a line separator here, as that is what run_command() splits
+	    # lines on. If just a newline is used, all error message lines end up on a single line
+	    # in the migration tasklog.
+	    my $err = '';
+	    $run_params{logfunc} = sub { $err .= "QEMU: $1\r\n"; };
+
 	    my $exitcode = run_command($cmd, %run_params);
 	    if ($exitcode) {
 		if ($tpmpid) {
 		    warn "stopping swtpm instance (pid $tpmpid) due to QEMU startup error\n";
 		    kill 'TERM', $tpmpid;
 		}
-		die "QEMU exited with code $exitcode\n";
+		die "QEMU exited with code $exitcode\r\n$err";
 	    }
 	};
     };
-- 
2.39.2