Add more trace points to VNC code

index c3eece4fa7..2a3766aa64 100644
@@ -28,6 +28,7 @@
 #include "vnc.h"
 #include "qapi/error.h"
 #include "qemu/main-loop.h"
+#include "trace.h"
 
 static void start_auth_vencrypt_subauth(VncState *vs)
 {

@@ -124,6 +125,7 @@ static int protocol_client_vencrypt_auth(VncState *vs, uint8_t *data, size_t len
         VNC_DEBUG("Start TLS VeNCrypt handshake process\n");
         object_unref(OBJECT(vs->ioc));
         vs->ioc = QIO_CHANNEL(tls);
+        trace_vnc_client_io_wrap(vs, vs->ioc, "tls");
         vs->tls = qio_channel_tls_get_session(tls);
 
         qio_channel_tls_handshake(tls,

index eaf309553c..6ccad22cef 100644
@@ -23,6 +23,7 @@
 #include "vnc.h"
 #include "io/channel-websock.h"
 #include "qemu/bswap.h"
+#include "trace.h"
 
 static void vncws_tls_handshake_done(QIOTask *task,
                                      gpointer user_data)

@@ -53,7 +54,6 @@ gboolean vncws_tls_handshake_io(QIOChannel *ioc G_GNUC_UNUSED,
     QIOChannelTLS *tls;
     Error *err = NULL;
 
-    VNC_DEBUG("TLS Websocket connection required\n");
     if (vs->ioc_tag) {
         g_source_remove(vs->ioc_tag);
         vs->ioc_tag = 0;

@@ -73,9 +73,9 @@ gboolean vncws_tls_handshake_io(QIOChannel *ioc G_GNUC_UNUSED,
 
     qio_channel_set_name(QIO_CHANNEL(tls), "vnc-ws-server-tls");
 
-    VNC_DEBUG("Start TLS WS handshake process\n");
     object_unref(OBJECT(vs->ioc));
     vs->ioc = QIO_CHANNEL(tls);
+    trace_vnc_client_io_wrap(vs, vs->ioc, "tls");
     vs->tls = qio_channel_tls_get_session(tls);
 
     qio_channel_tls_handshake(tls,

@@ -116,7 +116,6 @@ gboolean vncws_handshake_io(QIOChannel *ioc G_GNUC_UNUSED,
     VncState *vs = opaque;
     QIOChannelWebsock *wioc;
 
-    VNC_DEBUG("Websocket negotiate starting\n");
     if (vs->ioc_tag) {
         g_source_remove(vs->ioc_tag);
         vs->ioc_tag = 0;

@@ -127,6 +126,7 @@ gboolean vncws_handshake_io(QIOChannel *ioc G_GNUC_UNUSED,
 
     object_unref(OBJECT(vs->ioc));
     vs->ioc = QIO_CHANNEL(wioc);
+    trace_vnc_client_io_wrap(vs, vs->ioc, "websock");
 
     qio_channel_websock_handshake(wioc,
                                   vncws_handshake_done,

index 62f7a3f30a..47dacc47b6 100644
@@ -1118,6 +1118,7 @@ static void vnc_disconnect_start(VncState *vs)
     if (vs->disconnecting) {
         return;
     }
+    trace_vnc_client_disconnect_start(vs, vs->ioc);
     vnc_set_share_mode(vs, VNC_SHARE_MODE_DISCONNECTED);
     if (vs->ioc_tag) {
         g_source_remove(vs->ioc_tag);

@@ -1131,6 +1132,8 @@ void vnc_disconnect_finish(VncState *vs)
 {
     int i;
 
+    trace_vnc_client_disconnect_finish(vs, vs->ioc);
+
     vnc_jobs_join(vs); /* Wait encoding jobs */
 
     vnc_lock_output(vs);

@@ -1184,11 +1187,12 @@ ssize_t vnc_client_io_error(VncState *vs, ssize_t ret, Error **errp)
 {
     if (ret <= 0) {
         if (ret == 0) {
-            VNC_DEBUG("Closing down client sock: EOF\n");
+            trace_vnc_client_eof(vs, vs->ioc);
             vnc_disconnect_start(vs);
         } else if (ret != QIO_CHANNEL_ERR_BLOCK) {
-            VNC_DEBUG("Closing down client sock: ret %zd (%s)\n",
-                      ret, errp ? error_get_pretty(*errp) : "Unknown");
+            trace_vnc_client_io_error(vs, vs->ioc,
+                                      errp ? error_get_pretty(*errp) :
+                                      "Unknown");
             vnc_disconnect_start(vs);
         }
 

@@ -2885,6 +2889,7 @@ static void vnc_connect(VncDisplay *vd, QIOChannelSocket *sioc,
     bool first_client = QTAILQ_EMPTY(&vd->clients);
     int i;
 
+    trace_vnc_client_connect(vs, sioc);
     vs->sioc = sioc;
     object_ref(OBJECT(vs->sioc));
     vs->ioc = QIO_CHANNEL(sioc);

341 lines not on this page · raw message

index 2a3766aa64..7833631275 100644
@@ -35,27 +35,24 @@ static void start_auth_vencrypt_subauth(VncState *vs)
     switch (vs->subauth) {
     case VNC_AUTH_VENCRYPT_TLSNONE:
     case VNC_AUTH_VENCRYPT_X509NONE:
-       VNC_DEBUG("Accept TLS auth none\n");
        vnc_write_u32(vs, 0); /* Accept auth completion */
        start_client_init(vs);
        break;
 
     case VNC_AUTH_VENCRYPT_TLSVNC:
     case VNC_AUTH_VENCRYPT_X509VNC:
-       VNC_DEBUG("Start TLS auth VNC\n");
        start_auth_vnc(vs);
        break;
 
 #ifdef CONFIG_VNC_SASL
     case VNC_AUTH_VENCRYPT_TLSSASL:
     case VNC_AUTH_VENCRYPT_X509SASL:
-      VNC_DEBUG("Start TLS auth SASL\n");
       start_auth_sasl(vs);
       break;
 #endif /* CONFIG_VNC_SASL */
 
     default: /* Should not be possible, but just in case */
-       VNC_DEBUG("Reject subauth %d server bug\n", vs->auth);
+       trace_vnc_auth_fail(vs, vs->auth, "Unhandled VeNCrypt subauth", "");
        vnc_write_u8(vs, 1);
        if (vs->minor >= 8) {
            static const char err[] = "Unsupported authentication type";

@@ -73,8 +70,8 @@ static void vnc_tls_handshake_done(QIOTask *task,
     Error *err = NULL;
 
     if (qio_task_propagate_error(task, &err)) {
-        VNC_DEBUG("Handshake failed %s\n",
-                  error_get_pretty(err));
+        trace_vnc_auth_fail(vs, vs->auth, "TLS handshake failed",
+                            error_get_pretty(err));
         vnc_client_error(vs);
         error_free(err);
     } else {

@@ -92,15 +89,15 @@ static int protocol_client_vencrypt_auth(VncState *vs, uint8_t *data, size_t len
 {
     int auth = read_u32(data, 0);
 
+    trace_vnc_auth_vencrypt_subauth(vs, auth);
     if (auth != vs->subauth) {
-        VNC_DEBUG("Rejecting auth %d\n", auth);
+        trace_vnc_auth_fail(vs, vs->auth, "Unsupported sub-auth version", "");
         vnc_write_u8(vs, 0); /* Reject auth */
         vnc_flush(vs);
         vnc_client_error(vs);
     } else {
         Error *err = NULL;
         QIOChannelTLS *tls;
-        VNC_DEBUG("Accepting auth %d, setting up TLS for handshake\n", auth);
         vnc_write_u8(vs, 1); /* Accept auth */
         vnc_flush(vs);
 

@@ -115,14 +112,14 @@ static int protocol_client_vencrypt_auth(VncState *vs, uint8_t *data, size_t len
             vs->vd->tlsaclname,
             &err);
         if (!tls) {
-            VNC_DEBUG("Failed to setup TLS %s\n", error_get_pretty(err));
+            trace_vnc_auth_fail(vs, vs->auth, "TLS setup failed",
+                                error_get_pretty(err));
             error_free(err);
             vnc_client_error(vs);
             return 0;
         }
 
         qio_channel_set_name(QIO_CHANNEL(tls), "vnc-server-tls");
-        VNC_DEBUG("Start TLS VeNCrypt handshake process\n");
         object_unref(OBJECT(vs->ioc));
         vs->ioc = QIO_CHANNEL(tls);
         trace_vnc_client_io_wrap(vs, vs->ioc, "tls");

@@ -138,14 +135,14 @@ static int protocol_client_vencrypt_auth(VncState *vs, uint8_t *data, size_t len
 
 static int protocol_client_vencrypt_init(VncState *vs, uint8_t *data, size_t len)
 {
+    trace_vnc_auth_vencrypt_version(vs, (int)data[0], (int)data[1]);
     if (data[0] != 0 ||
         data[1] != 2) {
-        VNC_DEBUG("Unsupported VeNCrypt protocol %d.%d\n", (int)data[0], (int)data[1]);
+        trace_vnc_auth_fail(vs, vs->auth, "Unsupported version", "");
         vnc_write_u8(vs, 1); /* Reject version */
         vnc_flush(vs);
         vnc_client_error(vs);
     } else {
-        VNC_DEBUG("Sending allowed auth %d\n", vs->subauth);
         vnc_write_u8(vs, 0); /* Accept version */
         vnc_write_u8(vs, 1); /* Number of sub-auths */
         vnc_write_u32(vs, vs->subauth); /* The supported auth */

index 47dacc47b6..9f8d5a1b1f 100644
@@ -2407,11 +2407,11 @@ static int protocol_client_auth_vnc(VncState *vs, uint8_t *data, size_t len)
     Error *err = NULL;
 
     if (!vs->vd->password) {
-        VNC_DEBUG("No password configured on server");
+        trace_vnc_auth_fail(vs, vs->auth, "password is not set", "");
         goto reject;
     }
     if (vs->vd->expires < now) {
-        VNC_DEBUG("Password is expired");
+        trace_vnc_auth_fail(vs, vs->auth, "password is expired", "");
         goto reject;
     }
 

@@ -2428,8 +2428,8 @@ static int protocol_client_auth_vnc(VncState *vs, uint8_t *data, size_t len)
         key, G_N_ELEMENTS(key),
         &err);
     if (!cipher) {
-        VNC_DEBUG("Cannot initialize cipher %s",
-                  error_get_pretty(err));
+        trace_vnc_auth_fail(vs, vs->auth, "cannot create cipher",
+                            error_get_pretty(err));
         error_free(err);
         goto reject;
     }

@@ -2439,18 +2439,18 @@ static int protocol_client_auth_vnc(VncState *vs, uint8_t *data, size_t len)
                                response,
                                VNC_AUTH_CHALLENGE_SIZE,
                                &err) < 0) {
-        VNC_DEBUG("Cannot encrypt challenge %s",
-                  error_get_pretty(err));
+        trace_vnc_auth_fail(vs, vs->auth, "cannot encrypt challenge response",
+                            error_get_pretty(err));
         error_free(err);
         goto reject;
     }
 
     /* Compare expected vs actual challenge response */
     if (memcmp(response, data, VNC_AUTH_CHALLENGE_SIZE) != 0) {
-        VNC_DEBUG("Client challenge response did not match\n");
+        trace_vnc_auth_fail(vs, vs->auth, "mis-matched challenge response", "");
         goto reject;
     } else {
-        VNC_DEBUG("Accepting VNC challenge response\n");
+        trace_vnc_auth_pass(vs, vs->auth);
         vnc_write_u32(vs, 0); /* Accept auth */
         vnc_flush(vs);
 

@@ -2489,7 +2489,7 @@ static int protocol_client_auth(VncState *vs, uint8_t *data, size_t len)
     /* We only advertise 1 auth scheme at a time, so client
      * must pick the one we sent. Verify this */
     if (data[0] != vs->auth) { /* Reject auth */
-       VNC_DEBUG("Reject auth %d because it didn't match advertized\n", (int)data[0]);
+       trace_vnc_auth_reject(vs, vs->auth, (int)data[0]);
        vnc_write_u32(vs, 1);
        if (vs->minor >= 8) {
            static const char err[] = "Authentication failed";

@@ -2498,36 +2498,33 @@ static int protocol_client_auth(VncState *vs, uint8_t *data, size_t len)
        }
        vnc_client_error(vs);
     } else { /* Accept requested auth */
-       VNC_DEBUG("Client requested auth %d\n", (int)data[0]);
+       trace_vnc_auth_start(vs, vs->auth);
        switch (vs->auth) {
        case VNC_AUTH_NONE:
-           VNC_DEBUG("Accept auth none\n");
            if (vs->minor >= 8) {
                vnc_write_u32(vs, 0); /* Accept auth completion */
                vnc_flush(vs);
            }
+           trace_vnc_auth_pass(vs, vs->auth);
            start_client_init(vs);
            break;
 
        case VNC_AUTH_VNC:
-           VNC_DEBUG("Start VNC auth\n");
            start_auth_vnc(vs);
            break;
 
        case VNC_AUTH_VENCRYPT:
-           VNC_DEBUG("Accept VeNCrypt auth\n");
            start_auth_vencrypt(vs);
            break;
 
 #ifdef CONFIG_VNC_SASL
        case VNC_AUTH_SASL:
-           VNC_DEBUG("Accept SASL auth\n");
            start_auth_sasl(vs);
            break;
 #endif /* CONFIG_VNC_SASL */
 
        default: /* Should not be possible, but just in case */
-           VNC_DEBUG("Reject auth %d server code bug\n", vs->auth);
+           trace_vnc_auth_fail(vs, vs->auth, "Unhandled auth method", "");
            vnc_write_u8(vs, 1);
            if (vs->minor >= 8) {
                static const char err[] = "Authentication failed";

@@ -2572,10 +2569,11 @@ static int protocol_version(VncState *vs, uint8_t *version, size_t len)
         vs->minor = 3;
 
     if (vs->minor == 3) {
+        trace_vnc_auth_start(vs, vs->auth);
         if (vs->auth == VNC_AUTH_NONE) {
-            VNC_DEBUG("Tell client auth none\n");
             vnc_write_u32(vs, vs->auth);
             vnc_flush(vs);
+            trace_vnc_auth_pass(vs, vs->auth);
             start_client_init(vs);
        } else if (vs->auth == VNC_AUTH_VNC) {
             VNC_DEBUG("Tell client VNC auth\n");

@@ -2583,13 +2581,13 @@ static int protocol_version(VncState *vs, uint8_t *version, size_t len)
             vnc_flush(vs);
             start_auth_vnc(vs);
        } else {
-            VNC_DEBUG("Unsupported auth %d for protocol 3.3\n", vs->auth);
+            trace_vnc_auth_fail(vs, vs->auth,
+                                "Unsupported auth method for v3.3", "");
             vnc_write_u32(vs, VNC_AUTH_INVALID);
             vnc_flush(vs);
             vnc_client_error(vs);
        }
     } else {
-        VNC_DEBUG("Telling client we support auth %d\n", vs->auth);
         vnc_write_u8(vs, 1); /* num auth */
         vnc_write_u8(vs, vs->auth);
         vnc_read_when(vs, protocol_client_auth, 1);

@@ -3946,12 +3944,14 @@ void vnc_display_open(const char *id, Error **errp)
                                sasl, false, errp) < 0) {
         goto fail;
     }
+    trace_vnc_auth_init(vd, 0, vd->auth, vd->subauth);
 
     if (vnc_display_setup_auth(&vd->ws_auth, &vd->ws_subauth,
                                vd->tlscreds, password,
                                sasl, true, errp) < 0) {
         goto fail;
     }
+    trace_vnc_auth_init(vd, 1, vd->ws_auth, vd->ws_subauth);
 
 #ifdef CONFIG_VNC_SASL
     if ((saslErr = sasl_server_init(NULL, "qemu")) != SASL_OK) {