[PATCH v3] Add VM info to improve error log message for qemu monitor

[Ani Sinha]

On Tue, 4 Jan 2022, Rohit Kumar wrote:

> This change adds the domain name in the error and debug logs during
> monitor IO processing so that we may infer which VM experienced
> errors such as IO or socket hangup. This may help in debugging
> monitor IO errors.

LGTM. If you wish you can add a comment why the new member domainName in
qemuMonitor stuct was essential.

>
> Signed-off-by: Rohit Kumar <rohit.kumar3 at nutanix.com>

Reviewed-by: Ani Sinha <ani at anisinha.ca>

> ---
>  src/qemu/qemu_monitor.c | 36 +++++++++++++++++++++---------------
>  1 file changed, 21 insertions(+), 15 deletions(-)
>
> diff --git a/src/qemu/qemu_monitor.c b/src/qemu/qemu_monitor.c
> index dda6ae9796..2b4582578a 100644
> --- a/src/qemu/qemu_monitor.c
> +++ b/src/qemu/qemu_monitor.c
> @@ -80,6 +80,7 @@ struct _qemuMonitor {
>      GSource *watch;
>
>      virDomainObj *vm;
> +    char *domainName;
>
>      qemuMonitorCallbacks *cb;
>      void *callbackOpaque;
> @@ -243,6 +244,7 @@ qemuMonitorDispose(void *obj)
>      virCondDestroy(&mon->notify);
>      g_free(mon->buffer);
>      g_free(mon->balloonpath);
> +    g_free(mon->domainName);
>  }
>
>
> @@ -583,8 +585,8 @@ qemuMonitorIO(GSocket *socket G_GNUC_UNUSED,
>
>          if (!error && !mon->goteof &&
>              cond & G_IO_ERR) {
> -            virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
> -                           _("Invalid file descriptor while waiting for monitor"));
> +            virReportError(VIR_ERR_INTERNAL_ERROR,
> +                           _("Invalid file descriptor while waiting for monitor (vm='%s')"), mon->domainName);
>              mon->goteof = true;
>          }
>      }
> @@ -609,13 +611,14 @@ qemuMonitorIO(GSocket *socket G_GNUC_UNUSED,
>              virResetLastError();
>          } else {
>              if (virGetLastErrorCode() == VIR_ERR_OK && !mon->goteof)
> -                virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
> -                               _("Error while processing monitor IO"));
> +                virReportError(VIR_ERR_INTERNAL_ERROR,
> +                               _("Error while processing monitor IO (vm='%s')"), mon->domainName);
>              virCopyLastError(&mon->lastError);
>              virResetLastError();
>          }
>
> -        VIR_DEBUG("Error on monitor %s", NULLSTR(mon->lastError.message));
> +        VIR_DEBUG("Error on monitor %s mon=%p vm=%p name=%s",
> +                  NULLSTR(mon->lastError.message), mon, mon->vm, mon->domainName);
>          /* If IO process resulted in an error & we have a message,
>           * then wakeup that waiter */
>          if (mon->msg && !mon->msg->finished) {
> @@ -636,7 +639,8 @@ qemuMonitorIO(GSocket *socket G_GNUC_UNUSED,
>          /* Make sure anyone waiting wakes up now */
>          virCondSignal(&mon->notify);
>          virObjectUnlock(mon);
> -        VIR_DEBUG("Triggering EOF callback");
> +        VIR_DEBUG("Triggering EOF callback mon=%p vm=%p name=%s",
> +                  mon, mon->vm, mon->domainName);
>          (eofNotify)(mon, vm, mon->callbackOpaque);
>          virObjectUnref(mon);
>      } else if (error) {
> @@ -646,7 +650,8 @@ qemuMonitorIO(GSocket *socket G_GNUC_UNUSED,
>          /* Make sure anyone waiting wakes up now */
>          virCondSignal(&mon->notify);
>          virObjectUnlock(mon);
> -        VIR_DEBUG("Triggering error callback");
> +        VIR_DEBUG("Triggering error callback mon=%p vm=%p name=%s",
> +                  mon, mon->vm, mon->domainName);
>          (errorNotify)(mon, vm, mon->callbackOpaque);
>          virObjectUnref(mon);
>      } else {
> @@ -694,6 +699,7 @@ qemuMonitorOpenInternal(virDomainObj *vm,
>      mon->fd = fd;
>      mon->context = g_main_context_ref(context);
>      mon->vm = virObjectRef(vm);
> +    mon->domainName = g_strdup(NULLSTR(vm->def->name));
>      mon->waitGreeting = true;
>      mon->cb = cb;
>      mon->callbackOpaque = opaque;
> @@ -935,14 +941,14 @@ qemuMonitorSend(qemuMonitor *mon,
>
>      /* Check whether qemu quit unexpectedly */
>      if (mon->lastError.code != VIR_ERR_OK) {
> -        VIR_DEBUG("Attempt to send command while error is set %s",
> -                  NULLSTR(mon->lastError.message));
> +        VIR_DEBUG("Attempt to send command while error is set %s mon=%p vm=%p name=%s",
> +                  NULLSTR(mon->lastError.message), mon, mon->vm, mon->domainName);
>          virSetError(&mon->lastError);
>          return -1;
>      }
>      if (mon->goteof) {
> -        virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
> -                       _("End of file from qemu monitor"));
> +        virReportError(VIR_ERR_INTERNAL_ERROR,
> +                       _("End of file from qemu monitor (vm='%s')"), mon->domainName);
>          return -1;
>      }
>
> @@ -955,15 +961,15 @@ qemuMonitorSend(qemuMonitor *mon,
>
>      while (!mon->msg->finished) {
>          if (virCondWait(&mon->notify, &mon->parent.lock) < 0) {
> -            virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
> -                           _("Unable to wait on monitor condition"));
> +            virReportError(VIR_ERR_INTERNAL_ERROR,
> +                           _("Unable to wait on monitor condition (vm='%s')"), mon->domainName);
>              goto cleanup;
>          }
>      }
>
>      if (mon->lastError.code != VIR_ERR_OK) {
> -        VIR_DEBUG("Send command resulted in error %s",
> -                  NULLSTR(mon->lastError.message));
> +        VIR_DEBUG("Send command resulted in error %s mon=%p vm=%p name=%s",
> +                  NULLSTR(mon->lastError.message), mon, mon->vm, mon->domainName);
>          virSetError(&mon->lastError);
>          goto cleanup;
>      }
> --
> 2.25.1
>
>