| Message ID | 1444639295-6588-1-git-send-email-den@openvz.org |
|---|---|
| State | New |
| Headers | show |
On 10/12/2015 11:41 AM, Denis V. Lunev wrote: > From: Pavel Butsykin <pbutsykin@virtuozzo.com> > > This log would be very welcome for long-term diagnostics of the system > in the production. This log is at least necessary to understand what > has been happened on the system and to identify issues at higher-level > subsystems (libvirt, etc). > > Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com> > Signed-off-by: Denis V. Lunev <den@openvz.org> > CC: Markus Armbruster <armbru@redhat.com> > CC: Luiz Capitulino <lcapitulino@redhat.com> > CC: Eric Blake <eblake@redhat.com> > --- > include/qemu/log.h | 1 + > monitor.c | 4 ++++ > qemu-log.c | 1 + > 3 files changed, 6 insertions(+) > > diff --git a/include/qemu/log.h b/include/qemu/log.h > index f880e66..dfb587e 100644 > --- a/include/qemu/log.h > +++ b/include/qemu/log.h > @@ -41,6 +41,7 @@ static inline bool qemu_log_enabled(void) > #define LOG_UNIMP (1 << 10) > #define LOG_GUEST_ERROR (1 << 11) > #define CPU_LOG_MMU (1 << 12) > +#define LOG_CMD (1 << 13) > > /* Returns true if a bit is set in the current loglevel mask > */ > diff --git a/monitor.c b/monitor.c > index 4f1ba2f..a22a798 100644 > --- a/monitor.c > +++ b/monitor.c > @@ -2848,6 +2848,8 @@ static void handle_hmp_command(Monitor *mon, const char *cmdline) > QDict *qdict; > const mon_cmd_t *cmd; > > + qemu_log_mask(LOG_CMD, "hmp \"%s\" requested\n", cmdline); > + > cmd = monitor_parse_command(mon, &cmdline, mon->cmd_table); > if (!cmd) { > return; > @@ -3822,6 +3824,8 @@ static void handle_qmp_command(JSONMessageParser *parser, QList *tokens) > error_setg(&local_err, QERR_JSON_PARSING); > goto err_out; > } > + qemu_log_mask(LOG_CMD, "qmp \"%s\" requested\n", > + qobject_to_json(obj)->string); it seems that QString here is leaked > > input = qmp_check_input_obj(obj, &local_err); > if (!input) { > diff --git a/qemu-log.c b/qemu-log.c > index 13f3813..66b15ec 100644 > --- a/qemu-log.c > +++ b/qemu-log.c > @@ -119,6 +119,7 @@ const QEMULogItem qemu_log_items[] = { > { LOG_GUEST_ERROR, "guest_errors", > "log when the guest OS does something invalid (eg accessing a\n" > "non-existent register)" }, > + { LOG_CMD, "cmd", "log the hmp/qmp commands execution" }, > { 0, NULL, NULL }, > }; >
On 10/12/2015 02:41 AM, Denis V. Lunev wrote: > From: Pavel Butsykin <pbutsykin@virtuozzo.com> > > This log would be very welcome for long-term diagnostics of the system > in the production. This log is at least necessary to understand what > has been happened on the system and to identify issues at higher-level > subsystems (libvirt, etc). > > Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com> > Signed-off-by: Denis V. Lunev <den@openvz.org> > CC: Markus Armbruster <armbru@redhat.com> > CC: Luiz Capitulino <lcapitulino@redhat.com> > CC: Eric Blake <eblake@redhat.com> > --- > @@ -3822,6 +3824,8 @@ static void handle_qmp_command(JSONMessageParser *parser, QList *tokens) > error_setg(&local_err, QERR_JSON_PARSING); > goto err_out; > } > + qemu_log_mask(LOG_CMD, "qmp \"%s\" requested\n", > + qobject_to_json(obj)->string); > In addition to the leak already pointed out, qobject_to_json() can be expensive, and it looks like we are doing that work unconditionally even if the logging is not turned on. Is there a way to optimize so that the conversion is only done when logging is enabled?
On 10/12/2015 04:49 PM, Eric Blake wrote: > On 10/12/2015 02:41 AM, Denis V. Lunev wrote: >> From: Pavel Butsykin <pbutsykin@virtuozzo.com> >> >> This log would be very welcome for long-term diagnostics of the system >> in the production. This log is at least necessary to understand what >> has been happened on the system and to identify issues at higher-level >> subsystems (libvirt, etc). >> >> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com> >> Signed-off-by: Denis V. Lunev <den@openvz.org> >> CC: Markus Armbruster <armbru@redhat.com> >> CC: Luiz Capitulino <lcapitulino@redhat.com> >> CC: Eric Blake <eblake@redhat.com> >> --- >> @@ -3822,6 +3824,8 @@ static void handle_qmp_command(JSONMessageParser *parser, QList *tokens) >> error_setg(&local_err, QERR_JSON_PARSING); >> goto err_out; >> } >> + qemu_log_mask(LOG_CMD, "qmp \"%s\" requested\n", >> + qobject_to_json(obj)->string); >> > In addition to the leak already pointed out, qobject_to_json() can be > expensive, and it looks like we are doing that work unconditionally even > if the logging is not turned on. Is there a way to optimize so that the > conversion is only done when logging is enabled? > this seems quite reasonable. Will it be good if we'll change logging implementation to use macros, something like #define qemu_log_mask(int mask, const char *ftp, ...) \ do { \ va_list ap; \ \ if (!(qemu_loglevel & mask) || !qemu_logfile) {\ break;\ }\ qemu_log(ftp, __VA_ARGS__); \ } while (0) This IMHO makes sense even out of the scope of this patch. Den
On Mon, 12 Oct 2015 11:41:35 +0300 "Denis V. Lunev" <den@openvz.org> wrote: > From: Pavel Butsykin <pbutsykin@virtuozzo.com> > > This log would be very welcome for long-term diagnostics of the system > in the production. This log is at least necessary to understand what > has been happened on the system and to identify issues at higher-level > subsystems (libvirt, etc). This is good to have, and probably we should have had it since day one. But I have the following considerations: - libvirt would need support for this to use it the way you describe, although libvirt already has its logging facility (well, one could wrap qemu in bash and pass this by default but this is not ideal) - A true logging facility would also log responses and events - I don't think it's important to log HMP > > Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com> > Signed-off-by: Denis V. Lunev <den@openvz.org> > CC: Markus Armbruster <armbru@redhat.com> > CC: Luiz Capitulino <lcapitulino@redhat.com> > CC: Eric Blake <eblake@redhat.com> > --- > include/qemu/log.h | 1 + > monitor.c | 4 ++++ > qemu-log.c | 1 + > 3 files changed, 6 insertions(+) > > diff --git a/include/qemu/log.h b/include/qemu/log.h > index f880e66..dfb587e 100644 > --- a/include/qemu/log.h > +++ b/include/qemu/log.h > @@ -41,6 +41,7 @@ static inline bool qemu_log_enabled(void) > #define LOG_UNIMP (1 << 10) > #define LOG_GUEST_ERROR (1 << 11) > #define CPU_LOG_MMU (1 << 12) > +#define LOG_CMD (1 << 13) > > /* Returns true if a bit is set in the current loglevel mask > */ > diff --git a/monitor.c b/monitor.c > index 4f1ba2f..a22a798 100644 > --- a/monitor.c > +++ b/monitor.c > @@ -2848,6 +2848,8 @@ static void handle_hmp_command(Monitor *mon, const char *cmdline) > QDict *qdict; > const mon_cmd_t *cmd; > > + qemu_log_mask(LOG_CMD, "hmp \"%s\" requested\n", cmdline); > + > cmd = monitor_parse_command(mon, &cmdline, mon->cmd_table); > if (!cmd) { > return; > @@ -3822,6 +3824,8 @@ static void handle_qmp_command(JSONMessageParser *parser, QList *tokens) > error_setg(&local_err, QERR_JSON_PARSING); > goto err_out; > } > + qemu_log_mask(LOG_CMD, "qmp \"%s\" requested\n", > + qobject_to_json(obj)->string); > > input = qmp_check_input_obj(obj, &local_err); > if (!input) { > diff --git a/qemu-log.c b/qemu-log.c > index 13f3813..66b15ec 100644 > --- a/qemu-log.c > +++ b/qemu-log.c > @@ -119,6 +119,7 @@ const QEMULogItem qemu_log_items[] = { > { LOG_GUEST_ERROR, "guest_errors", > "log when the guest OS does something invalid (eg accessing a\n" > "non-existent register)" }, > + { LOG_CMD, "cmd", "log the hmp/qmp commands execution" }, > { 0, NULL, NULL }, > }; >
On 10/13/2015 04:05 PM, Luiz Capitulino wrote: > On Mon, 12 Oct 2015 11:41:35 +0300 > "Denis V. Lunev" <den@openvz.org> wrote: > >> From: Pavel Butsykin <pbutsykin@virtuozzo.com> >> >> This log would be very welcome for long-term diagnostics of the system >> in the production. This log is at least necessary to understand what >> has been happened on the system and to identify issues at higher-level >> subsystems (libvirt, etc). > This is good to have, and probably we should have had it since day one. > But I have the following considerations: > > - libvirt would need support for this to use it the way you describe, > although libvirt already has its logging facility (well, one could > wrap qemu in bash and pass this by default but this is not ideal) OK, I'll add task to the queue for our libvirt guys > - A true logging facility would also log responses and events responses are done alreade internally in the scope of preparations to the next submission, events are missed. Thank you for pointing this out > - I don't think it's important to log HMP OK, but I do not that that this will hurt us :) Den >> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com> >> Signed-off-by: Denis V. Lunev <den@openvz.org> >> CC: Markus Armbruster <armbru@redhat.com> >> CC: Luiz Capitulino <lcapitulino@redhat.com> >> CC: Eric Blake <eblake@redhat.com> >> --- >> include/qemu/log.h | 1 + >> monitor.c | 4 ++++ >> qemu-log.c | 1 + >> 3 files changed, 6 insertions(+) >> >> diff --git a/include/qemu/log.h b/include/qemu/log.h >> index f880e66..dfb587e 100644 >> --- a/include/qemu/log.h >> +++ b/include/qemu/log.h >> @@ -41,6 +41,7 @@ static inline bool qemu_log_enabled(void) >> #define LOG_UNIMP (1 << 10) >> #define LOG_GUEST_ERROR (1 << 11) >> #define CPU_LOG_MMU (1 << 12) >> +#define LOG_CMD (1 << 13) >> >> /* Returns true if a bit is set in the current loglevel mask >> */ >> diff --git a/monitor.c b/monitor.c >> index 4f1ba2f..a22a798 100644 >> --- a/monitor.c >> +++ b/monitor.c >> @@ -2848,6 +2848,8 @@ static void handle_hmp_command(Monitor *mon, const char *cmdline) >> QDict *qdict; >> const mon_cmd_t *cmd; >> >> + qemu_log_mask(LOG_CMD, "hmp \"%s\" requested\n", cmdline); >> + >> cmd = monitor_parse_command(mon, &cmdline, mon->cmd_table); >> if (!cmd) { >> return; >> @@ -3822,6 +3824,8 @@ static void handle_qmp_command(JSONMessageParser *parser, QList *tokens) >> error_setg(&local_err, QERR_JSON_PARSING); >> goto err_out; >> } >> + qemu_log_mask(LOG_CMD, "qmp \"%s\" requested\n", >> + qobject_to_json(obj)->string); >> >> input = qmp_check_input_obj(obj, &local_err); >> if (!input) { >> diff --git a/qemu-log.c b/qemu-log.c >> index 13f3813..66b15ec 100644 >> --- a/qemu-log.c >> +++ b/qemu-log.c >> @@ -119,6 +119,7 @@ const QEMULogItem qemu_log_items[] = { >> { LOG_GUEST_ERROR, "guest_errors", >> "log when the guest OS does something invalid (eg accessing a\n" >> "non-existent register)" }, >> + { LOG_CMD, "cmd", "log the hmp/qmp commands execution" }, >> { 0, NULL, NULL }, >> }; >>
diff --git a/include/qemu/log.h b/include/qemu/log.h index f880e66..dfb587e 100644 --- a/include/qemu/log.h +++ b/include/qemu/log.h @@ -41,6 +41,7 @@ static inline bool qemu_log_enabled(void) #define LOG_UNIMP (1 << 10) #define LOG_GUEST_ERROR (1 << 11) #define CPU_LOG_MMU (1 << 12) +#define LOG_CMD (1 << 13) /* Returns true if a bit is set in the current loglevel mask */ diff --git a/monitor.c b/monitor.c index 4f1ba2f..a22a798 100644 --- a/monitor.c +++ b/monitor.c @@ -2848,6 +2848,8 @@ static void handle_hmp_command(Monitor *mon, const char *cmdline) QDict *qdict; const mon_cmd_t *cmd; + qemu_log_mask(LOG_CMD, "hmp \"%s\" requested\n", cmdline); + cmd = monitor_parse_command(mon, &cmdline, mon->cmd_table); if (!cmd) { return; @@ -3822,6 +3824,8 @@ static void handle_qmp_command(JSONMessageParser *parser, QList *tokens) error_setg(&local_err, QERR_JSON_PARSING); goto err_out; } + qemu_log_mask(LOG_CMD, "qmp \"%s\" requested\n", + qobject_to_json(obj)->string); input = qmp_check_input_obj(obj, &local_err); if (!input) { diff --git a/qemu-log.c b/qemu-log.c index 13f3813..66b15ec 100644 --- a/qemu-log.c +++ b/qemu-log.c @@ -119,6 +119,7 @@ const QEMULogItem qemu_log_items[] = { { LOG_GUEST_ERROR, "guest_errors", "log when the guest OS does something invalid (eg accessing a\n" "non-existent register)" }, + { LOG_CMD, "cmd", "log the hmp/qmp commands execution" }, { 0, NULL, NULL }, };