1. Patchew
  2. Libvirt
  3. View series

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

Rohit Kumar posted 1 patch 2 years, 3 months ago
Test syntax-check failed
Patches applied successfully (tree, apply log)
git fetch https://github.com/patchew-project/libvirt tags/patchew/20220104124311.719228-1-rohit.kumar3@nutanix.com
src/qemu/qemu_monitor.c | 36 +++++++++++++++++++++---------------
1 file changed, 21 insertions(+), 15 deletions(-)
[PATCH v3] Add VM info to improve error log message for qemu monitor
Posted by Rohit Kumar 2 years, 3 months ago 
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.

Signed-off-by: Rohit Kumar <rohit.kumar3@nutanix.com>
---
 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
Re: [PATCH v3] Add VM info to improve error log message for qemu monitor
Posted by Peter Krempa 2 years, 3 months ago 
On Tue, Jan 04, 2022 at 04:43:11 -0800, 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.
> 
> Signed-off-by: Rohit Kumar <rohit.kumar3@nutanix.com>
> ---
>  src/qemu/qemu_monitor.c | 36 +++++++++++++++++++++---------------
>  1 file changed, 21 insertions(+), 15 deletions(-)

Reviewed-by: Peter Krempa <pkrempa@redhat.com>

I'll push the commit in a while.
Re: [PATCH v3] Add VM info to improve error log message for qemu monitor
Posted by Ani Sinha 2 years, 3 months ago 

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@nutanix.com>

Reviewed-by: Ani Sinha <ani@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
>
>
Re: [PATCH v3] Add VM info to improve error log message for qemu monitor
Posted by Rohit Kumar 2 years, 3 months ago 
On 04/01/22 6:27 pm, Ani Sinha wrote:
>
> 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.
Sure. I would update it in commit message if required.
I am waiting for Peter's reviews on this patch before proceeding futher.
Thanks.
>
>> Signed-off-by: Rohit Kumar <rohit.kumar3@nutanix.com>
> Reviewed-by: Ani Sinha <ani@anisinha.ca>
Thanks for the review, Ani.
>
>> ---
>>   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
>>
>>

Patchew 2.1-devel-0870f84

© 2016 - 2024 Red Hat, Inc.