[Qemu-devel] [PATCH 0/2] qemu-char: Clean up socket reporting

[Qemu-devel] [PATCH 0/2] qemu-char: Clean up socket reporting

[minyard]

The first patch fixes some reporting issues for reconnect sockets
that fail to connect.  It prevents a constant stream of error messages,
and reports the error immediately instead of delaying it.  This
required a small restructure, but nothing big.

The second adds an error to non-blocking connect reporting.  The
error was available, it just wasn't being passed.  Hopefully this
makes the error easier to diagnose.

-corey

[Qemu-devel] [PATCH 1/2] qemu-char: Fix reconnect socket error reporting

[minyard]

From: Corey Minyard <cminyard@mvista.com>

If reconnect was set, errors wouldn't always be reported.
Fix that and also only report a connect error once until a
connection has been made.

The primary purpose of this is to tell the user that a
connection failed so they can know they need to figure out
what went wrong.  So we don't want to spew too much
out here, just enough so they know.

Signed-off-by: Corey Minyard <cminyard@mvista.com>
---
 qemu-char.c | 47 ++++++++++++++++++++++++++++++++---------------
 1 file changed, 32 insertions(+), 15 deletions(-)

diff --git a/qemu-char.c b/qemu-char.c
index 62af0ef..fb895c7 100644
--- a/qemu-char.c
+++ b/qemu-char.c
@@ -2509,6 +2509,7 @@ typedef struct {
 
     guint reconnect_timer;
     int64_t reconnect_time;
+    bool connect_err_reported;
 } TCPCharDriver;
 
 static gboolean socket_reconnect_timeout(gpointer opaque);
@@ -2521,6 +2522,17 @@ static void qemu_chr_socket_restart_timer(CharDriverState *chr)
                                                socket_reconnect_timeout, chr);
 }
 
+static void check_report_connect_error(CharDriverState *chr, const char *str)
+{
+    TCPCharDriver *s = chr->opaque;
+
+    if (!s->connect_err_reported) {
+        error_report("%s char device %s\n", str, chr->label);
+        s->connect_err_reported = 1;
+    }
+    qemu_chr_socket_restart_timer(chr);
+}
+
 static gboolean tcp_chr_accept(GIOChannel *chan, GIOCondition cond, void *opaque);
 
 #ifndef _WIN32
@@ -3045,12 +3057,14 @@ static void qemu_chr_finish_socket_connection(CharDriverState *chr, int fd)
 static void qemu_chr_socket_connected(int fd, void *opaque)
 {
     CharDriverState *chr = opaque;
+    TCPCharDriver *s = chr->opaque;
 
     if (fd < 0) {
-        qemu_chr_socket_restart_timer(chr);
+        check_report_connect_error(chr, "Unable to connect to");
         return;
     }
 
+    s->connect_err_reported = 0;
     qemu_chr_finish_socket_connection(chr, fd);
 }
 
@@ -4066,11 +4080,19 @@ static CharDriverState *qmp_chardev_open_parallel(ChardevHostdev *parallel,
 
 #endif /* WIN32 */
 
+static void socket_try_connect(CharDriverState *chr)
+{
+    Error *err = NULL;
+
+    if (!qemu_chr_open_socket_fd(chr, &err)) {
+        check_report_connect_error(chr, "Unable to start connection to");
+    }
+}
+
 static gboolean socket_reconnect_timeout(gpointer opaque)
 {
     CharDriverState *chr = opaque;
     TCPCharDriver *s = chr->opaque;
-    Error *err;
 
     s->reconnect_timer = 0;
 
@@ -4078,10 +4100,7 @@ static gboolean socket_reconnect_timeout(gpointer opaque)
         return false;
     }
 
-    if (!qemu_chr_open_socket_fd(chr, &err)) {
-        error_report("Unable to connect to char device %s\n", chr->label);
-        qemu_chr_socket_restart_timer(chr);
-    }
+    socket_try_connect(chr);
 
     return false;
 }
@@ -4133,15 +4152,13 @@ static CharDriverState *qmp_chardev_open_socket(ChardevSocket *sock,
         s->reconnect_time = reconnect;
     }
 
