git: 506890a652aa - stable/13 - bhyve: Replace many fprintf(stderr, ...) calls with EPRINTLN

From: John Baldwin <jhb_at_FreeBSD.org>
Date: Tue, 24 Oct 2023 19:00:35 UTC
The branch stable/13 has been updated by jhb:

URL: https://cgit.FreeBSD.org/src/commit/?id=506890a652aaf19f59da0a84be26e991f99372d9

commit 506890a652aaf19f59da0a84be26e991f99372d9
Author:     John Baldwin <jhb@FreeBSD.org>
AuthorDate: 2023-10-16 22:17:48 +0000
Commit:     John Baldwin <jhb@FreeBSD.org>
CommitDate: 2023-10-24 18:58:15 +0000

    bhyve: Replace many fprintf(stderr, ...) calls with EPRINTLN
    
    EPRINTLN handles newlines appropriately when stdout/stderr have been
    reused as the backend for a serial port.
    
    For bhyverun.c itself, the rule this attempts to follow is to use
    regular fprintf/perror/warn/err prior to init_pci() (which is when
    serial ports are configured) and to switch to EPRINTLN afterwards.
    
    Reviewed by:    corvink, markj
    Differential Revision:  https://reviews.freebsd.org/D42182
    
    (cherry picked from commit b0936440b8fcee523c0b26fdbbef7c3b2b5098bf)
---
 usr.sbin/bhyve/bhyverun.c | 92 +++++++++++++++++++++++------------------------
 usr.sbin/bhyve/block_if.c |  2 +-
 usr.sbin/bhyve/bootrom.c  | 14 ++++----
 usr.sbin/bhyve/e820.c     |  5 +--
 usr.sbin/bhyve/gdb.c      |  3 +-
 usr.sbin/bhyve/pci_ahci.c |  7 ++--
 usr.sbin/bhyve/pci_xhci.c | 10 +++---
 usr.sbin/bhyve/snapshot.c |  6 ++--
 8 files changed, 70 insertions(+), 69 deletions(-)

