[PATCH kvmtool v2 0/4] Add --loglevel argument

[PATCH kvmtool v2 0/4] Add --loglevel argument

[Alexandru Elisei]

kvmtool can be unnecessarily verbose at times, and Will proposed in a chat
we had a while ago to add a --loglevel command line argument to choose
which type of messages to silence. This is me taking a stab at it.

Build tested for all arches and run tested lightly on a rockpro64 and my
x86 machine.

Base commit is 3b1cdcf9e78f ("virtio/vhost: Clear VIRTIO_F_ACCESS_PLATFORM").

Changelog in each patch.

Alexandru Elisei (4):
  util: Make pr_err() return void
  Replace printf/fprintf with pr_* macros
  util: Use __pr_debug() instead of pr_info() to print debug messages
  Add --loglevel argument for the run command

 arm/gic.c            |  5 ++--
 builtin-run.c        | 69 ++++++++++++++++++++++++++++++--------------
 builtin-setup.c      | 16 +++++-----
 guest_compat.c       |  2 +-
 include/kvm/util.h   | 14 ++++++---
 kvm-cpu.c            | 12 ++++----
 mmio.c               |  2 +-
 util/parse-options.c | 28 ++++++++++--------
 util/util.c          | 27 +++++++++++++++--
 9 files changed, 116 insertions(+), 59 deletions(-)

-- 
2.41.0

[PATCH kvmtool v2 1/4] util: Make pr_err() return void

[Alexandru Elisei]

Of all the pr_* functions, pr_err() is the only function that returns a
value, which is -1. The code in parse_options is the only code that relies
on pr_err() returning a value, and that value must be exactly -1, because
it is being treated differently than the other return values.

This makes the code opaque, because it's not immediately obvious where that
value comes from, and fragile, as a change in the return value of pr_err
would break it.

Make pr_err() more like the other functions and don't return a value.

Reviewed-by: Jean-Philippe Brucker <jean-philippe@linaro.org>
Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>
---
Changelog:

- Added Reviewed-by from Jean-Philippe, thanks!
- Remove unneeded " " in get_arg()

 include/kvm/util.h   |  2 +-
 util/parse-options.c | 28 ++++++++++++++++------------
 util/util.c          |  3 +--
 3 files changed, 18 insertions(+), 15 deletions(-)

diff --git a/include/kvm/util.h b/include/kvm/util.h
index b49454876a83..f51f370d2b37 100644
--- a/include/kvm/util.h
+++ b/include/kvm/util.h
@@ -39,7 +39,7 @@ extern bool do_debug_print;
 
 extern void die(const char *err, ...) NORETURN __attribute__((format (printf, 1, 2)));
 extern void die_perror(const char *s) NORETURN;
-extern int pr_err(const char *err, ...) __attribute__((format (printf, 1, 2)));
+extern void pr_err(const char *err, ...) __attribute__((format (printf, 1, 2)));
 extern void pr_warning(const char *err, ...) __attribute__((format (printf, 1, 2)));
 extern void pr_info(const char *err, ...) __attribute__((format (printf, 1, 2)));
 extern void set_die_routine(void (*routine)(const char *err, va_list params) NORETURN);
diff --git a/util/parse-options.c b/util/parse-options.c
index 9a1bbee6c271..d353256e2651 100644
--- a/util/parse-options.c
+++ b/util/parse-options.c
@@ -17,10 +17,13 @@
 static int opterror(const struct option *opt, const char *reason, int flags)
 {
 	if (flags & OPT_SHORT)
-		return pr_err("switch `%c' %s", opt->short_name, reason);
-	if (flags & OPT_UNSET)
-		return pr_err("option `no-%s' %s", opt->long_name, reason);
-	return pr_err("option `%s' %s", opt->long_name, reason);
+		pr_err("switch `%c' %s", opt->short_name, reason);
+	else if (flags & OPT_UNSET)
+		pr_err("option `no-%s' %s", opt->long_name, reason);
+	else
+		pr_err("option `%s' %s", opt->long_name, reason);
+
+	return -1;
 }
 
 static int get_arg(struct parse_opt_ctx_t *p, const struct option *opt,
@@ -429,14 +432,15 @@ is_abbreviated:
 		return get_value(p, options, flags);
 	}
 
-	if (ambiguous_option)
-		return pr_err("Ambiguous option: %s "
-				"(could be --%s%s or --%s%s)",
-				arg,
-				(ambiguous_flags & OPT_UNSET) ?  "no-" : "",
-				ambiguous_option->long_name,
-				(abbrev_flags & OPT_UNSET) ?  "no-" : "",
-				abbrev_option->long_name);
+	if (ambiguous_option) {
+		pr_err("Ambiguous option: %s (could be --%s%s or --%s%s)",
+			arg,
+			(ambiguous_flags & OPT_UNSET) ?  "no-" : "",
+			ambiguous_option->long_name,
+			(abbrev_flags & OPT_UNSET) ?  "no-" : "",
+			abbrev_option->long_name);
+		return -1;
+	}
 	if (abbrev_option)
 		return get_value(p, abbrev_option, abbrev_flags);
 	return -2;
diff --git a/util/util.c b/util/util.c
index 1877105e3c08..f59f26e1581c 100644
--- a/util/util.c
+++ b/util/util.c
@@ -47,14 +47,13 @@ void die(const char *err, ...)
 	va_end(params);
 }
 
-int pr_err(const char *err, ...)
+void pr_err(const char *err, ...)
 {
 	va_list params;
 
 	va_start(params, err);
 	error_builtin(err, params);
 	va_end(params);
-	return -1;
 }
 
 void pr_warning(const char *warn, ...)
-- 
2.41.0

[PATCH kvmtool v2 2/4] Replace printf/fprintf with pr_* macros

[Alexandru Elisei]

To prepare for allowing finer control over the messages that kvmtool
displays, replace printf() and fprintf() with the pr_* macros.

Minor changes were made to fix coding style issues that were pet peeves for
the author. And use pr_err() in kvm_cpu__init() instead of pr_warning() for
fatal errors.