-    if (!qemu_chr_open_socket_fd(chr, errp)) {
-        if (s->reconnect_time) {
-            qemu_chr_socket_restart_timer(chr);
-        } else {
-            g_free(s);
-            g_free(chr->filename);
-            g_free(chr);
-            return NULL;
-        }
+    if (s->reconnect_time) {
+        socket_try_connect(chr);
+    } else if (!qemu_chr_open_socket_fd(chr, errp)) {
+        g_free(s);
+        g_free(chr->filename);
+        g_free(chr);
+        return NULL;
     }
 
     if (is_listen && is_waitconnect) {
-- 
1.8.3.1

Re: [Qemu-devel] [PATCH 1/2] qemu-char: Fix reconnect socket error reporting

[Eric Blake]

[-- Attachment #1: Type: text/plain, Size: 2441 bytes --]

On 10/06/2014 11:59 AM, minyard@acm.org wrote:
> From: Corey Minyard <cminyard@mvista.com>
> 
> If reconnect was set, errors wouldn't always be reported.
> Fix that and also only report a connect error once until a
> connection has been made.
> 
> The primary purpose of this is to tell the user that a
> connection failed so they can know they need to figure out
> what went wrong.  So we don't want to spew too much
> out here, just enough so they know.
> 
> Signed-off-by: Corey Minyard <cminyard@mvista.com>
> ---
>  qemu-char.c | 47 ++++++++++++++++++++++++++++++++---------------
>  1 file changed, 32 insertions(+), 15 deletions(-)

> +    bool connect_err_reported;
>  } TCPCharDriver;
>  
>  static gboolean socket_reconnect_timeout(gpointer opaque);
> @@ -2521,6 +2522,17 @@ static void qemu_chr_socket_restart_timer(CharDriverState *chr)
>                                                 socket_reconnect_timeout, chr);
>  }
>  
> +static void check_report_connect_error(CharDriverState *chr, const char *str)
> +{
> +    TCPCharDriver *s = chr->opaque;
> +
> +    if (!s->connect_err_reported) {
> +        error_report("%s char device %s\n", str, chr->label);

No \n at the end of an error_report() message.

> +        s->connect_err_reported = 1;

s/1/true/ since you typed it as bool.

> +    }
> +    qemu_chr_socket_restart_timer(chr);
> +}
> +
>  static gboolean tcp_chr_accept(GIOChannel *chan, GIOCondition cond, void *opaque);
>  
>  #ifndef _WIN32
> @@ -3045,12 +3057,14 @@ static void qemu_chr_finish_socket_connection(CharDriverState *chr, int fd)
>  static void qemu_chr_socket_connected(int fd, void *opaque)
>  {
>      CharDriverState *chr = opaque;
> +    TCPCharDriver *s = chr->opaque;
>  
>      if (fd < 0) {
> -        qemu_chr_socket_restart_timer(chr);
> +        check_report_connect_error(chr, "Unable to connect to");

Works in English, but if there is ever translation of the message
printed in check_report_connect_error, you are probably doing
translators a disservice by splitting a sentence into two parts
separated by a number of lines of code.  (Spoken by one who has never
contributed a translation, so take with a grain of salt)

>          return;
>      }
>  
> +    s->connect_err_reported = 0;

s/0/false/



-- 
Eric Blake   eblake redhat com    +1-919-301-3266
Libvirt virtualization library http://libvirt.org


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 539 bytes --]

Re: [Qemu-devel] [PATCH 1/2] qemu-char: Fix reconnect socket error reporting

[Corey Minyard]