diff --git a/usr.sbin/bhyve/bhyverun.c b/usr.sbin/bhyve/bhyverun.c
index 56acf5bfb5d7..3d2aa851911f 100644
--- a/usr.sbin/bhyve/bhyverun.c
+++ b/usr.sbin/bhyve/bhyverun.c
@@ -571,7 +571,7 @@ fbsdrun_deletecpu(int vcpu)
 {
 
 	if (!CPU_ISSET(vcpu, &cpumask)) {
-		fprintf(stderr, "Attempting to delete unknown cpu %d\n", vcpu);
+		EPRINTLN("Attempting to delete unknown cpu %d", vcpu);
 		exit(4);
 	}
 
@@ -613,7 +613,7 @@ vmexit_inout(struct vmctx *ctx, struct vm_exit *vme, int *pvcpu)
 
 	error = emulate_inout(ctx, vcpu, vme);
 	if (error) {
-		fprintf(stderr, "Unhandled %s%c 0x%04x at 0x%lx\n",
+		EPRINTLN("Unhandled %s%c 0x%04x at 0x%lx",
 		    in ? "in" : "out",
 		    bytes == 1 ? 'b' : (bytes == 2 ? 'w' : 'l'),
 		    port, vme->rip);
@@ -633,7 +633,7 @@ vmexit_rdmsr(struct vmctx *ctx, struct vm_exit *vme, int *pvcpu)
 	val = 0;
 	error = emulate_rdmsr(ctx, *pvcpu, vme->u.msr.code, &val);
 	if (error != 0) {
-		fprintf(stderr, "rdmsr to register %#x on vcpu %d\n",
+		EPRINTLN("rdmsr to register %#x on vcpu %d",
 		    vme->u.msr.code, *pvcpu);
 		if (get_config_bool("x86.strictmsr")) {
 			vm_inject_gp(ctx, *pvcpu);
@@ -659,7 +659,7 @@ vmexit_wrmsr(struct vmctx *ctx, struct vm_exit *vme, int *pvcpu)
 
 	error = emulate_wrmsr(ctx, *pvcpu, vme->u.msr.code, vme->u.msr.wval);
 	if (error != 0) {
-		fprintf(stderr, "wrmsr to register %#x(%#lx) on vcpu %d\n",
+		EPRINTLN("wrmsr to register %#x(%#lx) on vcpu %d",
 		    vme->u.msr.code, vme->u.msr.wval, *pvcpu);
 		if (get_config_bool("x86.strictmsr")) {
 			vm_inject_gp(ctx, *pvcpu);
@@ -691,17 +691,17 @@ static int
 vmexit_vmx(struct vmctx *ctx, struct vm_exit *vme, int *pvcpu)
 {
 
-	fprintf(stderr, "vm exit[%d]\n", *pvcpu);
-	fprintf(stderr, "\treason\t\tVMX\n");
-	fprintf(stderr, "\trip\t\t0x%016lx\n", vme->rip);
-	fprintf(stderr, "\tinst_length\t%d\n", vme->inst_length);
-	fprintf(stderr, "\tstatus\t\t%d\n", vme->u.vmx.status);
-	fprintf(stderr, "\texit_reason\t%u (%s)\n", vme->u.vmx.exit_reason,
+	EPRINTLN("vm exit[%d]", *pvcpu);
+	EPRINTLN("\treason\t\tVMX");
+	EPRINTLN("\trip\t\t0x%016lx", vme->rip);
+	EPRINTLN("\tinst_length\t%d", vme->inst_length);
+	EPRINTLN("\tstatus\t\t%d", vme->u.vmx.status);
+	EPRINTLN("\texit_reason\t%u (%s)", vme->u.vmx.exit_reason,
 	    vmexit_vmx_desc(vme->u.vmx.exit_reason));
-	fprintf(stderr, "\tqualification\t0x%016lx\n",
+	EPRINTLN("\tqualification\t0x%016lx",
 	    vme->u.vmx.exit_qualification);
-	fprintf(stderr, "\tinst_type\t\t%d\n", vme->u.vmx.inst_type);
-	fprintf(stderr, "\tinst_error\t\t%d\n", vme->u.vmx.inst_error);
+	EPRINTLN("\tinst_type\t\t%d", vme->u.vmx.inst_type);
+	EPRINTLN("\tinst_error\t\t%d", vme->u.vmx.inst_error);
 #ifdef DEBUG_EPT_MISCONFIG
 	if (vme->u.vmx.exit_reason == EXIT_REASON_EPT_MISCONFIG) {
 		vm_get_register(ctx, *pvcpu,
@@ -709,9 +709,9 @@ vmexit_vmx(struct vmctx *ctx, struct vm_exit *vme, int *pvcpu)
 		    &ept_misconfig_gpa);
 		vm_get_gpa_pmap(ctx, ept_misconfig_gpa, ept_misconfig_pte,
 		    &ept_misconfig_ptenum);
-		fprintf(stderr, "\tEPT misconfiguration:\n");
-		fprintf(stderr, "\t\tGPA: %#lx\n", ept_misconfig_gpa);
-		fprintf(stderr, "\t\tPTE(%d): %#lx %#lx %#lx %#lx\n",
+		EPRINTLN("\tEPT misconfiguration:");
+		EPRINTLN("\t\tGPA: %#lx", ept_misconfig_gpa);
+		EPRINTLN("\t\tPTE(%d): %#lx %#lx %#lx %#lx",
 		    ept_misconfig_ptenum, ept_misconfig_pte[0],
 		    ept_misconfig_pte[1], ept_misconfig_pte[2],
 		    ept_misconfig_pte[3]);
@@ -724,13 +724,13 @@ static int
 vmexit_svm(struct vmctx *ctx __unused, struct vm_exit *vme, int *pvcpu)
 {
 
-	fprintf(stderr, "vm exit[%d]\n", *pvcpu);
-	fprintf(stderr, "\treason\t\tSVM\n");
-	fprintf(stderr, "\trip\t\t0x%016lx\n", vme->rip);
-	fprintf(stderr, "\tinst_length\t%d\n", vme->inst_length);
-	fprintf(stderr, "\texitcode\t%#lx\n", vme->u.svm.exitcode);
-	fprintf(stderr, "\texitinfo1\t%#lx\n", vme->u.svm.exitinfo1);
-	fprintf(stderr, "\texitinfo2\t%#lx\n", vme->u.svm.exitinfo2);
+	EPRINTLN("vm exit[%d]", *pvcpu);
+	EPRINTLN("\treason\t\tSVM");
+	EPRINTLN("\trip\t\t0x%016lx", vme->rip);
+	EPRINTLN("\tinst_length\t%d", vme->inst_length);
+	EPRINTLN("\texitcode\t%#lx", vme->u.svm.exitcode);
+	EPRINTLN("\texitinfo1\t%#lx", vme->u.svm.exitinfo1);
+	EPRINTLN("\texitinfo2\t%#lx", vme->u.svm.exitinfo2);
 	return (VMEXIT_ABORT);
 }
 
@@ -886,7 +886,7 @@ vmexit_suspend(struct vmctx *ctx, struct vm_exit *vme, int *pvcpu)
 	case VM_SUSPEND_TRIPLEFAULT:
 		exit(3);
 	default:
-		fprintf(stderr, "vmexit_suspend: invalid reason %d\n", how);
+		EPRINTLN("vmexit_suspend: invalid reason %d", how);
 		exit(100);
 	}
 	return (0);	/* NOTREACHED */
@@ -1001,7 +1001,7 @@ vm_loop(struct vmctx *ctx, int vcpu)
 			exit(4);
 		}
 	}
-	fprintf(stderr, "vm_run error %d, errno %d\n", error, errno);
+	EPRINTLN("vm_run error %d, errno %d", error, errno);
 }
 
 static int
@@ -1033,7 +1033,7 @@ fbsdrun_set_capabilities(struct vmctx *ctx, int cpu)
 	if (get_config_bool_default("x86.vmexit_on_hlt", false)) {
 		err = vm_get_capability(ctx, cpu, VM_CAP_HALT_EXIT, &tmp);
 		if (err < 0) {
-			fprintf(stderr, "VM exit on HLT not supported\n");
+			EPRINTLN("VM exit on HLT not supported");
 			exit(4);
 		}
 		vm_set_capability(ctx, cpu, VM_CAP_HALT_EXIT, 1);
@@ -1047,8 +1047,7 @@ fbsdrun_set_capabilities(struct vmctx *ctx, int cpu)
 		 */
 		err = vm_get_capability(ctx, cpu, VM_CAP_PAUSE_EXIT, &tmp);
 		if (err < 0) {
-			fprintf(stderr,
-			    "SMP mux requested, no pause support\n");
+			EPRINTLN("SMP mux requested, no pause support");
 			exit(4);
 		}
 		vm_set_capability(ctx, cpu, VM_CAP_PAUSE_EXIT, 1);
@@ -1062,7 +1061,7 @@ fbsdrun_set_capabilities(struct vmctx *ctx, int cpu)
 		err = vm_set_x2apic_state(ctx, cpu, X2APIC_DISABLED);
 
 	if (err) {
-		fprintf(stderr, "Unable to set x2apic state (%d)\n", err);
+		EPRINTLN("Unable to set x2apic state (%d)", err);
 		exit(4);
 	}
 
@@ -1466,13 +1465,13 @@ main(int argc, char *argv[])
 	sci_init(ctx);
 
 	if (qemu_fwcfg_init(ctx) != 0) {
-		fprintf(stderr, "qemu fwcfg initialization error");
+		fprintf(stderr, "qemu fwcfg initialization error\n");
 		exit(4);
 	}
 
 	if (qemu_fwcfg_add_file("opt/bhyve/hw.ncpu", sizeof(guest_ncpus),
 	    &guest_ncpus) != 0) {
-		fprintf(stderr, "Could not add qemu fwcfg opt/bhyve/hw.ncpu");
+		fprintf(stderr, "Could not add qemu fwcfg opt/bhyve/hw.ncpu\n");
 		exit(4);
 	}
 
@@ -1485,7 +1484,8 @@ main(int argc, char *argv[])
 	 * Exit if a device emulation finds an error in its initilization
 	 */
 	if (init_pci(ctx) != 0) {
-		perror("device emulation initialization error");
+		EPRINTLN("Device emulation initialization error: %s",
+		    strerror(errno));
 		exit(4);
 	}
 
@@ -1500,8 +1500,8 @@ main(int argc, char *argv[])
 
 	if (lpc_bootrom()) {
 		if (vm_set_capability(ctx, BSP, VM_CAP_UNRESTRICTED_GUEST, 1)) {
-			fprintf(stderr, "ROM boot failed: unrestricted guest "
-			    "capability not available\n");
+			EPRINTLN("ROM boot failed: unrestricted guest "
+			    "capability not available");
 			exit(4);
 		}
 		error = vcpu_reset(ctx, BSP);
@@ -1520,33 +1520,33 @@ main(int argc, char *argv[])
 
 #ifdef BHYVE_SNAPSHOT
 	if (restore_file != NULL) {
-		fprintf(stdout, "Pausing pci devs...\r\n");
+		FPRINTLN(stdout, "Pausing pci devs...");
 		if (vm_pause_devices() != 0) {
-			fprintf(stderr, "Failed to pause PCI device state.\n");
+			EPRINTLN("Failed to pause PCI device state.");
 			exit(1);
 		}
 
-		fprintf(stdout, "Restoring vm mem...\r\n");
+		FPRINTLN(stdout, "Restoring vm mem...");
 		if (restore_vm_mem(ctx, &rstate) != 0) {
-			fprintf(stderr, "Failed to restore VM memory.\n");
+			EPRINTLN("Failed to restore VM memory.");
 			exit(1);
 		}
 
-		fprintf(stdout, "Restoring pci devs...\r\n");
+		FPRINTLN(stdout, "Restoring pci devs...");
 		if (vm_restore_devices(ctx, &rstate) != 0) {
-			fprintf(stderr, "Failed to restore PCI device state.\n");
+			EPRINTLN("Failed to restore PCI device state.");
 			exit(1);
 		}
 
-		fprintf(stdout, "Restoring kernel structs...\r\n");
+		FPRINTLN(stdout, "Restoring kernel structs...");
 		if (vm_restore_kern_structs(ctx, &rstate) != 0) {
-			fprintf(stderr, "Failed to restore kernel structs.\n");
+			EPRINTLN("Failed to restore kernel structs.");
 			exit(1);
 		}
 
-		fprintf(stdout, "Resuming pci devs...\r\n");
+		FPRINTLN(stdout, "Resuming pci devs...");
 		if (vm_resume_devices() != 0) {
-			fprintf(stderr, "Failed to resume PCI device state.\n");
+			EPRINTLN("Failed to resume PCI device state.");
 			exit(1);
 		}
 	}
@@ -1577,12 +1577,12 @@ main(int argc, char *argv[])
 
 	e820_fwcfg_item = e820_get_fwcfg_item();
 	if (e820_fwcfg_item == NULL) {
-	    fprintf(stderr, "invalid e820 table");
+		EPRINTLN("invalid e820 table");
 		exit(4);
 	}
 	if (qemu_fwcfg_add_file("etc/e820", e820_fwcfg_item->size,
 		e820_fwcfg_item->data) != 0) {
-		fprintf(stderr, "could not add qemu fwcfg etc/e820");
+		EPRINTLN("could not add qemu fwcfg etc/e820");
 		exit(4);
 	}
 	free(e820_fwcfg_item);
diff --git a/usr.sbin/bhyve/block_if.c b/usr.sbin/bhyve/block_if.c
index dc8dc434d447..5fabb7719e29 100644
--- a/usr.sbin/bhyve/block_if.c
+++ b/usr.sbin/bhyve/block_if.c
@@ -1009,7 +1009,7 @@ blockif_pause(struct blockif_ctxt *bc)
 	pthread_mutex_unlock(&bc->bc_mtx);
 
 	if (!bc->bc_rdonly && blockif_flush_bc(bc))
-		fprintf(stderr, "%s: [WARN] failed to flush backing file.\r\n",
+		EPRINTLN("%s: [WARN] failed to flush backing file.",
 			__func__);
 }
 
diff --git a/usr.sbin/bhyve/bootrom.c b/usr.sbin/bhyve/bootrom.c
index 4f0ab733acb2..6d9153b7ddc6 100644
--- a/usr.sbin/bhyve/bootrom.c
+++ b/usr.sbin/bhyve/bootrom.c
@@ -238,14 +238,14 @@ bootrom_loadrom(struct vmctx *ctx, const nvlist_t *nvl)
 	if (varfile != NULL) {
 		varfd = open(varfile, O_RDWR);
 		if (varfd < 0) {
-			fprintf(stderr, "Error opening bootrom variable file "
-			    "\"%s\": %s\n", varfile, strerror(errno));
+			EPRINTLN("Error opening bootrom variable file "
+			    "\"%s\": %s", varfile, strerror(errno));
 			goto done;
 		}
 
 		if (fstat(varfd, &sbuf) < 0) {
-			fprintf(stderr,
-			    "Could not fstat bootrom variable file \"%s\": %s\n",
+			EPRINTLN(
+			    "Could not fstat bootrom variable file \"%s\": %s",
 			    varfile, strerror(errno));
 			goto done;
 		}
@@ -255,7 +255,7 @@ bootrom_loadrom(struct vmctx *ctx, const nvlist_t *nvl)
 
 	if (var_size > BOOTROM_SIZE ||
 	    (var_size != 0 && var_size < PAGE_SIZE)) {
-		fprintf(stderr, "Invalid bootrom variable size %ld\n",
+		EPRINTLN("Invalid bootrom variable size %ld",
 		    var_size);
 		goto done;
 	}
@@ -263,8 +263,8 @@ bootrom_loadrom(struct vmctx *ctx, const nvlist_t *nvl)
 	total_size = rom_size + var_size;
 
 	if (total_size > BOOTROM_SIZE) {
-		fprintf(stderr, "Invalid bootrom and variable aggregate size "
-		    "%ld\n", total_size);
+		EPRINTLN("Invalid bootrom and variable aggregate size %ld",
+		    total_size);
 		goto done;
 	}
 
diff --git a/usr.sbin/bhyve/e820.c b/usr.sbin/bhyve/e820.c
index 99a66645f70f..a2c638e3ecbe 100644
--- a/usr.sbin/bhyve/e820.c
+++ b/usr.sbin/bhyve/e820.c
@@ -17,6 +17,7 @@
 #include <stdlib.h>
 #include <string.h>
 
+#include "debug.h"
 #include "e820.h"
 #include "qemu_fwcfg.h"
 
@@ -93,11 +94,11 @@ e820_dump_table(void)
 	struct e820_element *element;
 	uint64_t i;
 
-	fprintf(stderr, "E820 map:\n");
+	EPRINTLN("E820 map:");
 	
 	i = 0;
 	TAILQ_FOREACH(element, &e820_table, chain) {
-		fprintf(stderr, "  (%4lu) [%16lx, %16lx] %s\n", i,
+		EPRINTLN("  (%4lu) [%16lx, %16lx] %s", i,
 		    element->base, element->end,
 		    e820_get_type_name(element->type));
 
diff --git a/usr.sbin/bhyve/gdb.c b/usr.sbin/bhyve/gdb.c
index a9ece8cf35e9..cec9ac92ac1c 100644
--- a/usr.sbin/bhyve/gdb.c
+++ b/usr.sbin/bhyve/gdb.c
@@ -59,6 +59,7 @@
 
 #include "bhyverun.h"
 #include "config.h"
+#include "debug.h"
 #include "gdb.h"
 #include "mem.h"
 #include "mevent.h"
@@ -882,7 +883,7 @@ gdb_cpu_breakpoint(int vcpu, struct vm_exit *vmexit)
 	int error;
 
 	if (!gdb_active) {
-		fprintf(stderr, "vm_loop: unexpected VMEXIT_DEBUG\n");
+		EPRINTLN("vm_loop: unexpected VMEXIT_DEBUG");
 		exit(4);
 	}
 	pthread_mutex_lock(&gdb_lock);
diff --git a/usr.sbin/bhyve/pci_ahci.c b/usr.sbin/bhyve/pci_ahci.c
index 863c504d2dc6..8a48eb00e9b0 100644
--- a/usr.sbin/bhyve/pci_ahci.c
+++ b/usr.sbin/bhyve/pci_ahci.c
@@ -2609,7 +2609,7 @@ pci_ahci_snapshot(struct vm_snapshot_meta *meta)
 		/* Mostly for restore; save is ensured by the lines above. */
 		if (((bctx == NULL) && (port->bctx != NULL)) ||
 		    ((bctx != NULL) && (port->bctx == NULL))) {
-			fprintf(stderr, "%s: ports not matching\r\n", __func__);
+			EPRINTLN("%s: ports not matching", __func__);
 			ret = EINVAL;
 			goto done;
 		}
@@ -2618,9 +2618,8 @@ pci_ahci_snapshot(struct vm_snapshot_meta *meta)
 			continue;
 
 		if (port->port != i) {
-			fprintf(stderr, "%s: ports not matching: "
-					"actual: %d expected: %d\r\n",
-					__func__, port->port, i);
+			EPRINTLN("%s: ports not matching: "
+			    "actual: %d expected: %d", __func__, port->port, i);
 			ret = EINVAL;
 			goto done;
 		}
diff --git a/usr.sbin/bhyve/pci_xhci.c b/usr.sbin/bhyve/pci_xhci.c
index 4be3381419c8..58f2d53eb9b5 100644
--- a/usr.sbin/bhyve/pci_xhci.c
+++ b/usr.sbin/bhyve/pci_xhci.c
@@ -3101,8 +3101,8 @@ pci_xhci_snapshot(struct vm_snapshot_meta *meta)
 
 		/* check if the restored device (when restoring) is sane */
 		if (restore_idx != i) {
-			fprintf(stderr, "%s: idx not matching: actual: %d, "
-				"expected: %d\r\n", __func__, restore_idx, i);
+			EPRINTLN("%s: idx not matching: actual: %d, "
+			    "expected: %d", __func__, restore_idx, i);
 			ret = EINVAL;
 			goto done;
 		}
@@ -3117,9 +3117,9 @@ pci_xhci_snapshot(struct vm_snapshot_meta *meta)
 		if (meta->op == VM_SNAPSHOT_RESTORE) {
 			dname[sizeof(dname) - 1] = '\0';
 			if (strcmp(dev->dev_ue->ue_emu, dname)) {
-				fprintf(stderr, "%s: device names mismatch: "
-					"actual: %s, expected: %s\r\n",
-					__func__, dname, dev->dev_ue->ue_emu);
+				EPRINTLN("%s: device names mismatch: "
+				    "actual: %s, expected: %s",
+				    __func__, dname, dev->dev_ue->ue_emu);
 
 				ret = EINVAL;
 				goto done;
diff --git a/usr.sbin/bhyve/snapshot.c b/usr.sbin/bhyve/snapshot.c
index 953958b0fdab..dc9bfa005092 100644
--- a/usr.sbin/bhyve/snapshot.c
+++ b/usr.sbin/bhyve/snapshot.c
@@ -180,13 +180,13 @@ strcat_extension(const char *base_str, const char *ext)
 	ext_len = strnlen(ext, NAME_MAX);
 
 	if (base_len + ext_len > NAME_MAX) {
-		fprintf(stderr, "Filename exceeds maximum length.\n");
+		EPRINTLN("Filename exceeds maximum length.");
 		return (NULL);
 	}
 
 	res = malloc(base_len + ext_len + 1);
 	if (res == NULL) {
-		perror("Failed to allocate memory.");
+		EPRINTLN("Failed to allocate memory: %s", strerror(errno));
 		return (NULL);
 	}
 
@@ -201,7 +201,7 @@ void
 destroy_restore_state(struct restore_state *rstate)
 {
 	if (rstate == NULL) {
-		fprintf(stderr, "Attempting to destroy NULL restore struct.\n");
+		EPRINTLN("Attempting to destroy NULL restore struct.");
 		return;
 	}