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

2022-01-06 Thread Peter Krempa 
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 
> ---
>  src/qemu/qemu_monitor.c | 36 +---
>  1 file changed, 21 insertions(+), 15 deletions(-)

Reviewed-by: Peter Krempa 

I'll push the commit in a while.

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

2022-01-04 Thread Rohit Kumar 



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 

Reviewed-by: Ani Sinha 

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(>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(>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(>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(>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(>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(>notify, >parent.lock) < 0) {
-virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
-

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

2022-01-04 Thread 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 

Reviewed-by: Ani Sinha 

> ---
>  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(>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(>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(>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(>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(>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(>notify, >parent.lock) < 0) {
> -virReportError(VIR_ERR_INTERNAL_ERROR, "%s",
> -   _("Unable to wait on monitor

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

2022-01-04 Thread Rohit Kumar 
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 
---
 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(>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(>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(>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(>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(>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(>notify, >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