Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
Patchew URL: https://patchew.org/QEMU/20181214105642.673-1-cferg...@redhat.com/ Hi, This series failed the docker-mingw@fedora build test. Please find the testing commands and their output below. If you have Docker installed, you can probably reproduce it locally. === TEST SCRIPT BEGIN === #!/bin/bash time make docker-test-mingw@fedora SHOW_ENV=1 J=14 === TEST SCRIPT END === CC vl.o CC tpm.o /tmp/qemu-test/src/block/sheepdog.c: In function 'find_vdi_name': /tmp/qemu-test/src/block/sheepdog.c:1239:5: error: 'strncpy' specified bound 256 equals destination size [-Werror=stringop-truncation] strncpy(buf + SD_MAX_VDI_LEN, tag, SD_MAX_VDI_TAG_LEN); ^~ cc1: all warnings being treated as errors The full log is available at http://patchew.org/logs/20181214105642.673-1-cferg...@redhat.com/testing.docker-mingw@fedora/?type=message. --- Email generated automatically by Patchew [http://patchew.org/]. Please send your feedback to patchew-de...@redhat.com
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
On Fri, Dec 14, 2018 at 11:56:42AM +0100, Christophe Fergeau wrote: > This commit adds a qemu_init_logging() helper which calls > g_log_set_default_handler() so that glib logs (g_log, g_warning, ...) > are handled similarly to other QEMU logs. This means they will get a > timestamp if timestamps are enabled, and they will go through the > monitor if one is configured. > This commit also adds a call to qemu_init_logging() to the binaries > installed by QEMU. > glib debug messages are enabled through G_MESSAGES_DEBUG similarly to > glib default log handler. > > At the moment, this change will mostly impact SPICE logging if your > spice version is >= 0.14.1. With older spice versions, this is not going > to work as expected, but will not have any ill effect, so this call is > not conditional on the SPICE version. > > Signed-off-by: Christophe Fergeau > Reviewed-by: Daniel P. Berrangé > --- > Changes since v3: > - Fixed style issue: removed 2 extra spaces before parens > (reported by checkpatch) > > bsd-user/main.c | 1 + > include/qemu/error-report.h | 2 ++ > linux-user/main.c | 1 + > qemu-img.c | 1 + > qemu-io.c | 1 + > qemu-nbd.c | 1 + > scsi/qemu-pr-helper.c | 1 + > util/qemu-error.c | 47 + > vl.c| 1 + > 9 files changed, 56 insertions(+) Reviewed-by: Stefan Hajnoczi signature.asc Description: PGP signature
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
On Tue, Jan 15, 2019 at 02:09:12PM +, Stefan Hajnoczi wrote: > > In these codepaths, I'm confident up to > > void monitor_vfprintf(FILE *stream, const char *fmt, va_list ap) > > { > > if (cur_mon && !monitor_cur_is_qmp()) { > > monitor_vprintf(cur_mon, fmt, ap); > > } else { > > vfprintf(stream, fmt, ap); > > } > > } > > > > From there, it was not obvious to me whether the monitor_vprintf > > codepath can be triggered from info/warn/error_report or not. If they > > can, I'd feel less confident that monitor_vprintf will never indirectly > > call glib log functions. > > I think we're okay because otherwise monitor_vprintf() -> > info/warn/error_report() would already be an infinite loop today. Ah good point :) Christophe signature.asc Description: PGP signature
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
On Mon, Jan 14, 2019 at 12:54:20PM +0100, Christophe Fergeau wrote: > On Fri, Jan 04, 2019 at 03:40:34PM +, Stefan Hajnoczi wrote: > > On Thu, Jan 03, 2019 at 03:14:55PM +0100, Christophe Fergeau wrote: > > > Hey, > > > > > > On Thu, Jan 03, 2019 at 10:54:25AM +, Stefan Hajnoczi wrote: > > > > On Fri, Dec 14, 2018 at 11:56:42AM +0100, Christophe Fergeau wrote: > > > > > +static void qemu_log_func(const gchar *log_domain, > > > > > + GLogLevelFlags log_level, > > > > > + const gchar *message, > > > > > + gpointer user_data) > > > > > +{ > > > > > +switch (log_level & G_LOG_LEVEL_MASK) { > > > > > +case G_LOG_LEVEL_DEBUG: > > > > > +/* Use same G_MESSAGES_DEBUG logic as glib to enable/disable > > > > > debug > > > > > + * messages > > > > > + */ > > > > > +if (qemu_glog_domains == NULL) { > > > > > +break; > > > > > +} > > > > > +if (strcmp(qemu_glog_domains, "all") != 0 && > > > > > + (log_domain == NULL || !strstr(qemu_glog_domains, > > > > > log_domain))) { > > > > > +break; > > > > > +} > > > > > +/* Fall through */ > > > > > +case G_LOG_LEVEL_INFO: > > > > > +/* Fall through */ > > > > > +case G_LOG_LEVEL_MESSAGE: > > > > > +info_report("%s: %s", log_domain, message); > > > > > > > > QEMU itself uses glib, so what happens if *_report() emit more log > > > > messages? Can this result in an infinite loop? > > > > > > If *_report try to output messages through the g_log API, glib will > > > catch it and will abort, so not an infinite loop, but not a > > > desirable outcome either. > > > > > > Some low-level logging functions which are going to dump the message > > > without glib (or using g_log_default_handler()) are needed. > > > The timestamping/prepending of 'error:', 'warning:' to the error message > > > is done right below *_report (in vreport) so this looked like a good > > > place for that. > > > > If you're confident that QEMU will never (indirectly) emit a glib log > > message from the *_report() code path, then I'm happy. > > In these codepaths, I'm confident up to > void monitor_vfprintf(FILE *stream, const char *fmt, va_list ap) > { > if (cur_mon && !monitor_cur_is_qmp()) { > monitor_vprintf(cur_mon, fmt, ap); > } else { > vfprintf(stream, fmt, ap); > } > } > > From there, it was not obvious to me whether the monitor_vprintf > codepath can be triggered from info/warn/error_report or not. If they > can, I'd feel less confident that monitor_vprintf will never indirectly > call glib log functions. I think we're okay because otherwise monitor_vprintf() -> info/warn/error_report() would already be an infinite loop today. Stefan signature.asc Description: PGP signature
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
On Fri, Jan 04, 2019 at 03:40:34PM +, Stefan Hajnoczi wrote: > On Thu, Jan 03, 2019 at 03:14:55PM +0100, Christophe Fergeau wrote: > > Hey, > > > > On Thu, Jan 03, 2019 at 10:54:25AM +, Stefan Hajnoczi wrote: > > > On Fri, Dec 14, 2018 at 11:56:42AM +0100, Christophe Fergeau wrote: > > > > +static void qemu_log_func(const gchar *log_domain, > > > > + GLogLevelFlags log_level, > > > > + const gchar *message, > > > > + gpointer user_data) > > > > +{ > > > > +switch (log_level & G_LOG_LEVEL_MASK) { > > > > +case G_LOG_LEVEL_DEBUG: > > > > +/* Use same G_MESSAGES_DEBUG logic as glib to enable/disable > > > > debug > > > > + * messages > > > > + */ > > > > +if (qemu_glog_domains == NULL) { > > > > +break; > > > > +} > > > > +if (strcmp(qemu_glog_domains, "all") != 0 && > > > > + (log_domain == NULL || !strstr(qemu_glog_domains, > > > > log_domain))) { > > > > +break; > > > > +} > > > > +/* Fall through */ > > > > +case G_LOG_LEVEL_INFO: > > > > +/* Fall through */ > > > > +case G_LOG_LEVEL_MESSAGE: > > > > +info_report("%s: %s", log_domain, message); > > > > > > QEMU itself uses glib, so what happens if *_report() emit more log > > > messages? Can this result in an infinite loop? > > > > If *_report try to output messages through the g_log API, glib will > > catch it and will abort, so not an infinite loop, but not a > > desirable outcome either. > > > > Some low-level logging functions which are going to dump the message > > without glib (or using g_log_default_handler()) are needed. > > The timestamping/prepending of 'error:', 'warning:' to the error message > > is done right below *_report (in vreport) so this looked like a good > > place for that. > > If you're confident that QEMU will never (indirectly) emit a glib log > message from the *_report() code path, then I'm happy. In these codepaths, I'm confident up to void monitor_vfprintf(FILE *stream, const char *fmt, va_list ap) { if (cur_mon && !monitor_cur_is_qmp()) { monitor_vprintf(cur_mon, fmt, ap); } else { vfprintf(stream, fmt, ap); } } From there, it was not obvious to me whether the monitor_vprintf codepath can be triggered from info/warn/error_report or not. If they can, I'd feel less confident that monitor_vprintf will never indirectly call glib log functions. Christophe > > Stefan signature.asc Description: PGP signature
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
On Thu, Jan 03, 2019 at 03:14:55PM +0100, Christophe Fergeau wrote: > Hey, > > On Thu, Jan 03, 2019 at 10:54:25AM +, Stefan Hajnoczi wrote: > > On Fri, Dec 14, 2018 at 11:56:42AM +0100, Christophe Fergeau wrote: > > > +static void qemu_log_func(const gchar *log_domain, > > > + GLogLevelFlags log_level, > > > + const gchar *message, > > > + gpointer user_data) > > > +{ > > > +switch (log_level & G_LOG_LEVEL_MASK) { > > > +case G_LOG_LEVEL_DEBUG: > > > +/* Use same G_MESSAGES_DEBUG logic as glib to enable/disable > > > debug > > > + * messages > > > + */ > > > +if (qemu_glog_domains == NULL) { > > > +break; > > > +} > > > +if (strcmp(qemu_glog_domains, "all") != 0 && > > > + (log_domain == NULL || !strstr(qemu_glog_domains, > > > log_domain))) { > > > +break; > > > +} > > > +/* Fall through */ > > > +case G_LOG_LEVEL_INFO: > > > +/* Fall through */ > > > +case G_LOG_LEVEL_MESSAGE: > > > +info_report("%s: %s", log_domain, message); > > > > QEMU itself uses glib, so what happens if *_report() emit more log > > messages? Can this result in an infinite loop? > > If *_report try to output messages through the g_log API, glib will > catch it and will abort, so not an infinite loop, but not a > desirable outcome either. > > Some low-level logging functions which are going to dump the message > without glib (or using g_log_default_handler()) are needed. > The timestamping/prepending of 'error:', 'warning:' to the error message > is done right below *_report (in vreport) so this looked like a good > place for that. If you're confident that QEMU will never (indirectly) emit a glib log message from the *_report() code path, then I'm happy. Stefan signature.asc Description: PGP signature
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
Hey, On Thu, Jan 03, 2019 at 10:54:25AM +, Stefan Hajnoczi wrote: > On Fri, Dec 14, 2018 at 11:56:42AM +0100, Christophe Fergeau wrote: > > +static void qemu_log_func(const gchar *log_domain, > > + GLogLevelFlags log_level, > > + const gchar *message, > > + gpointer user_data) > > +{ > > +switch (log_level & G_LOG_LEVEL_MASK) { > > +case G_LOG_LEVEL_DEBUG: > > +/* Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug > > + * messages > > + */ > > +if (qemu_glog_domains == NULL) { > > +break; > > +} > > +if (strcmp(qemu_glog_domains, "all") != 0 && > > + (log_domain == NULL || !strstr(qemu_glog_domains, log_domain))) { > > +break; > > +} > > +/* Fall through */ > > +case G_LOG_LEVEL_INFO: > > +/* Fall through */ > > +case G_LOG_LEVEL_MESSAGE: > > +info_report("%s: %s", log_domain, message); > > QEMU itself uses glib, so what happens if *_report() emit more log > messages? Can this result in an infinite loop? If *_report try to output messages through the g_log API, glib will catch it and will abort, so not an infinite loop, but not a desirable outcome either. Some low-level logging functions which are going to dump the message without glib (or using g_log_default_handler()) are needed. The timestamping/prepending of 'error:', 'warning:' to the error message is done right below *_report (in vreport) so this looked like a good place for that. Christophe signature.asc Description: PGP signature
Re: [Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
On Fri, Dec 14, 2018 at 11:56:42AM +0100, Christophe Fergeau wrote: > +static void qemu_log_func(const gchar *log_domain, > + GLogLevelFlags log_level, > + const gchar *message, > + gpointer user_data) > +{ > +switch (log_level & G_LOG_LEVEL_MASK) { > +case G_LOG_LEVEL_DEBUG: > +/* Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug > + * messages > + */ > +if (qemu_glog_domains == NULL) { > +break; > +} > +if (strcmp(qemu_glog_domains, "all") != 0 && > + (log_domain == NULL || !strstr(qemu_glog_domains, log_domain))) { > +break; > +} > +/* Fall through */ > +case G_LOG_LEVEL_INFO: > +/* Fall through */ > +case G_LOG_LEVEL_MESSAGE: > +info_report("%s: %s", log_domain, message); QEMU itself uses glib, so what happens if *_report() emit more log messages? Can this result in an infinite loop? Stefan signature.asc Description: PGP signature
[Qemu-devel] [PATCH v4] log: Make glib logging go through QEMU
This commit adds a qemu_init_logging() helper which calls g_log_set_default_handler() so that glib logs (g_log, g_warning, ...) are handled similarly to other QEMU logs. This means they will get a timestamp if timestamps are enabled, and they will go through the monitor if one is configured. This commit also adds a call to qemu_init_logging() to the binaries installed by QEMU. glib debug messages are enabled through G_MESSAGES_DEBUG similarly to glib default log handler. At the moment, this change will mostly impact SPICE logging if your spice version is >= 0.14.1. With older spice versions, this is not going to work as expected, but will not have any ill effect, so this call is not conditional on the SPICE version. Signed-off-by: Christophe Fergeau Reviewed-by: Daniel P. Berrangé --- Changes since v3: - Fixed style issue: removed 2 extra spaces before parens (reported by checkpatch) bsd-user/main.c | 1 + include/qemu/error-report.h | 2 ++ linux-user/main.c | 1 + qemu-img.c | 1 + qemu-io.c | 1 + qemu-nbd.c | 1 + scsi/qemu-pr-helper.c | 1 + util/qemu-error.c | 47 + vl.c| 1 + 9 files changed, 56 insertions(+) diff --git a/bsd-user/main.c b/bsd-user/main.c index 0d3156974c..96787b27ef 100644 --- a/bsd-user/main.c +++ b/bsd-user/main.c @@ -743,6 +743,7 @@ int main(int argc, char **argv) if (argc <= 1) usage(); +qemu_init_logging(); module_call_init(MODULE_INIT_TRACE); qemu_init_cpu_list(); module_call_init(MODULE_INIT_QOM); diff --git a/include/qemu/error-report.h b/include/qemu/error-report.h index 0a8d9cc9ea..2852e9df2a 100644 --- a/include/qemu/error-report.h +++ b/include/qemu/error-report.h @@ -49,6 +49,8 @@ bool error_report_once_cond(bool *printed, const char *fmt, ...) bool warn_report_once_cond(bool *printed, const char *fmt, ...) GCC_FMT_ATTR(2, 3); +void qemu_init_logging(void); + /* * Similar to error_report(), except it prints the message just once. * Return true when it prints, false otherwise. diff --git a/linux-user/main.c b/linux-user/main.c index 923cbb753a..de9ff462e9 100644 --- a/linux-user/main.c +++ b/linux-user/main.c @@ -600,6 +600,7 @@ int main(int argc, char **argv, char **envp) int ret; int execfd; +qemu_init_logging(); module_call_init(MODULE_INIT_TRACE); qemu_init_cpu_list(); module_call_init(MODULE_INIT_QOM); diff --git a/qemu-img.c b/qemu-img.c index ad04f59565..9214392565 100644 --- a/qemu-img.c +++ b/qemu-img.c @@ -4912,6 +4912,7 @@ int main(int argc, char **argv) signal(SIGPIPE, SIG_IGN); #endif +qemu_init_logging(); module_call_init(MODULE_INIT_TRACE); error_set_progname(argv[0]); qemu_init_exec_dir(argv[0]); diff --git a/qemu-io.c b/qemu-io.c index 6df7731af4..ad38d12e68 100644 --- a/qemu-io.c +++ b/qemu-io.c @@ -524,6 +524,7 @@ int main(int argc, char **argv) signal(SIGPIPE, SIG_IGN); #endif +qemu_init_logging(); module_call_init(MODULE_INIT_TRACE); progname = g_path_get_basename(argv[0]); qemu_init_exec_dir(argv[0]); diff --git a/qemu-nbd.c b/qemu-nbd.c index ca7109652e..2cac038230 100644 --- a/qemu-nbd.c +++ b/qemu-nbd.c @@ -570,6 +570,7 @@ int main(int argc, char **argv) signal(SIGPIPE, SIG_IGN); #endif +qemu_init_logging(); module_call_init(MODULE_INIT_TRACE); qcrypto_init(_fatal); diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c index e7af637232..523f8b237c 100644 --- a/scsi/qemu-pr-helper.c +++ b/scsi/qemu-pr-helper.c @@ -895,6 +895,7 @@ int main(int argc, char **argv) signal(SIGPIPE, SIG_IGN); +qemu_init_logging(); module_call_init(MODULE_INIT_TRACE); module_call_init(MODULE_INIT_QOM); qemu_add_opts(_trace_opts); diff --git a/util/qemu-error.c b/util/qemu-error.c index fcbe8a1f74..1118ed4695 100644 --- a/util/qemu-error.c +++ b/util/qemu-error.c @@ -345,3 +345,50 @@ bool warn_report_once_cond(bool *printed, const char *fmt, ...) va_end(ap); return true; } + +static char *qemu_glog_domains; + +static void qemu_log_func(const gchar *log_domain, + GLogLevelFlags log_level, + const gchar *message, + gpointer user_data) +{ +switch (log_level & G_LOG_LEVEL_MASK) { +case G_LOG_LEVEL_DEBUG: +/* Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug + * messages + */ +if (qemu_glog_domains == NULL) { +break; +} +if (strcmp(qemu_glog_domains, "all") != 0 && + (log_domain == NULL || !strstr(qemu_glog_domains, log_domain))) { +break; +} +/* Fall through */ +case G_LOG_LEVEL_INFO: +/* Fall through */ +case G_LOG_LEVEL_MESSAGE: +info_report("%s: %s", log_domain, message); +break; +