On 10/06/2014 01:36 PM, Eric Blake wrote:
> On 10/06/2014 11:59 AM, minyard@acm.org wrote:
>> From: Corey Minyard <cminyard@mvista.com>
>>
>> If reconnect was set, errors wouldn't always be reported.
>> Fix that and also only report a connect error once until a
>> connection has been made.
>>
>> The primary purpose of this is to tell the user that a
>> connection failed so they can know they need to figure out
>> what went wrong.  So we don't want to spew too much
>> out here, just enough so they know.
>>
>> Signed-off-by: Corey Minyard <cminyard@mvista.com>
>> ---
>>  qemu-char.c | 47 ++++++++++++++++++++++++++++++++---------------
>>  1 file changed, 32 insertions(+), 15 deletions(-)
>> +    bool connect_err_reported;
>>  } TCPCharDriver;
>>  
>>  static gboolean socket_reconnect_timeout(gpointer opaque);
>> @@ -2521,6 +2522,17 @@ static void qemu_chr_socket_restart_timer(CharDriverState *chr)
>>                                                 socket_reconnect_timeout, chr);
>>  }
>>  
>> +static void check_report_connect_error(CharDriverState *chr, const char *str)
>> +{
>> +    TCPCharDriver *s = chr->opaque;
>> +
>> +    if (!s->connect_err_reported) {
>> +        error_report("%s char device %s\n", str, chr->label);
> No \n at the end of an error_report() message.

Oops, I read that and forgot to change it.

>
>> +        s->connect_err_reported = 1;
> s/1/true/ since you typed it as bool.

Sigh.  Old habits die hard.

>
>> +    }
>> +    qemu_chr_socket_restart_timer(chr);
>> +}
>> +
>>  static gboolean tcp_chr_accept(GIOChannel *chan, GIOCondition cond, void *opaque);
>>  
>>  #ifndef _WIN32
>> @@ -3045,12 +3057,14 @@ static void qemu_chr_finish_socket_connection(CharDriverState *chr, int fd)
>>  static void qemu_chr_socket_connected(int fd, void *opaque)
>>  {
>>      CharDriverState *chr = opaque;
>> +    TCPCharDriver *s = chr->opaque;
>>  
>>      if (fd < 0) {
>> -        qemu_chr_socket_restart_timer(chr);
>> +        check_report_connect_error(chr, "Unable to connect to");
> Works in English, but if there is ever translation of the message
> printed in check_report_connect_error, you are probably doing
> translators a disservice by splitting a sentence into two parts
> separated by a number of lines of code.  (Spoken by one who has never
> contributed a translation, so take with a grain of salt)

Yeah, I was avoiding having to add an error_vreport().  I should just
add that.

All other comments fixed.  Thanks.

-corey

>>          return;
>>      }
>>  
>> +    s->connect_err_reported = 0;
> s/0/false/
>
>
>

Re: [Qemu-devel] [PATCH 1/2] qemu-char: Fix reconnect socket error reporting

[Paolo Bonzini]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Il 06/10/2014 20:36, Eric Blake ha scritto:
>>> -        qemu_chr_socket_restart_timer(chr); +
>>> check_report_connect_error(chr, "Unable to connect to");
> Works in English, but if there is ever translation of the message 
> printed in check_report_connect_error, you are probably doing 
> translators a disservice by splitting a sentence into two parts 
> separated by a number of lines of code.  (Spoken by one who has
> never contributed a translation, so take with a grain of salt)
> 

I agree, I think it's simpler to unify the two messages.

Paolo
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQEcBAEBAgAGBQJUMv1IAAoJEBRUblpOawnXtFoH/1QIYr/yZXZQhw7zqDxiyhgH
Gto3UiDjd/eLNC/iFwdY3J2pnuHIu8yVmBAO68cALdK6KotZ6X/TGVpsGUmPeoPk
rPtkbxAvBvxdPImCUi798YSXbkOsVA/5+pMOOxNLeMwzA2ClFDFBqzgqgBbL/PwU
O25XgCNucwFpk6An5yTOblHbS5Ji6oSnfJfHkXwuZlzjE7ql2nbr0Gr9lEulgHk3
3+hDoyesCD55V0r1qO/CwGJsuyJ1PXJGxV65ML1ja6F+yiMjlCgaTmzLAtcdWu4A
oD6wR5auS9ZTWogS/JBxCx9oFnZVs19LgnSPSvQVHb3TaQJcVSTZuQjkb3/m8bU=
=ctwR
-----END PGP SIGNATURE-----

Re: [Qemu-devel] [PATCH 1/2] qemu-char: Fix reconnect socket error reporting

[Markus Armbruster]

minyard@acm.org writes:

> From: Corey Minyard <cminyard@mvista.com>
>
> If reconnect was set, errors wouldn't always be reported.
> Fix that and also only report a connect error once until a
> connection has been made.
>
> The primary purpose of this is to tell the user that a
> connection failed so they can know they need to figure out
> what went wrong.  So we don't want to spew too much
> out here, just enough so they know.
>
> Signed-off-by: Corey Minyard <cminyard@mvista.com>
> ---
>  qemu-char.c | 47 ++++++++++++++++++++++++++++++++---------------
>  1 file changed, 32 insertions(+), 15 deletions(-)
>
> diff --git a/qemu-char.c b/qemu-char.c
> index 62af0ef..fb895c7 100644
> --- a/qemu-char.c
> +++ b/qemu-char.c
> @@ -2509,6 +2509,7 @@ typedef struct {
>  
>      guint reconnect_timer;
>      int64_t reconnect_time;
> +    bool connect_err_reported;
>  } TCPCharDriver;
>  
>  static gboolean socket_reconnect_timeout(gpointer opaque);

Doesn't apply, obviously depends on some other patch.  Always state your
dependencies explicitly in the cover letter!

[...]

[Qemu-devel] [PATCH 2/2] qemu-sockets: Add error to non-blocking connect handler

[minyard]

From: Corey Minyard <cminyard@mvista.com>

An error value here would be quite handy and more consistent
with the rest of the code.

Corey Minyard <cminyard@mvista.com>
---
 include/qemu/sockets.h |  2 +-
 migration-tcp.c        |  4 ++--
 migration-unix.c       |  4 ++--
 qemu-char.c            | 12 +++++++-----
 util/qemu-sockets.c    | 19 ++++++++++++++-----
 5 files changed, 26 insertions(+), 15 deletions(-)

diff --git a/include/qemu/sockets.h b/include/qemu/sockets.h
index fdbb196..f47dae6 100644
--- a/include/qemu/sockets.h
+++ b/include/qemu/sockets.h
@@ -47,7 +47,7 @@ int recv_all(int fd, void *buf, int len1, bool single_read);
 /* callback function for nonblocking connect
  * valid fd on success, negative error code on failure
  */
-typedef void NonBlockingConnectHandler(int fd, void *opaque);
+typedef void NonBlockingConnectHandler(int fd, Error *errp, void *opaque);
 
 InetSocketAddress *inet_parse(const char *str, Error **errp);
 int inet_listen_opts(QemuOpts *opts, int port_offset, Error **errp);
diff --git a/migration-tcp.c b/migration-tcp.c
index 2e34517..91c9cf3 100644
--- a/migration-tcp.c
+++ b/migration-tcp.c
@@ -33,12 +33,12 @@
     do { } while (0)
 #endif
 
-static void tcp_wait_for_connect(int fd, void *opaque)
+static void tcp_wait_for_connect(int fd, Error *err, void *opaque)
 {
     MigrationState *s = opaque;
 
     if (fd < 0) {
-        DPRINTF("migrate connect error\n");
+        DPRINTF("migrate connect error: %s\n", error_get_pretty(err));
         s->file = NULL;
         migrate_fd_error(s);
     } else {
diff --git a/migration-unix.c b/migration-unix.c
index 0a5f8a1..1cdadfb 100644
--- a/migration-unix.c
+++ b/migration-unix.c
@@ -33,12 +33,12 @@
     do { } while (0)
 #endif
 
-static void unix_wait_for_connect(int fd, void *opaque)
+static void unix_wait_for_connect(int fd, Error *err, void *opaque)
 {
     MigrationState *s = opaque;
 
     if (fd < 0) {
-        DPRINTF("migrate connect error\n");
+        DPRINTF("migrate connect error: %s\n", error_get_pretty(err));
         s->file = NULL;
         migrate_fd_error(s);
     } else {
diff --git a/qemu-char.c b/qemu-char.c
index fb895c7..22a2eb7 100644
--- a/qemu-char.c
+++ b/qemu-char.c
@@ -2522,12 +2522,14 @@ static void qemu_chr_socket_restart_timer(CharDriverState *chr)
                                                socket_reconnect_timeout, chr);
 }
 
-static void check_report_connect_error(CharDriverState *chr, const char *str)
+static void check_report_connect_error(CharDriverState *chr, const char *str,
+                                       Error *err)
 {
     TCPCharDriver *s = chr->opaque;
 
     if (!s->connect_err_reported) {
-        error_report("%s char device %s\n", str, chr->label);
+        error_report("%s char device %s: %s\n", str, chr->label,
+                     error_get_pretty(err));
         s->connect_err_reported = 1;
     }
     qemu_chr_socket_restart_timer(chr);
@@ -3054,13 +3056,13 @@ static void qemu_chr_finish_socket_connection(CharDriverState *chr, int fd)
     }
 }
 
-static void qemu_chr_socket_connected(int fd, void *opaque)
+static void qemu_chr_socket_connected(int fd, Error *err, void *opaque)
 {
     CharDriverState *chr = opaque;
     TCPCharDriver *s = chr->opaque;
 
     if (fd < 0) {
-        check_report_connect_error(chr, "Unable to connect to");
+        check_report_connect_error(chr, "Unable to connect to", err);
         return;
     }
 
@@ -4085,7 +4087,7 @@ static void socket_try_connect(CharDriverState *chr)
     Error *err = NULL;
 
     if (!qemu_chr_open_socket_fd(chr, &err)) {
-        check_report_connect_error(chr, "Unable to start connection to");
+        check_report_connect_error(chr, "Unable to start connection to", err);
     }
 }
 
diff --git a/util/qemu-sockets.c b/util/qemu-sockets.c
index 1eef590..e6a9644 100644
--- a/util/qemu-sockets.c
+++ b/util/qemu-sockets.c
@@ -234,6 +234,7 @@ static void wait_for_connect(void *opaque)
     int val = 0, rc = 0;
     socklen_t valsize = sizeof(val);
     bool in_progress;
+    Error *err = NULL;
 
     qemu_set_fd_handler2(s->fd, NULL, NULL, NULL, NULL);
 
@@ -248,6 +249,7 @@ static void wait_for_connect(void *opaque)
 
     /* connect error */
     if (rc < 0) {
+        error_setg_errno(&err, errno, "Error connecting to socket");
         closesocket(s->fd);
         s->fd = rc;
     }
@@ -257,9 +259,14 @@ static void wait_for_connect(void *opaque)
         while (s->current_addr->ai_next != NULL && s->fd < 0) {
             s->current_addr = s->current_addr->ai_next;
             s->fd = inet_connect_addr(s->current_addr, &in_progress, s, NULL);
+            if (s->fd < 0) {
+                error_free(err);
+                err = NULL;
+                error_setg_errno(&err, errno, "Unable to start socket connect");
+            }
             /* connect in progress */
             if (in_progress) {
-                return;
+                goto out;
             }
         }
 
@@ -267,9 +274,11 @@ static void wait_for_connect(void *opaque)
     }
 
     if (s->callback) {
-        s->callback(s->fd, s->opaque);
+        s->callback(s->fd, err, s->opaque);
     }
     g_free(s);
+out:
+    error_free(err);
 }
 
 static int inet_connect_addr(struct addrinfo *addr, bool *in_progress,
@@ -401,7 +410,7 @@ int inet_connect_opts(QemuOpts *opts, Error **errp,
         return sock;
     } else {
         if (callback) {
-            callback(sock, opaque);
+            callback(sock, NULL, opaque);
         }
     }
     g_free(connect_state);
@@ -769,7 +778,7 @@ int unix_connect_opts(QemuOpts *opts, Error **errp,
     } else if (rc >= 0) {
         /* non blocking socket immediate success, call callback */
         if (callback != NULL) {
-            callback(sock, opaque);
+            callback(sock, NULL, opaque);
         }
     }
 
@@ -919,7 +928,7 @@ int socket_connect(SocketAddress *addr, Error **errp,
         fd = monitor_get_fd(cur_mon, addr->fd->str, errp);
         if (fd >= 0 && callback) {
             qemu_set_nonblock(fd);
-            callback(fd, opaque);
+            callback(fd, NULL, opaque);
         }
         break;
 
-- 
1.8.3.1

Re: [Qemu-devel] [PATCH 2/2] qemu-sockets: Add error to non-blocking connect handler

[Paolo Bonzini]

Il 06/10/2014 19:59, minyard@acm.org ha scritto:
> +        error_setg_errno(&err, errno, "Error connecting to socket");
>          closesocket(s->fd);
>          s->fd = rc;
>      }
> @@ -257,9 +259,14 @@ static void wait_for_connect(void *opaque)
>          while (s->current_addr->ai_next != NULL && s->fd < 0) {
>              s->current_addr = s->current_addr->ai_next;
>              s->fd = inet_connect_addr(s->current_addr, &in_progress, s, NULL);
> +            if (s->fd < 0) {
> +                error_free(err);
> +                err = NULL;
> +                error_setg_errno(&err, errno, "Unable to start socket connect");

So the above snippet is the actual errors that are passed here:

> +static void check_report_connect_error(CharDriverState *chr, const char *str,
> +                                       Error *err)
>  {
>      TCPCharDriver *s = chr->opaque;
>  
>      if (!s->connect_err_reported) {
> -        error_report("%s char device %s\n", str, chr->label);
> +        error_report("%s char device %s: %s\n", str, chr->label,
> +                     error_get_pretty(err));


If you just make it

error_report("%s: %s", chr->label, error_get_pretty(err));

we still get a good error.  It would arguably be better, since there's
no duplication, except that it doesn't mention character devices
anymore.  But something like "serial0: error connecting to socket" is a
decent error.

Thanks,

Paolo