Also, fix the message when printing the exit code for KVM_EXIT_UNKNOWN by
removing the '0x' part, because it's printing a decimal number, not a
hexadecimal one (the format specifier is %llu, not %llx).

Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>
---
Changelog:

- Use pr_err() to directly replace fprintf() in kernel_usage_with_options()
  instead of concatening the kernel locations.
- Removed the '0x' from the "KVM exit code: 0x%llu" message in kvm_cpu_thread()
  because the number is decimal (it's %llu, not %llx).
- Reverted the changes to kvm__emulate_mmio() and debug_io () because those
  messages are displayed with --debug-mmio, respectively --debug-ioport, and
  --loglevel hiding them would have been counter-intuitive.
- Replaced the "warning" string in kvm__emulate_mmio() with "MMIO warning", to
  match the message from kvm__emulate_io(). And to make it clear that it isn't
  toggled with --loglevel.
- Removed extra spaces in virtio_compat_add_message().

 arm/gic.c       |  5 ++---
 builtin-run.c   | 37 +++++++++++++++++++------------------
 builtin-setup.c | 16 ++++++++--------
 guest_compat.c  |  2 +-
 kvm-cpu.c       | 12 ++++++------
 mmio.c          |  2 +-
 6 files changed, 37 insertions(+), 37 deletions(-)

diff --git a/arm/gic.c b/arm/gic.c
index a223a72cfeb9..0795e9509bf8 100644
--- a/arm/gic.c
+++ b/arm/gic.c
@@ -115,9 +115,8 @@ static int gic__create_its_frame(struct kvm *kvm, u64 its_frame_addr)
 
 	err = ioctl(kvm->vm_fd, KVM_CREATE_DEVICE, &its_device);
 	if (err) {
-		fprintf(stderr,
-			"GICv3 ITS requested, but kernel does not support it.\n");
-		fprintf(stderr, "Try --irqchip=gicv3 instead\n");
+		pr_err("GICv3 ITS requested, but kernel does not support it.");
+		pr_err("Try --irqchip=gicv3 instead");
 		return err;
 	}
 
diff --git a/builtin-run.c b/builtin-run.c
index bd0d0b9c2467..190a226e46da 100644
--- a/builtin-run.c
+++ b/builtin-run.c
@@ -271,12 +271,14 @@ static void *kvm_cpu_thread(void *arg)
 	return (void *) (intptr_t) 0;
 
 panic_kvm:
-	fprintf(stderr, "KVM exit reason: %u (\"%s\")\n",
+	pr_err("KVM exit reason: %u (\"%s\")",
 		current_kvm_cpu->kvm_run->exit_reason,
 		kvm_exit_reasons[current_kvm_cpu->kvm_run->exit_reason]);
-	if (current_kvm_cpu->kvm_run->exit_reason == KVM_EXIT_UNKNOWN)
-		fprintf(stderr, "KVM exit code: 0x%llu\n",
+
+	if (current_kvm_cpu->kvm_run->exit_reason == KVM_EXIT_UNKNOWN) {
+		pr_err("KVM exit code: %llu",
 			(unsigned long long)current_kvm_cpu->kvm_run->hw.hardware_exit_reason);
+	}
 
 	kvm_cpu__set_debug_fd(STDOUT_FILENO);
 	kvm_cpu__show_registers(current_kvm_cpu);
@@ -313,10 +315,10 @@ static void kernel_usage_with_options(void)
 	const char **k;
 	struct utsname uts;
 
-	fprintf(stderr, "Fatal: could not find default kernel image in:\n");
+	pr_err("Could not find default kernel image in:");
 	k = &default_kernels[0];
 	while (*k) {
-		fprintf(stderr, "\t%s\n", *k);
+		pr_err("\t%s", *k);
 		k++;
 	}
 
@@ -327,10 +329,10 @@ static void kernel_usage_with_options(void)
 	while (*k) {
 		if (snprintf(kernel, PATH_MAX, "%s-%s", *k, uts.release) < 0)
 			return;
-		fprintf(stderr, "\t%s\n", kernel);
+		pr_err("\t%s", kernel);
 		k++;
 	}
-	fprintf(stderr, "\nPlease see '%s run --help' for more options.\n\n",
+	pr_info("Please see '%s run --help' for more options.",
 		KVM_BINARY_NAME);
 }
 
@@ -656,8 +658,7 @@ static struct kvm *kvm_cmd_run_init(int argc, const char **argv)
 
 			if ((kvm_run_wrapper == KVM_RUN_DEFAULT && kvm->cfg.kernel_filename) ||
 				(kvm_run_wrapper == KVM_RUN_SANDBOX && kvm->cfg.sandbox)) {
-				fprintf(stderr, "Cannot handle parameter: "
-						"%s\n", argv[0]);
+				pr_err("Cannot handle parameter: %s", argv[0]);
 				usage_with_options(run_usage, options);
 				free(kvm);
 				return ERR_PTR(-EINVAL);
@@ -775,15 +776,15 @@ static struct kvm *kvm_cmd_run_init(int argc, const char **argv)
 		kvm_run_set_real_cmdline(kvm);
 
 	if (kvm->cfg.kernel_filename) {
-		printf("  # %s run -k %s -m %Lu -c %d --name %s\n", KVM_BINARY_NAME,
-		       kvm->cfg.kernel_filename,
-		       (unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
-		       kvm->cfg.nrcpus, kvm->cfg.guest_name);
+		pr_info("# %s run -k %s -m %Lu -c %d --name %s", KVM_BINARY_NAME,
+			kvm->cfg.kernel_filename,
+			(unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
+			kvm->cfg.nrcpus, kvm->cfg.guest_name);
 	} else if (kvm->cfg.firmware_filename) {
-		printf("  # %s run --firmware %s -m %Lu -c %d --name %s\n", KVM_BINARY_NAME,
-		       kvm->cfg.firmware_filename,
-		       (unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
-		       kvm->cfg.nrcpus, kvm->cfg.guest_name);
+		pr_info("# %s run --firmware %s -m %Lu -c %d --name %s", KVM_BINARY_NAME,
+			kvm->cfg.firmware_filename,
+			(unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
+			kvm->cfg.nrcpus, kvm->cfg.guest_name);
 	}
 
 	if (init_list__init(kvm) < 0)
@@ -815,7 +816,7 @@ static void kvm_cmd_run_exit(struct kvm *kvm, int guest_ret)
 	init_list__exit(kvm);
 
 	if (guest_ret == 0)
-		printf("\n  # KVM session ended normally.\n");
+		pr_info("KVM session ended normally.");
 }
 
 int kvm_cmd_run(int argc, const char **argv, const char *prefix)
diff --git a/builtin-setup.c b/builtin-setup.c
index b24d2a18921e..27b641982359 100644
--- a/builtin-setup.c
+++ b/builtin-setup.c
@@ -271,15 +271,15 @@ int kvm_cmd_setup(int argc, const char **argv, const char *prefix)
 		kvm_setup_help();
 
 	r = do_setup(instance_name);
-	if (r == 0)
-		printf("A new rootfs '%s' has been created in '%s%s'.\n\n"
-			"You can now start it by running the following command:\n\n"
-			"  %s run -d %s\n",
-			instance_name, kvm__get_dir(), instance_name,
-			KVM_BINARY_NAME,instance_name);
-	else
-		printf("Unable to create rootfs in %s%s: %s\n",
+	if (r == 0) {
+		pr_info("A new rootfs '%s' has been created in '%s%s'.",
+			instance_name, kvm__get_dir(), instance_name);
+		pr_info("You can now start it by running the following command:");
+		pr_info("%s run -d %s", KVM_BINARY_NAME, instance_name);
+	} else {
+		pr_err("Unable to create rootfs in %s%s: %s",
 			kvm__get_dir(), instance_name, strerror(errno));
+	}
 
 	return r;
 }
diff --git a/guest_compat.c b/guest_compat.c
index fd4704b20b16..93f9aabcd6db 100644
--- a/guest_compat.c
+++ b/guest_compat.c
@@ -86,7 +86,7 @@ int compat__print_all_messages(void)
 
 		msg = list_first_entry(&messages, struct compat_message, list);
 
-		printf("\n  # KVM compatibility warning.\n\t%s\n\t%s\n",
+		pr_warning("KVM compatibility warning.\n\t%s\n\t%s",
 			msg->title, msg->desc);
 
 		list_del(&msg->list);
diff --git a/kvm-cpu.c b/kvm-cpu.c
index 7dec08894cd3..1c566b3f21d6 100644
--- a/kvm-cpu.c
+++ b/kvm-cpu.c
@@ -265,32 +265,32 @@ int kvm_cpu__init(struct kvm *kvm)
 	recommended_cpus = kvm__recommended_cpus(kvm);
 
 	if (kvm->cfg.nrcpus > max_cpus) {
-		printf("  # Limit the number of CPUs to %d\n", max_cpus);
+		pr_warning("Limiting the number of CPUs to %d", max_cpus);
 		kvm->cfg.nrcpus = max_cpus;
 	} else if (kvm->cfg.nrcpus > recommended_cpus) {
-		printf("  # Warning: The maximum recommended amount of VCPUs"
-			" is %d\n", recommended_cpus);
+		pr_warning("The maximum recommended amount of VCPUs is %d",
+			   recommended_cpus);
 	}
 
 	kvm->nrcpus = kvm->cfg.nrcpus;
 
 	task_eventfd = eventfd(0, 0);
 	if (task_eventfd < 0) {
-		pr_warning("Couldn't create task_eventfd");
+		pr_err("Couldn't create task_eventfd");
 		return task_eventfd;
 	}
 
 	/* Alloc one pointer too many, so array ends up 0-terminated */
 	kvm->cpus = calloc(kvm->nrcpus + 1, sizeof(void *));
 	if (!kvm->cpus) {
-		pr_warning("Couldn't allocate array for %d CPUs", kvm->nrcpus);
+		pr_err("Couldn't allocate array for %d CPUs", kvm->nrcpus);
 		return -ENOMEM;
 	}
 
 	for (i = 0; i < kvm->nrcpus; i++) {
 		kvm->cpus[i] = kvm_cpu__arch_init(kvm, i);
 		if (!kvm->cpus[i]) {
-			pr_warning("unable to initialize KVM VCPU");
+			pr_err("unable to initialize KVM VCPU");
 			goto fail_alloc;
 		}
 	}
diff --git a/mmio.c b/mmio.c
index 5a114e9997d9..231ce91e3d47 100644
--- a/mmio.c
+++ b/mmio.c
@@ -203,7 +203,7 @@ bool kvm__emulate_mmio(struct kvm_cpu *vcpu, u64 phys_addr, u8 *data,
 	mmio = mmio_get(&mmio_tree, phys_addr, len);
 	if (!mmio) {
 		if (vcpu->kvm->cfg.mmio_debug)
-			fprintf(stderr,	"Warning: Ignoring MMIO %s at %016llx (length %u)\n",
+			fprintf(stderr,	"MMIO warning: Ignoring MMIO %s at %016llx (length %u)\n",
 				to_direction(is_write),
 				(unsigned long long)phys_addr, len);
 		goto out;
-- 
2.41.0

[PATCH kvmtool v2 3/4] util: Use __pr_debug() instead of pr_info() to print debug messages

[Alexandru Elisei]

pr_debug() is special, because it can be suppressed with a command line
argument, and because it needs to be a macro to capture the correct
filename, function name and line number. Display debug messages with the
prefix "Debug", to make it clear that those aren't informational messages.

Reviewed-by: Jean-Philippe Brucker <jean-philippe@linaro.org>
Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>
---
Changelog:

- Added Reviewed-by.
- Changed parameter name to the pr_debug functions to be "debug" instead of
  "info".

 include/kvm/util.h |  3 ++-
 util/util.c        | 15 +++++++++++++++
 2 files changed, 17 insertions(+), 1 deletion(-)

diff --git a/include/kvm/util.h b/include/kvm/util.h
index f51f370d2b37..68d568d0fa9a 100644
--- a/include/kvm/util.h
+++ b/include/kvm/util.h
@@ -42,12 +42,13 @@ extern void die_perror(const char *s) NORETURN;
 extern void pr_err(const char *err, ...) __attribute__((format (printf, 1, 2)));
 extern void pr_warning(const char *err, ...) __attribute__((format (printf, 1, 2)));
 extern void pr_info(const char *err, ...) __attribute__((format (printf, 1, 2)));
+extern void __pr_debug(const char *debug, ...) __attribute__((format (printf, 1, 2)));
 extern void set_die_routine(void (*routine)(const char *err, va_list params) NORETURN);
 
 #define pr_debug(fmt, ...)						\
 	do {								\
 		if (do_debug_print)					\
-			pr_info("(%s) %s:%d: " fmt, __FILE__,		\
+			__pr_debug("(%s) %s:%d: " fmt, __FILE__,	\
 				__func__, __LINE__, ##__VA_ARGS__);	\
 	} while (0)
 
diff --git a/util/util.c b/util/util.c
index f59f26e1581c..7cf62edc3d34 100644
--- a/util/util.c
+++ b/util/util.c
@@ -38,6 +38,11 @@ static void info_builtin(const char *info, va_list params)
 	report(" Info: ", info, params);
 }
 
+static void debug_builtin(const char *debug, va_list params)
+{
+	report(" Debug: ", debug, params);
+}
+
 void die(const char *err, ...)
 {
 	va_list params;
@@ -74,6 +79,16 @@ void pr_info(const char *info, ...)
 	va_end(params);
 }
 
+/* Do not call directly; call pr_debug() instead. */
+void __pr_debug(const char *debug, ...)
+{
+	va_list params;
+
+	va_start(params, debug);
+	debug_builtin(debug, params);
+	va_end(params);
+}
+
 void die_perror(const char *s)
 {
 	perror(s);
-- 
2.41.0

[PATCH kvmtool v2 4/4] Add --loglevel argument for the run command

[Alexandru Elisei]

Add --loglevel command line argument, with the possible values of 'error',
'warning', 'info' or 'debug' to control what messages kvmtool displays. The
argument functions similarly to the Linux kernel parameter, when lower
verbosity levels hide all message with a higher verbosity (for example,
'warning' hides info and debug messages, allows warning and error
messsages).

The default level is 'info', to match the current behaviour. --debug has
been kept as a legacy option, which might be removed in the future.

Reviewed-by: Jean-Philippe Brucker <jean-philippe@linaro.org>
Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>
---
Changelog:

- Added Reviewed-by from Jean-Philippe, many thanks!

 builtin-run.c      | 32 ++++++++++++++++++++++++++++----
 include/kvm/util.h |  9 +++++++--
 util/util.c        |  9 +++++++++
 3 files changed, 44 insertions(+), 6 deletions(-)

diff --git a/builtin-run.c b/builtin-run.c
index 190a226e46da..b1a27fdaa961 100644
--- a/builtin-run.c
+++ b/builtin-run.c
@@ -58,8 +58,7 @@
 __thread struct kvm_cpu *current_kvm_cpu;
 
 static int  kvm_run_wrapper;
-
-bool do_debug_print = false;
+int loglevel = LOGLEVEL_INFO;
 
 static const char * const run_usage[] = {
 	"lkvm run [<options>] [<kernel image>]",
@@ -146,6 +145,27 @@ static int mem_parser(const struct option *opt, const char *arg, int unset)
 	return 0;
 }
 
+static int loglevel_parser(const struct option *opt, const char *arg, int unset)
+{
+	if (strcmp(opt->long_name, "debug") == 0) {
+		loglevel = LOGLEVEL_DEBUG;
+		return 0;
+	}
+
+	if (strcmp(arg, "debug") == 0)
+		loglevel = LOGLEVEL_DEBUG;
+	else if (strcmp(arg, "info") == 0)
+		loglevel = LOGLEVEL_INFO;
+	else if (strcmp(arg, "warning") == 0)
+		loglevel = LOGLEVEL_WARNING;
+	else if (strcmp(arg, "error") == 0)
+		loglevel = LOGLEVEL_ERROR;
+	else
+		die("Unknown loglevel: %s", arg);
+
+	return 0;
+}
+
 #ifndef OPT_ARCH_RUN
 #define OPT_ARCH_RUN(...)
 #endif
@@ -215,6 +235,8 @@ static int mem_parser(const struct option *opt, const char *arg, int unset)
 		     VIRTIO_TRANS_OPT_HELP_SHORT,		        \
 		     "Type of virtio transport",			\
 		     virtio_transport_parser, NULL),			\
+	OPT_CALLBACK('\0', "loglevel", NULL, "[error|warning|info|debug]",\
+			"Set the verbosity level", loglevel_parser, NULL),\
 									\
 	OPT_GROUP("Kernel options:"),					\
 	OPT_STRING('k', "kernel", &(cfg)->kernel_filename, "kernel",	\
@@ -241,8 +263,10 @@ static int mem_parser(const struct option *opt, const char *arg, int unset)
 		     vfio_device_parser, kvm),				\
 									\
 	OPT_GROUP("Debug options:"),					\
-	OPT_BOOLEAN('\0', "debug", &do_debug_print,			\
-			"Enable debug messages"),			\
+	OPT_CALLBACK_NOOPT('\0', "debug", kvm, NULL,			\
+			"Enable debug messages (deprecated, use "	\
+			"--loglevel=debug instead)",			\
+			loglevel_parser, NULL),				\
 	OPT_BOOLEAN('\0', "debug-single-step", &(cfg)->single_step,	\
 			"Enable single stepping"),			\
 	OPT_BOOLEAN('\0', "debug-ioport", &(cfg)->ioport_debug,		\
diff --git a/include/kvm/util.h b/include/kvm/util.h
index 68d568d0fa9a..ac8515f8c46b 100644
--- a/include/kvm/util.h
+++ b/include/kvm/util.h
@@ -32,7 +32,10 @@
 #endif
 #endif
 
-extern bool do_debug_print;
+#define LOGLEVEL_ERROR		0
+#define LOGLEVEL_WARNING	1
+#define LOGLEVEL_INFO		2
+#define LOGLEVEL_DEBUG		3
 
 #define PROT_RW (PROT_READ|PROT_WRITE)
 #define MAP_ANON_NORESERVE (MAP_PRIVATE | MAP_ANONYMOUS | MAP_NORESERVE)
@@ -45,9 +48,11 @@ extern void pr_info(const char *err, ...) __attribute__((format (printf, 1, 2)))
 extern void __pr_debug(const char *debug, ...) __attribute__((format (printf, 1, 2)));
 extern void set_die_routine(void (*routine)(const char *err, va_list params) NORETURN);
 
+extern int loglevel;
+
 #define pr_debug(fmt, ...)						\
 	do {								\
-		if (do_debug_print)					\
+		if (loglevel >= LOGLEVEL_DEBUG)				\
 			__pr_debug("(%s) %s:%d: " fmt, __FILE__,	\
 				__func__, __LINE__, ##__VA_ARGS__);	\
 	} while (0)
diff --git a/util/util.c b/util/util.c
index 7cf62edc3d34..bab4bb394111 100644
--- a/util/util.c
+++ b/util/util.c
@@ -56,6 +56,9 @@ void pr_err(const char *err, ...)
 {
 	va_list params;
 
+	if (loglevel < LOGLEVEL_ERROR)
+		return;
+
 	va_start(params, err);
 	error_builtin(err, params);
 	va_end(params);
@@ -65,6 +68,9 @@ void pr_warning(const char *warn, ...)
 {
 	va_list params;
 
+	if (loglevel < LOGLEVEL_WARNING)
+		return;
+
 	va_start(params, warn);
 	warn_builtin(warn, params);
 	va_end(params);
@@ -74,6 +80,9 @@ void pr_info(const char *info, ...)
 {
 	va_list params;
 
+	if (loglevel < LOGLEVEL_INFO)
+		return;
+
 	va_start(params, info);
 	info_builtin(info, params);
 	va_end(params);
-- 
2.41.0

Re: [PATCH kvmtool v2 0/4] Add --loglevel argument

[Anup Patel]

On Fri, Jul 7, 2023 at 8:41 PM Alexandru Elisei
<alexandru.elisei@arm.com> wrote:
>
> kvmtool can be unnecessarily verbose at times, and Will proposed in a chat
> we had a while ago to add a --loglevel command line argument to choose
> which type of messages to silence. This is me taking a stab at it.
>
> Build tested for all arches and run tested lightly on a rockpro64 and my
> x86 machine.
>
> Base commit is 3b1cdcf9e78f ("virtio/vhost: Clear VIRTIO_F_ACCESS_PLATFORM").
>
> Changelog in each patch.
>
> Alexandru Elisei (4):
>   util: Make pr_err() return void
>   Replace printf/fprintf with pr_* macros
>   util: Use __pr_debug() instead of pr_info() to print debug messages
>   Add --loglevel argument for the run command

Looks good for KVMTOOL RISC-V.

Reviewed-by: Anup Patel <anup@brainfault.org>

Regards,
Anup

>
>  arm/gic.c            |  5 ++--
>  builtin-run.c        | 69 ++++++++++++++++++++++++++++++--------------
>  builtin-setup.c      | 16 +++++-----
>  guest_compat.c       |  2 +-
>  include/kvm/util.h   | 14 ++++++---
>  kvm-cpu.c            | 12 ++++----
>  mmio.c               |  2 +-
>  util/parse-options.c | 28 ++++++++++--------
>  util/util.c          | 27 +++++++++++++++--
>  9 files changed, 116 insertions(+), 59 deletions(-)
>
> --
> 2.41.0
>

Re: [PATCH kvmtool v2 2/4] Replace printf/fprintf with pr_* macros

[Jean-Philippe Brucker]

On Fri, Jul 07, 2023 at 04:11:17PM +0100, Alexandru Elisei wrote:
> To prepare for allowing finer control over the messages that kvmtool
> displays, replace printf() and fprintf() with the pr_* macros.
> 
> Minor changes were made to fix coding style issues that were pet peeves for
> the author. And use pr_err() in kvm_cpu__init() instead of pr_warning() for
> fatal errors.
> 
> Also, fix the message when printing the exit code for KVM_EXIT_UNKNOWN by
> removing the '0x' part, because it's printing a decimal number, not a
> hexadecimal one (the format specifier is %llu, not %llx).
> 
> Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>

Reviewed-by: Jean-Philippe Brucker <jean-philippe@linaro.org>

> ---
> Changelog:
> 
> - Use pr_err() to directly replace fprintf() in kernel_usage_with_options()
>   instead of concatening the kernel locations.
> - Removed the '0x' from the "KVM exit code: 0x%llu" message in kvm_cpu_thread()
>   because the number is decimal (it's %llu, not %llx).
> - Reverted the changes to kvm__emulate_mmio() and debug_io () because those
>   messages are displayed with --debug-mmio, respectively --debug-ioport, and
>   --loglevel hiding them would have been counter-intuitive.
> - Replaced the "warning" string in kvm__emulate_mmio() with "MMIO warning", to
>   match the message from kvm__emulate_io(). And to make it clear that it isn't
>   toggled with --loglevel.
> - Removed extra spaces in virtio_compat_add_message().
> 
>  arm/gic.c       |  5 ++---
>  builtin-run.c   | 37 +++++++++++++++++++------------------
>  builtin-setup.c | 16 ++++++++--------
>  guest_compat.c  |  2 +-
>  kvm-cpu.c       | 12 ++++++------
>  mmio.c          |  2 +-
>  6 files changed, 37 insertions(+), 37 deletions(-)
> 
> diff --git a/arm/gic.c b/arm/gic.c
> index a223a72cfeb9..0795e9509bf8 100644
> --- a/arm/gic.c
> +++ b/arm/gic.c
> @@ -115,9 +115,8 @@ static int gic__create_its_frame(struct kvm *kvm, u64 its_frame_addr)
>  
>  	err = ioctl(kvm->vm_fd, KVM_CREATE_DEVICE, &its_device);
>  	if (err) {
> -		fprintf(stderr,
> -			"GICv3 ITS requested, but kernel does not support it.\n");
> -		fprintf(stderr, "Try --irqchip=gicv3 instead\n");
> +		pr_err("GICv3 ITS requested, but kernel does not support it.");
> +		pr_err("Try --irqchip=gicv3 instead");
>  		return err;
>  	}
>  
> diff --git a/builtin-run.c b/builtin-run.c
> index bd0d0b9c2467..190a226e46da 100644
> --- a/builtin-run.c
> +++ b/builtin-run.c
> @@ -271,12 +271,14 @@ static void *kvm_cpu_thread(void *arg)
>  	return (void *) (intptr_t) 0;
>  
>  panic_kvm:
> -	fprintf(stderr, "KVM exit reason: %u (\"%s\")\n",
> +	pr_err("KVM exit reason: %u (\"%s\")",
>  		current_kvm_cpu->kvm_run->exit_reason,
>  		kvm_exit_reasons[current_kvm_cpu->kvm_run->exit_reason]);
> -	if (current_kvm_cpu->kvm_run->exit_reason == KVM_EXIT_UNKNOWN)
> -		fprintf(stderr, "KVM exit code: 0x%llu\n",
> +
> +	if (current_kvm_cpu->kvm_run->exit_reason == KVM_EXIT_UNKNOWN) {
> +		pr_err("KVM exit code: %llu",
>  			(unsigned long long)current_kvm_cpu->kvm_run->hw.hardware_exit_reason);
> +	}
>  
>  	kvm_cpu__set_debug_fd(STDOUT_FILENO);
>  	kvm_cpu__show_registers(current_kvm_cpu);
> @@ -313,10 +315,10 @@ static void kernel_usage_with_options(void)
>  	const char **k;
>  	struct utsname uts;
>  
> -	fprintf(stderr, "Fatal: could not find default kernel image in:\n");
> +	pr_err("Could not find default kernel image in:");
>  	k = &default_kernels[0];
>  	while (*k) {
> -		fprintf(stderr, "\t%s\n", *k);
> +		pr_err("\t%s", *k);
>  		k++;
>  	}
>  
> @@ -327,10 +329,10 @@ static void kernel_usage_with_options(void)
>  	while (*k) {
>  		if (snprintf(kernel, PATH_MAX, "%s-%s", *k, uts.release) < 0)
>  			return;
> -		fprintf(stderr, "\t%s\n", kernel);
> +		pr_err("\t%s", kernel);
>  		k++;
>  	}
> -	fprintf(stderr, "\nPlease see '%s run --help' for more options.\n\n",
> +	pr_info("Please see '%s run --help' for more options.",
>  		KVM_BINARY_NAME);
>  }
>  
> @@ -656,8 +658,7 @@ static struct kvm *kvm_cmd_run_init(int argc, const char **argv)
>  
>  			if ((kvm_run_wrapper == KVM_RUN_DEFAULT && kvm->cfg.kernel_filename) ||
>  				(kvm_run_wrapper == KVM_RUN_SANDBOX && kvm->cfg.sandbox)) {
> -				fprintf(stderr, "Cannot handle parameter: "
> -						"%s\n", argv[0]);
> +				pr_err("Cannot handle parameter: %s", argv[0]);
>  				usage_with_options(run_usage, options);
>  				free(kvm);
>  				return ERR_PTR(-EINVAL);
> @@ -775,15 +776,15 @@ static struct kvm *kvm_cmd_run_init(int argc, const char **argv)
>  		kvm_run_set_real_cmdline(kvm);
>  
>  	if (kvm->cfg.kernel_filename) {
> -		printf("  # %s run -k %s -m %Lu -c %d --name %s\n", KVM_BINARY_NAME,
> -		       kvm->cfg.kernel_filename,
> -		       (unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
> -		       kvm->cfg.nrcpus, kvm->cfg.guest_name);
> +		pr_info("# %s run -k %s -m %Lu -c %d --name %s", KVM_BINARY_NAME,
> +			kvm->cfg.kernel_filename,
> +			(unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
> +			kvm->cfg.nrcpus, kvm->cfg.guest_name);
>  	} else if (kvm->cfg.firmware_filename) {
> -		printf("  # %s run --firmware %s -m %Lu -c %d --name %s\n", KVM_BINARY_NAME,
> -		       kvm->cfg.firmware_filename,
> -		       (unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
> -		       kvm->cfg.nrcpus, kvm->cfg.guest_name);
> +		pr_info("# %s run --firmware %s -m %Lu -c %d --name %s", KVM_BINARY_NAME,
> +			kvm->cfg.firmware_filename,
> +			(unsigned long long)kvm->cfg.ram_size >> MB_SHIFT,
> +			kvm->cfg.nrcpus, kvm->cfg.guest_name);
>  	}
>  
>  	if (init_list__init(kvm) < 0)
> @@ -815,7 +816,7 @@ static void kvm_cmd_run_exit(struct kvm *kvm, int guest_ret)
>  	init_list__exit(kvm);
>  
>  	if (guest_ret == 0)
> -		printf("\n  # KVM session ended normally.\n");
> +		pr_info("KVM session ended normally.");
>  }
>  
>  int kvm_cmd_run(int argc, const char **argv, const char *prefix)
> diff --git a/builtin-setup.c b/builtin-setup.c
> index b24d2a18921e..27b641982359 100644
> --- a/builtin-setup.c
> +++ b/builtin-setup.c
> @@ -271,15 +271,15 @@ int kvm_cmd_setup(int argc, const char **argv, const char *prefix)
>  		kvm_setup_help();
>  
>  	r = do_setup(instance_name);
> -	if (r == 0)
> -		printf("A new rootfs '%s' has been created in '%s%s'.\n\n"
> -			"You can now start it by running the following command:\n\n"
> -			"  %s run -d %s\n",
> -			instance_name, kvm__get_dir(), instance_name,
> -			KVM_BINARY_NAME,instance_name);
> -	else
> -		printf("Unable to create rootfs in %s%s: %s\n",
> +	if (r == 0) {
> +		pr_info("A new rootfs '%s' has been created in '%s%s'.",
> +			instance_name, kvm__get_dir(), instance_name);
> +		pr_info("You can now start it by running the following command:");
> +		pr_info("%s run -d %s", KVM_BINARY_NAME, instance_name);
> +	} else {
> +		pr_err("Unable to create rootfs in %s%s: %s",
>  			kvm__get_dir(), instance_name, strerror(errno));
> +	}
>  
>  	return r;
>  }
> diff --git a/guest_compat.c b/guest_compat.c
> index fd4704b20b16..93f9aabcd6db 100644
> --- a/guest_compat.c
> +++ b/guest_compat.c
> @@ -86,7 +86,7 @@ int compat__print_all_messages(void)
>  
>  		msg = list_first_entry(&messages, struct compat_message, list);
>  
> -		printf("\n  # KVM compatibility warning.\n\t%s\n\t%s\n",
> +		pr_warning("KVM compatibility warning.\n\t%s\n\t%s",
>  			msg->title, msg->desc);
>  
>  		list_del(&msg->list);
> diff --git a/kvm-cpu.c b/kvm-cpu.c
> index 7dec08894cd3..1c566b3f21d6 100644
> --- a/kvm-cpu.c
> +++ b/kvm-cpu.c
> @@ -265,32 +265,32 @@ int kvm_cpu__init(struct kvm *kvm)
>  	recommended_cpus = kvm__recommended_cpus(kvm);
>  
>  	if (kvm->cfg.nrcpus > max_cpus) {
> -		printf("  # Limit the number of CPUs to %d\n", max_cpus);
> +		pr_warning("Limiting the number of CPUs to %d", max_cpus);
>  		kvm->cfg.nrcpus = max_cpus;
>  	} else if (kvm->cfg.nrcpus > recommended_cpus) {
> -		printf("  # Warning: The maximum recommended amount of VCPUs"
> -			" is %d\n", recommended_cpus);
> +		pr_warning("The maximum recommended amount of VCPUs is %d",
> +			   recommended_cpus);
>  	}
>  
>  	kvm->nrcpus = kvm->cfg.nrcpus;
>  
>  	task_eventfd = eventfd(0, 0);
>  	if (task_eventfd < 0) {
> -		pr_warning("Couldn't create task_eventfd");
> +		pr_err("Couldn't create task_eventfd");
>  		return task_eventfd;
>  	}
>  
>  	/* Alloc one pointer too many, so array ends up 0-terminated */
>  	kvm->cpus = calloc(kvm->nrcpus + 1, sizeof(void *));
>  	if (!kvm->cpus) {
> -		pr_warning("Couldn't allocate array for %d CPUs", kvm->nrcpus);
> +		pr_err("Couldn't allocate array for %d CPUs", kvm->nrcpus);
>  		return -ENOMEM;
>  	}
>  
>  	for (i = 0; i < kvm->nrcpus; i++) {
>  		kvm->cpus[i] = kvm_cpu__arch_init(kvm, i);
>  		if (!kvm->cpus[i]) {
> -			pr_warning("unable to initialize KVM VCPU");
> +			pr_err("unable to initialize KVM VCPU");
>  			goto fail_alloc;
>  		}
>  	}
> diff --git a/mmio.c b/mmio.c
> index 5a114e9997d9..231ce91e3d47 100644
> --- a/mmio.c
> +++ b/mmio.c
> @@ -203,7 +203,7 @@ bool kvm__emulate_mmio(struct kvm_cpu *vcpu, u64 phys_addr, u8 *data,
>  	mmio = mmio_get(&mmio_tree, phys_addr, len);
>  	if (!mmio) {
>  		if (vcpu->kvm->cfg.mmio_debug)
> -			fprintf(stderr,	"Warning: Ignoring MMIO %s at %016llx (length %u)\n",
> +			fprintf(stderr,	"MMIO warning: Ignoring MMIO %s at %016llx (length %u)\n",
>  				to_direction(is_write),
>  				(unsigned long long)phys_addr, len);
>  		goto out;
> -- 
> 2.41.0
> 

Re: [PATCH kvmtool v2 0/4] Add --loglevel argument

[Will Deacon]

On Fri, 7 Jul 2023 16:11:15 +0100, Alexandru Elisei wrote:
> kvmtool can be unnecessarily verbose at times, and Will proposed in a chat
> we had a while ago to add a --loglevel command line argument to choose
> which type of messages to silence. This is me taking a stab at it.
> 
> Build tested for all arches and run tested lightly on a rockpro64 and my
> x86 machine.
> 
> [...]

Applied to kvmtool (master), thanks!

[1/4] util: Make pr_err() return void
      https://git.kernel.org/will/kvmtool/c/2cc4929cc6b9
[2/4] Replace printf/fprintf with pr_* macros
      https://git.kernel.org/will/kvmtool/c/72e13944777a
[3/4] util: Use __pr_debug() instead of pr_info() to print debug messages
      https://git.kernel.org/will/kvmtool/c/fc184a682a21
[4/4] Add --loglevel argument for the run command
      https://git.kernel.org/will/kvmtool/c/bd4ba57156da

Cheers,
-- 
Will

https://fixes.arm64.dev
https://next.arm64.dev
https://will.arm64.dev

Re: [PATCH kvmtool v2 2/4] Replace printf/fprintf with pr_* macros

[Suzuki K Poulose]

Hi Alexandru

On 07/07/2023 16:11, Alexandru Elisei wrote:
> To prepare for allowing finer control over the messages that kvmtool
> displays, replace printf() and fprintf() with the pr_* macros.
> 
> Minor changes were made to fix coding style issues that were pet peeves for
> the author. And use pr_err() in kvm_cpu__init() instead of pr_warning() for
> fatal errors.
> 
> Also, fix the message when printing the exit code for KVM_EXIT_UNKNOWN by
> removing the '0x' part, because it's printing a decimal number, not a
> hexadecimal one (the format specifier is %llu, not %llx).
> 
> Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>
> ---
> Changelog:
> 
> - Use pr_err() to directly replace fprintf() in kernel_usage_with_options()
>    instead of concatening the kernel locations.
> - Removed the '0x' from the "KVM exit code: 0x%llu" message in kvm_cpu_thread()
>    because the number is decimal (it's %llu, not %llx).
> - Reverted the changes to kvm__emulate_mmio() and debug_io () because those
>    messages are displayed with --debug-mmio, respectively --debug-ioport, and
>    --loglevel hiding them would have been counter-intuitive.
> - Replaced the "warning" string in kvm__emulate_mmio() with "MMIO warning", to
>    match the message from kvm__emulate_io(). And to make it clear that it isn't
>    toggled with --loglevel.
> - Removed extra spaces in virtio_compat_add_message().
> 
>   arm/gic.c       |  5 ++---
>   builtin-run.c   | 37 +++++++++++++++++++------------------
>   builtin-setup.c | 16 ++++++++--------
>   guest_compat.c  |  2 +-
>   kvm-cpu.c       | 12 ++++++------
>   mmio.c          |  2 +-
>   6 files changed, 37 insertions(+), 37 deletions(-)
> 

> diff --git a/guest_compat.c b/guest_compat.c
> index fd4704b20b16..93f9aabcd6db 100644
> --- a/guest_compat.c
> +++ b/guest_compat.c
> @@ -86,7 +86,7 @@ int compat__print_all_messages(void)
>   
>   		msg = list_first_entry(&messages, struct compat_message, list);
>   
> -		printf("\n  # KVM compatibility warning.\n\t%s\n\t%s\n",
> +		pr_warning("KVM compatibility warning.\n\t%s\n\t%s",
>   			msg->title, msg->desc);

Does this really need to be a Warning ? A user could be running a non-
Linux guest and reporting the compatibility with WARNING level makes it
a bit tricky to suppress. i.e., User may want to suppress the "virtio"
compatibility messages, without actually loosing any other important
"Warnings". With the --loglevel=warning, we don't have that capability.

There are two options here as far as I can see:

1) Convert compatibility messages to "Info"
2) Control the compatibility messages via new option, (something like we
    did here, with --nocompat [0])

[0] 
https://lore.kernel.org/all/20230127113932.166089-5-suzuki.poulose@arm.com/


Suzuki

Re: [PATCH kvmtool v2 2/4] Replace printf/fprintf with pr_* macros

[Alexandru Elisei]

Hi Suzuki,

On Wed, Jul 12, 2023 at 05:26:24PM +0100, Suzuki K Poulose wrote:
> Hi Alexandru
> 
> On 07/07/2023 16:11, Alexandru Elisei wrote:
> > To prepare for allowing finer control over the messages that kvmtool
> > displays, replace printf() and fprintf() with the pr_* macros.
> > 
> > Minor changes were made to fix coding style issues that were pet peeves for
> > the author. And use pr_err() in kvm_cpu__init() instead of pr_warning() for
> > fatal errors.
> > 
> > Also, fix the message when printing the exit code for KVM_EXIT_UNKNOWN by
> > removing the '0x' part, because it's printing a decimal number, not a
> > hexadecimal one (the format specifier is %llu, not %llx).
> > 
> > Signed-off-by: Alexandru Elisei <alexandru.elisei@arm.com>
> > ---
> > Changelog:
> > 
> > - Use pr_err() to directly replace fprintf() in kernel_usage_with_options()
> >    instead of concatening the kernel locations.
> > - Removed the '0x' from the "KVM exit code: 0x%llu" message in kvm_cpu_thread()
> >    because the number is decimal (it's %llu, not %llx).
> > - Reverted the changes to kvm__emulate_mmio() and debug_io () because those
> >    messages are displayed with --debug-mmio, respectively --debug-ioport, and
> >    --loglevel hiding them would have been counter-intuitive.
> > - Replaced the "warning" string in kvm__emulate_mmio() with "MMIO warning", to
> >    match the message from kvm__emulate_io(). And to make it clear that it isn't
> >    toggled with --loglevel.
> > - Removed extra spaces in virtio_compat_add_message().
> > 
> >   arm/gic.c       |  5 ++---
> >   builtin-run.c   | 37 +++++++++++++++++++------------------
> >   builtin-setup.c | 16 ++++++++--------
> >   guest_compat.c  |  2 +-
> >   kvm-cpu.c       | 12 ++++++------
> >   mmio.c          |  2 +-
> >   6 files changed, 37 insertions(+), 37 deletions(-)
> > 
> 
> > diff --git a/guest_compat.c b/guest_compat.c
> > index fd4704b20b16..93f9aabcd6db 100644
> > --- a/guest_compat.c
> > +++ b/guest_compat.c
> > @@ -86,7 +86,7 @@ int compat__print_all_messages(void)
> >   		msg = list_first_entry(&messages, struct compat_message, list);
> > -		printf("\n  # KVM compatibility warning.\n\t%s\n\t%s\n",
> > +		pr_warning("KVM compatibility warning.\n\t%s\n\t%s",
> >   			msg->title, msg->desc);
> 
> Does this really need to be a Warning ? A user could be running a non-
> Linux guest and reporting the compatibility with WARNING level makes it
> a bit tricky to suppress. i.e., User may want to suppress the "virtio"
> compatibility messages, without actually loosing any other important
> "Warnings". With the --loglevel=warning, we don't have that capability.

That sounds reasonable.

> 
> There are two options here as far as I can see:
> 
> 1) Convert compatibility messages to "Info"
> 2) Control the compatibility messages via new option, (something like we
>    did here, with --nocompat [0])

Out of the two, I would rather go the "info" route, so there aren't two
separate methods to disable kvmtool messages, via --loglevel and via
--nocompat.

I'll prepare a patch.

Thanks,
Alex

> 
> [0]
> https://lore.kernel.org/all/20230127113932.166089-5-suzuki.poulose@arm.com/
> 
> 
> Suzuki
>