Merge remote-tracking branch 'remotes/kraxel/tags/ui-20170929-pull-request' into staging

ui and input patches.

# gpg: Signature made Fri 29 Sep 2017 11:21:45 BST
# gpg:                using RSA key 0x4CB6D8EED3E87138
# gpg: Good signature from "Gerd Hoffmann (work) <kraxel@redhat.com>"
# gpg:                 aka "Gerd Hoffmann <gerd@kraxel.org>"
# gpg:                 aka "Gerd Hoffmann (private) <kraxel@gmail.com>"
# Primary key fingerprint: A032 8CFF B93A 17A7 9901  FE7D 4CB6 D8EE D3E8 7138

* remotes/kraxel/tags/ui-20170929-pull-request:
  ui: add tracing of VNC authentication process
  ui: add tracing of VNC operations related to QIOChannel
  virtio-input: send rel-wheel events for wheel buttons
  egl: misc framebuffer helper improvements.
  console: purge curses bits from console.h
Signed-off-by: NPeter Maydell <peter.maydell@linaro.org>

hw/input/virtio-input-hid.c

@@ -190,6 +190,7 @@ static void virtio_input_key_config(VirtIOInput *vinput,
 static void virtio_input_handle_event(DeviceState *dev, QemuConsole *src,
                                       InputEvent *evt)
 {
+    VirtIOInputHID *vhid = VIRTIO_INPUT_HID(dev);
     VirtIOInput *vinput = VIRTIO_INPUT(dev);
     virtio_input_event event;
     int qcode;
@@ -215,7 +216,14 @@ static void virtio_input_handle_event(DeviceState *dev, QemuConsole *src,
         break;
     case INPUT_EVENT_KIND_BTN:
         btn = evt->u.btn.data;
-        if (keymap_button[btn->button]) {
+        if (vhid->wheel_axis && (btn->button == INPUT_BUTTON_WHEEL_UP ||
+                                 btn->button == INPUT_BUTTON_WHEEL_DOWN)) {
+            event.type  = cpu_to_le16(EV_REL);
+            event.code  = cpu_to_le16(REL_WHEEL);
+            event.value = cpu_to_le32(btn->button == INPUT_BUTTON_WHEEL_UP
+                                      ? 1 : -1);
+            virtio_input_send(vinput, &event);
+        } else if (keymap_button[btn->button]) {
             event.type  = cpu_to_le16(EV_KEY);
             event.code  = cpu_to_le16(keymap_button[btn->button]);
             event.value = cpu_to_le32(btn->down ? 1 : 0);
@@ -407,7 +415,7 @@ static QemuInputHandler virtio_mouse_handler = {
     .sync  = virtio_input_handle_sync,
 };
 
-static struct virtio_input_config virtio_mouse_config[] = {
+static struct virtio_input_config virtio_mouse_config_v1[] = {
     {
         .select    = VIRTIO_INPUT_CFG_ID_NAME,
         .size      = sizeof(VIRTIO_ID_NAME_MOUSE),
@@ -432,13 +440,53 @@ static struct virtio_input_config virtio_mouse_config[] = {
     { /* end of list */ },
 };
 
+static struct virtio_input_config virtio_mouse_config_v2[] = {
+    {
+        .select    = VIRTIO_INPUT_CFG_ID_NAME,
+        .size      = sizeof(VIRTIO_ID_NAME_MOUSE),
+        .u.string  = VIRTIO_ID_NAME_MOUSE,
+    },{
+        .select    = VIRTIO_INPUT_CFG_ID_DEVIDS,
+        .size      = sizeof(struct virtio_input_devids),
+        .u.ids     = {
+            .bustype = const_le16(BUS_VIRTUAL),
+            .vendor  = const_le16(0x0627), /* same we use for usb hid devices */
+            .product = const_le16(0x0002),
+            .version = const_le16(0x0002),
+        },
+    },{
+        .select    = VIRTIO_INPUT_CFG_EV_BITS,
+        .subsel    = EV_REL,
+        .size      = 2,
+        .u.bitmap  = {
+            (1 << REL_X) | (1 << REL_Y),
+            (1 << (REL_WHEEL - 8))
+        },
+    },
+    { /* end of list */ },
+};
+
+static Property virtio_mouse_properties[] = {
+    DEFINE_PROP_BOOL("wheel-axis", VirtIOInputHID, wheel_axis, true),
+    DEFINE_PROP_END_OF_LIST(),
+};
+
+static void virtio_mouse_class_init(ObjectClass *klass, void *data)
+{
+    DeviceClass *dc = DEVICE_CLASS(klass);
+
+    dc->props  = virtio_mouse_properties;
+}
+
 static void virtio_mouse_init(Object *obj)
 {
     VirtIOInputHID *vhid = VIRTIO_INPUT_HID(obj);
     VirtIOInput *vinput = VIRTIO_INPUT(obj);
 
     vhid->handler = &virtio_mouse_handler;
-    virtio_input_init_config(vinput, virtio_mouse_config);
+    virtio_input_init_config(vinput, vhid->wheel_axis
+                             ? virtio_mouse_config_v2
+                             : virtio_mouse_config_v1);
     virtio_input_key_config(vinput, keymap_button,
                             ARRAY_SIZE(keymap_button));
 }
@@ -448,6 +496,7 @@ static const TypeInfo virtio_mouse_info = {
     .parent        = TYPE_VIRTIO_INPUT_HID,
     .instance_size = sizeof(VirtIOInputHID),
     .instance_init = virtio_mouse_init,
+    .class_init    = virtio_mouse_class_init,
 };
 
 /* ----------------------------------------------------------------- */
@@ -459,7 +508,7 @@ static QemuInputHandler virtio_tablet_handler = {
     .sync  = virtio_input_handle_sync,
 };
 
-static struct virtio_input_config virtio_tablet_config[] = {
+static struct virtio_input_config virtio_tablet_config_v1[] = {
     {
         .select    = VIRTIO_INPUT_CFG_ID_NAME,
         .size      = sizeof(VIRTIO_ID_NAME_TABLET),
@@ -496,13 +545,72 @@ static struct virtio_input_config virtio_tablet_config[] = {
     { /* end of list */ },
 };
 
+static struct virtio_input_config virtio_tablet_config_v2[] = {
+    {
+        .select    = VIRTIO_INPUT_CFG_ID_NAME,
+        .size      = sizeof(VIRTIO_ID_NAME_TABLET),
+        .u.string  = VIRTIO_ID_NAME_TABLET,
+    },{
+        .select    = VIRTIO_INPUT_CFG_ID_DEVIDS,
+        .size      = sizeof(struct virtio_input_devids),
+        .u.ids     = {
+            .bustype = const_le16(BUS_VIRTUAL),
+            .vendor  = const_le16(0x0627), /* same we use for usb hid devices */
+            .product = const_le16(0x0003),
+            .version = const_le16(0x0002),
+        },
+    },{
+        .select    = VIRTIO_INPUT_CFG_EV_BITS,
+        .subsel    = EV_ABS,
+        .size      = 1,
+        .u.bitmap  = {
+            (1 << ABS_X) | (1 << ABS_Y),
+        },
+    },{
+        .select    = VIRTIO_INPUT_CFG_EV_BITS,
+        .subsel    = EV_REL,
+        .size      = 2,
+        .u.bitmap  = {
+            0,
+            (1 << (REL_WHEEL - 8))
+        },
+    },{
+        .select    = VIRTIO_INPUT_CFG_ABS_INFO,
+        .subsel    = ABS_X,
+        .size      = sizeof(virtio_input_absinfo),
+        .u.abs.min = const_le32(INPUT_EVENT_ABS_MIN),
+        .u.abs.max = const_le32(INPUT_EVENT_ABS_MAX),
+    },{
+        .select    = VIRTIO_INPUT_CFG_ABS_INFO,
+        .subsel    = ABS_Y,
+        .size      = sizeof(virtio_input_absinfo),
+        .u.abs.min = const_le32(INPUT_EVENT_ABS_MIN),
+        .u.abs.max = const_le32(INPUT_EVENT_ABS_MAX),
+    },
+    { /* end of list */ },
+};
+
+static Property virtio_tablet_properties[] = {
+    DEFINE_PROP_BOOL("wheel-axis", VirtIOInputHID, wheel_axis, true),
+    DEFINE_PROP_END_OF_LIST(),
+};
+
+static void virtio_tablet_class_init(ObjectClass *klass, void *data)
+{
+    DeviceClass *dc = DEVICE_CLASS(klass);
+
+    dc->props  = virtio_tablet_properties;
+}
+
 static void virtio_tablet_init(Object *obj)
 {
     VirtIOInputHID *vhid = VIRTIO_INPUT_HID(obj);
     VirtIOInput *vinput = VIRTIO_INPUT(obj);
 
     vhid->handler = &virtio_tablet_handler;
-    virtio_input_init_config(vinput, virtio_tablet_config);
+    virtio_input_init_config(vinput, vhid->wheel_axis
+                             ? virtio_tablet_config_v2
+                             : virtio_tablet_config_v1);
     virtio_input_key_config(vinput, keymap_button,
                             ARRAY_SIZE(keymap_button));
 }
@@ -512,6 +620,7 @@ static const TypeInfo virtio_tablet_info = {
     .parent        = TYPE_VIRTIO_INPUT_HID,
     .instance_size = sizeof(VirtIOInputHID),
     .instance_init = virtio_tablet_init,
+    .class_init    = virtio_tablet_class_init,
 };
 
 /* ----------------------------------------------------------------- */

include/hw/compat.h

@@ -2,7 +2,15 @@
 #define HW_COMPAT_H
 
 #define HW_COMPAT_2_10 \
-    /* empty */
+    {\
+        .driver   = "virtio-mouse-device",\
+        .property = "wheel-axis",\
+        .value    = "false",\
+    },{\
+        .driver   = "virtio-tablet-device",\
+        .property = "wheel-axis",\
+        .value    = "false",\
+    },
 
 #define HW_COMPAT_2_9 \
     {\

include/hw/virtio/virtio-input.h

@@ -89,6 +89,7 @@ struct VirtIOInputHID {
     QemuInputHandler                  *handler;
     QemuInputHandlerState             *hs;
     int                               ledstate;
+    bool                              wheel_axis;
 };
 
 struct VirtIOInputHost {

include/ui/console.h

@@ -336,29 +336,10 @@ static inline pixman_format_code_t surface_format(DisplaySurface *s)
     return s->format;
 }
 
-#ifdef CONFIG_CURSES
-/* KEY_EVENT is defined in wincon.h and in curses.h. Avoid redefinition. */
-#undef KEY_EVENT
-#include <curses.h>
-#undef KEY_EVENT
-typedef chtype console_ch_t;
-extern chtype vga_to_curses[];
-#else
-typedef unsigned long console_ch_t;
-#endif
+typedef uint32_t console_ch_t;
+
 static inline void console_write_ch(console_ch_t *dest, uint32_t ch)
 {
-    uint8_t c = ch;
-#ifdef CONFIG_CURSES
-    if (vga_to_curses[c]) {
-        ch &= ~(console_ch_t)0xff;
-        ch |= vga_to_curses[c];
-    }
-#else
-    if (c == '\0') {
-        ch |= ' ';
-    }
-#endif
     *dest = ch;
 }
 

include/ui/egl-helpers.h

@@ -18,8 +18,9 @@ typedef struct egl_fb {
 
 void egl_fb_destroy(egl_fb *fb);
 void egl_fb_setup_default(egl_fb *fb, int width, int height);
-void egl_fb_create_for_tex(egl_fb *fb, int width, int height, GLuint texture);
-void egl_fb_create_new_tex(egl_fb *fb, int width, int height);
+void egl_fb_setup_for_tex(egl_fb *fb, int width, int height,
+                          GLuint texture, bool delete);
+void egl_fb_setup_new_tex(egl_fb *fb, int width, int height);
 void egl_fb_blit(egl_fb *dst, egl_fb *src, bool flip);
 void egl_fb_read(void *dst, egl_fb *src);
 

target/unicore32/helper.c

@@ -163,6 +163,12 @@ uint32_t helper_cp0_get(CPUUniCore32State *env, uint32_t creg, uint32_t cop)
 }
 
 #ifdef CONFIG_CURSES
+
+/* KEY_EVENT is defined in wincon.h and in curses.h. Avoid redefinition. */
+#undef KEY_EVENT
+#include <curses.h>
+#undef KEY_EVENT
+
 /*
  * FIXME:
  *     1. curses windows will be blank when switching back

ui/curses.c

@@ -33,6 +33,11 @@
 #include "ui/input.h"
 #include "sysemu/sysemu.h"
 
+/* KEY_EVENT is defined in wincon.h and in curses.h. Avoid redefinition. */
+#undef KEY_EVENT
+#include <curses.h>
+#undef KEY_EVENT
+
 #define FONT_HEIGHT 16
 #define FONT_WIDTH 8
 
@@ -42,16 +47,26 @@ static WINDOW *screenpad = NULL;
 static int width, height, gwidth, gheight, invalidate;
 static int px, py, sminx, sminy, smaxx, smaxy;
 
-chtype vga_to_curses[256];
+static chtype vga_to_curses[256];
 
 static void curses_update(DisplayChangeListener *dcl,
                           int x, int y, int w, int h)
 {
-    chtype *line;
+    console_ch_t *line;
+    chtype curses_line[width];
 
-    line = ((chtype *) screen) + y * width;
-    for (h += y; y < h; y ++, line += width)
-        mvwaddchnstr(screenpad, y, 0, line, width);
+    line = screen + y * width;
+    for (h += y; y < h; y ++, line += width) {
+        for (x = 0; x < width; x++) {
+            chtype ch = line[x] & 0xff;
+            chtype at = line[x] & ~0xff;
+            if (vga_to_curses[ch]) {
+                ch = vga_to_curses[ch];
+            }
+            curses_line[x] = ch | at;
+        }
+        mvwaddchnstr(screenpad, y, 0, curses_line, width);
+    }
 
     pnoutrefresh(screenpad, py, px, sminy, sminx, smaxy - 1, smaxx - 1);
     refresh();

ui/egl-headless.c

@@ -54,14 +54,14 @@ static void egl_scanout_texture(DisplayChangeListener *dcl,
     edpy->y_0_top = backing_y_0_top;
 
     /* source framebuffer */
-    egl_fb_create_for_tex(&edpy->guest_fb,
-                          backing_width, backing_height, backing_id);
+    egl_fb_setup_for_tex(&edpy->guest_fb,
+                         backing_width, backing_height, backing_id, false);
 
     /* dest framebuffer */
     if (edpy->blit_fb.width  != backing_width ||
         edpy->blit_fb.height != backing_height) {
         egl_fb_destroy(&edpy->blit_fb);
-        egl_fb_create_new_tex(&edpy->blit_fb, backing_width, backing_height);
+        egl_fb_setup_new_tex(&edpy->blit_fb, backing_width, backing_height);
     }
 }
 

ui/egl-helpers.c

@@ -26,16 +26,23 @@ EGLConfig qemu_egl_config;
 
 /* ------------------------------------------------------------------ */
 
-void egl_fb_destroy(egl_fb *fb)
+static void egl_fb_delete_texture(egl_fb *fb)
 {
-    if (!fb->framebuffer) {
+    if (!fb->delete_texture) {
         return;
     }
 
-    if (fb->delete_texture) {
     glDeleteTextures(1, &fb->texture);
     fb->delete_texture = false;
+}
+
+void egl_fb_destroy(egl_fb *fb)
+{
+    if (!fb->framebuffer) {
+        return;
     }
+
+    egl_fb_delete_texture(fb);
     glDeleteFramebuffers(1, &fb->framebuffer);
 
     fb->width = 0;
@@ -51,11 +58,15 @@ void egl_fb_setup_default(egl_fb *fb, int width, int height)
     fb->framebuffer = 0; /* default framebuffer */
 }
 
-void egl_fb_create_for_tex(egl_fb *fb, int width, int height, GLuint texture)
+void egl_fb_setup_for_tex(egl_fb *fb, int width, int height,
+                          GLuint texture, bool delete)
 {
+    egl_fb_delete_texture(fb);
+
     fb->width = width;
     fb->height = height;
     fb->texture = texture;
+    fb->delete_texture = delete;
     if (!fb->framebuffer) {
         glGenFramebuffers(1, &fb->framebuffer);
     }
@@ -65,7 +76,7 @@ void egl_fb_create_for_tex(egl_fb *fb, int width, int height, GLuint texture)
                               GL_TEXTURE_2D, fb->texture, 0);
 }
 
-void egl_fb_create_new_tex(egl_fb *fb, int width, int height)
+void egl_fb_setup_new_tex(egl_fb *fb, int width, int height)
 {
     GLuint texture;
 
@@ -74,8 +85,7 @@ void egl_fb_create_new_tex(egl_fb *fb, int width, int height)
     glTexImage2D(GL_TEXTURE_2D, 0, GL_RGB, width, height,
                  0, GL_BGRA, GL_UNSIGNED_BYTE, 0);
 
-    egl_fb_create_for_tex(fb, width, height, texture);
-    fb->delete_texture = true;
+    egl_fb_setup_for_tex(fb, width, height, texture, true);
 }
 
 void egl_fb_blit(egl_fb *dst, egl_fb *src, bool flip)

ui/gtk-egl.c

@@ -190,8 +190,8 @@ void gd_egl_scanout_texture(DisplayChangeListener *dcl,
                    vc->gfx.esurface, vc->gfx.ectx);
 
     gtk_egl_set_scanout_mode(vc, true);
-    egl_fb_create_for_tex(&vc->gfx.guest_fb, backing_width, backing_height,
-                          backing_id);
+    egl_fb_setup_for_tex(&vc->gfx.guest_fb, backing_width, backing_height,
+                         backing_id, false);
 }
 
 void gd_egl_scanout_flush(DisplayChangeListener *dcl,

ui/gtk-gl-area.c

@@ -185,8 +185,8 @@ void gd_gl_area_scanout_texture(DisplayChangeListener *dcl,
     }
 
     gtk_gl_area_set_scanout_mode(vc, true);
-    egl_fb_create_for_tex(&vc->gfx.guest_fb, backing_width, backing_height,
-                          backing_id);
+    egl_fb_setup_for_tex(&vc->gfx.guest_fb, backing_width, backing_height,
+                         backing_id, false);
 }
 
 void gd_gl_area_scanout_flush(DisplayChangeListener *dcl,

ui/sdl2-gl.c

@@ -207,8 +207,8 @@ void sdl2_gl_scanout_texture(DisplayChangeListener *dcl,
     SDL_GL_MakeCurrent(scon->real_window, scon->winctx);
 
     sdl2_set_scanout_mode(scon, true);
-    egl_fb_create_for_tex(&scon->guest_fb, backing_width, backing_height,
-                          backing_id);
+    egl_fb_setup_for_tex(&scon->guest_fb, backing_width, backing_height,
+                         backing_id, false);
 }
 
 void sdl2_gl_scanout_flush(DisplayChangeListener *dcl,

ui/trace-events

@@ -29,6 +29,27 @@ vnc_key_event_ext(bool down, int sym, int keycode, const char *name) "down %d, s
 vnc_key_event_map(bool down, int sym, int keycode, const char *name) "down %d, sym 0x%x -> keycode 0x%x [%s]"
 vnc_key_sync_numlock(bool on) "%d"
 vnc_key_sync_capslock(bool on) "%d"
+vnc_client_eof(void *state, void *ioc) "VNC client EOF state=%p ioc=%p"
+vnc_client_io_error(void *state, void *ioc, const char *msg) "VNC client I/O error state=%p ioc=%p errmsg=%s"
+vnc_client_connect(void *state, void *ioc) "VNC client connect state=%p ioc=%p"
+vnc_client_disconnect_start(void *state, void *ioc) "VNC client disconnect start state=%p ioc=%p"
+vnc_client_disconnect_finish(void *state, void *ioc) "VNC client disconnect finish state=%p ioc=%p"
+vnc_client_io_wrap(void *state, void *ioc, const char *type) "VNC client I/O wrap state=%p ioc=%p type=%s"
+vnc_auth_init(void *display, int websock, int auth, int subauth) "VNC auth init state=%p websock=%d auth=%d subauth=%d"
+vnc_auth_start(void *state, int method) "VNC client auth start state=%p method=%d"
+vnc_auth_pass(void *state, int method) "VNC client auth passed state=%p method=%d"
+vnc_auth_fail(void *state, int method, const char *message, const char *reason) "VNC client auth failed state=%p method=%d message=%s reason=%s"
+vnc_auth_reject(void *state, int expect, int got) "VNC client auth rejected state=%p method expected=%d got=%d"
+vnc_auth_vencrypt_version(void *state, int major, int minor) "VNC client auth vencrypt version state=%p major=%d minor=%d"
+vnc_auth_vencrypt_subauth(void *state, int auth) "VNC client auth vencrypt subauth state=%p auth=%d"
+vnc_auth_sasl_mech_list(void *state, const char *mechs) "VNC client auth SASL state=%p mechlist=%s"
+vnc_auth_sasl_mech_choose(void *state, const char *mech) "VNC client auth SASL state=%p mech=%s"
+vnc_auth_sasl_start(void *state, const void *clientdata, size_t clientlen, const void *serverdata, size_t severlen, int ret) "VNC client auth SASL start state=%p clientdata=%p clientlen=%zu serverdata=%p serverlen=%zu ret=%d"
+vnc_auth_sasl_step(void *state, const void *clientdata, size_t clientlen, const void *serverdata, size_t severlen, int ret) "VNC client auth SASL step state=%p clientdata=%p clientlen=%zu serverdata=%p serverlen=%zu ret=%d"
+vnc_auth_sasl_ssf(void *state, int ssf) "VNC client auth SASL SSF state=%p size=%d"
+vnc_auth_sasl_username(void *state, const char *name) "VNC client auth SASL user state=%p name=%s"
+vnc_auth_sasl_acl(void *state, int allow) "VNC client auth SASL ACL state=%p allow=%d"
+
 
 # ui/input.c
 input_event_key_number(int conidx, int number, const char *qcode, bool down) "con %d, key number 0x%x [%s], down %d"

ui/vnc-auth-sasl.c

@@ -25,6 +25,7 @@
 #include "qemu/osdep.h"
 #include "qapi/error.h"
 #include "vnc.h"
+#include "trace.h"
 
 /* Max amount of data we send/recv for SASL steps to prevent DOS */
 #define SASL_DATA_MAX_LEN (1024 * 1024)
@@ -133,27 +134,26 @@ static int vnc_auth_sasl_check_access(VncState *vs)
 
     err = sasl_getprop(vs->sasl.conn, SASL_USERNAME, &val);
     if (err != SASL_OK) {
-        VNC_DEBUG("cannot query SASL username on connection %d (%s), denying access\n",
-                  err, sasl_errstring(err, NULL, NULL));
+        trace_vnc_auth_fail(vs, vs->auth, "Cannot fetch SASL username",
+                            sasl_errstring(err, NULL, NULL));
         return -1;
     }
     if (val == NULL) {
-        VNC_DEBUG("no client username was found, denying access\n");
+        trace_vnc_auth_fail(vs, vs->auth, "No SASL username set", "");
         return -1;
     }
-    VNC_DEBUG("SASL client username %s\n", (const char *)val);
 
     vs->sasl.username = g_strdup((const char*)val);
+    trace_vnc_auth_sasl_username(vs, vs->sasl.username);
 
     if (vs->vd->sasl.acl == NULL) {
-        VNC_DEBUG("no ACL activated, allowing access\n");
+        trace_vnc_auth_sasl_acl(vs, 1);
         return 0;
     }
 
     allow = qemu_acl_party_is_allowed(vs->vd->sasl.acl, vs->sasl.username);
 
-    VNC_DEBUG("SASL client %s %s by ACL\n", vs->sasl.username,
-              allow ? "allowed" : "denied");
+    trace_vnc_auth_sasl_acl(vs, allow);
     return allow ? 0 : -1;
 }
 
@@ -170,7 +170,9 @@ static int vnc_auth_sasl_check_ssf(VncState *vs)
         return 0;
 
     ssf = *(const int *)val;
-    VNC_DEBUG("negotiated an SSF of %d\n", ssf);
+
+    trace_vnc_auth_sasl_ssf(vs, ssf);
+
     if (ssf < 56)
         return 0; /* 56 is good for Kerberos */
 
@@ -218,33 +220,28 @@ static int protocol_client_auth_sasl_step(VncState *vs, uint8_t *data, size_t le
         datalen--; /* Don't count NULL byte when passing to _start() */
     }
 
-    VNC_DEBUG("Step using SASL Data %p (%d bytes)\n",
-              clientdata, datalen);
     err = sasl_server_step(vs->sasl.conn,
                            clientdata,
                            datalen,
                            &serverout,
                            &serveroutlen);
+    trace_vnc_auth_sasl_step(vs, data, len, serverout, serveroutlen, err);
     if (err != SASL_OK &&
         err != SASL_CONTINUE) {
-        VNC_DEBUG("sasl step failed %d (%s)\n",
-                  err, sasl_errdetail(vs->sasl.conn));
+        trace_vnc_auth_fail(vs, vs->auth, "Cannot step SASL auth",
+                            sasl_errdetail(vs->sasl.conn));
         sasl_dispose(&vs->sasl.conn);
         vs->sasl.conn = NULL;
         goto authabort;
     }
 
     if (serveroutlen > SASL_DATA_MAX_LEN) {
-        VNC_DEBUG("sasl step reply data too long %d\n",
-                  serveroutlen);
+        trace_vnc_auth_fail(vs, vs->auth, "SASL data too long", "");
         sasl_dispose(&vs->sasl.conn);
         vs->sasl.conn = NULL;
         goto authabort;
     }
 
-    VNC_DEBUG("SASL return data %d bytes, nil; %d\n",
-              serveroutlen, serverout ? 0 : 1);
-
     if (serveroutlen) {
         vnc_write_u32(vs, serveroutlen + 1);
         vnc_write(vs, serverout, serveroutlen + 1);
@@ -256,22 +253,20 @@ static int protocol_client_auth_sasl_step(VncState *vs, uint8_t *data, size_t le
     vnc_write_u8(vs, err == SASL_CONTINUE ? 0 : 1);
 
     if (err == SASL_CONTINUE) {
-        VNC_DEBUG("%s", "Authentication must continue\n");
         /* Wait for step length */
         vnc_read_when(vs, protocol_client_auth_sasl_step_len, 4);
     } else {
         if (!vnc_auth_sasl_check_ssf(vs)) {
-            VNC_DEBUG("Authentication rejected for weak SSF %p\n", vs->ioc);
+            trace_vnc_auth_fail(vs, vs->auth, "SASL SSF too weak", "");
             goto authreject;
         }
 
         /* Check username whitelist ACL */
         if (vnc_auth_sasl_check_access(vs) < 0) {
-            VNC_DEBUG("Authentication rejected for ACL %p\n", vs->ioc);
             goto authreject;
         }
 
-        VNC_DEBUG("Authentication successful %p\n", vs->ioc);
+        trace_vnc_auth_pass(vs, vs->auth);
         vnc_write_u32(vs, 0); /* Accept auth */
         /*
          * Delay writing in SSF encoded mode until pending output
@@ -300,9 +295,9 @@ static int protocol_client_auth_sasl_step(VncState *vs, uint8_t *data, size_t le
 static int protocol_client_auth_sasl_step_len(VncState *vs, uint8_t *data, size_t len)
 {
     uint32_t steplen = read_u32(data, 0);
-    VNC_DEBUG("Got client step len %d\n", steplen);
+
     if (steplen > SASL_DATA_MAX_LEN) {
-        VNC_DEBUG("Too much SASL data %d\n", steplen);
+        trace_vnc_auth_fail(vs, vs->auth, "SASL step len too large", "");
         vnc_client_error(vs);
         return -1;
     }
@@ -346,33 +341,28 @@ static int protocol_client_auth_sasl_start(VncState *vs, uint8_t *data, size_t l
         datalen--; /* Don't count NULL byte when passing to _start() */
     }
 
-    VNC_DEBUG("Start SASL auth with mechanism %s. Data %p (%d bytes)\n",
-              vs->sasl.mechlist, clientdata, datalen);
     err = sasl_server_start(vs->sasl.conn,
                             vs->sasl.mechlist,
                             clientdata,
                             datalen,
                             &serverout,
                             &serveroutlen);
+    trace_vnc_auth_sasl_start(vs, data, len, serverout, serveroutlen, err);
     if (err != SASL_OK &&
         err != SASL_CONTINUE) {
-        VNC_DEBUG("sasl start failed %d (%s)\n",
-                  err, sasl_errdetail(vs->sasl.conn));
+        trace_vnc_auth_fail(vs, vs->auth, "Cannot start SASL auth",
+                            sasl_errdetail(vs->sasl.conn));
         sasl_dispose(&vs->sasl.conn);
         vs->sasl.conn = NULL;
         goto authabort;
     }
     if (serveroutlen > SASL_DATA_MAX_LEN) {
-        VNC_DEBUG("sasl start reply data too long %d\n",
-                  serveroutlen);
+        trace_vnc_auth_fail(vs, vs->auth, "SASL data too long", "");
         sasl_dispose(&vs->sasl.conn);
         vs->sasl.conn = NULL;
         goto authabort;
     }
 
-    VNC_DEBUG("SASL return data %d bytes, nil; %d\n",
-              serveroutlen, serverout ? 0 : 1);
-
     if (serveroutlen) {
         vnc_write_u32(vs, serveroutlen + 1);
         vnc_write(vs, serverout, serveroutlen + 1);
@@ -384,22 +374,20 @@ static int protocol_client_auth_sasl_start(VncState *vs, uint8_t *data, size_t l
     vnc_write_u8(vs, err == SASL_CONTINUE ? 0 : 1);
 
     if (err == SASL_CONTINUE) {
-        VNC_DEBUG("%s", "Authentication must continue\n");
         /* Wait for step length */
         vnc_read_when(vs, protocol_client_auth_sasl_step_len, 4);
     } else {
         if (!vnc_auth_sasl_check_ssf(vs)) {
-            VNC_DEBUG("Authentication rejected for weak SSF %p\n", vs->ioc);
+            trace_vnc_auth_fail(vs, vs->auth, "SASL SSF too weak", "");
             goto authreject;
         }
 
         /* Check username whitelist ACL */
         if (vnc_auth_sasl_check_access(vs) < 0) {
-            VNC_DEBUG("Authentication rejected for ACL %p\n", vs->ioc);
             goto authreject;
         }
 
-        VNC_DEBUG("Authentication successful %p\n", vs->ioc);
+        trace_vnc_auth_pass(vs, vs->auth);
         vnc_write_u32(vs, 0); /* Accept auth */
         start_client_init(vs);
     }
@@ -422,9 +410,9 @@ static int protocol_client_auth_sasl_start(VncState *vs, uint8_t *data, size_t l
 static int protocol_client_auth_sasl_start_len(VncState *vs, uint8_t *data, size_t len)
 {
     uint32_t startlen = read_u32(data, 0);
-    VNC_DEBUG("Got client start len %d\n", startlen);
+
     if (startlen > SASL_DATA_MAX_LEN) {
-        VNC_DEBUG("Too much SASL data %d\n", startlen);
+        trace_vnc_auth_fail(vs, vs->auth, "SASL start len too large", "");
         vnc_client_error(vs);
         return -1;
     }
@@ -439,22 +427,18 @@ static int protocol_client_auth_sasl_start_len(VncState *vs, uint8_t *data, size
 static int protocol_client_auth_sasl_mechname(VncState *vs, uint8_t *data, size_t len)
 {
     char *mechname = g_strndup((const char *) data, len);
-    VNC_DEBUG("Got client mechname '%s' check against '%s'\n",
-              mechname, vs->sasl.mechlist);
+    trace_vnc_auth_sasl_mech_choose(vs, mechname);
 
     if (strncmp(vs->sasl.mechlist, mechname, len) == 0) {
         if (vs->sasl.mechlist[len] != '\0' &&
             vs->sasl.mechlist[len] != ',') {
-            VNC_DEBUG("One %d", vs->sasl.mechlist[len]);
             goto fail;
         }
     } else {
         char *offset = strstr(vs->sasl.mechlist, mechname);
-        VNC_DEBUG("Two %p\n", offset);
         if (!offset) {
             goto fail;
         }
-        VNC_DEBUG("Two '%s'\n", offset);
         if (offset[-1] != ',' ||
             (offset[len] != '\0'&&
              offset[len] != ',')) {
@@ -465,11 +449,11 @@ static int protocol_client_auth_sasl_mechname(VncState *vs, uint8_t *data, size_
     g_free(vs->sasl.mechlist);
     vs->sasl.mechlist = mechname;
 
-    VNC_DEBUG("Validated mechname '%s'\n", mechname);
     vnc_read_when(vs, protocol_client_auth_sasl_start_len, 4);
     return 0;
 
  fail:
+    trace_vnc_auth_fail(vs, vs->auth, "Unsupported mechname", mechname);
     vnc_client_error(vs);
     g_free(mechname);
     return -1;
@@ -478,14 +462,14 @@ static int protocol_client_auth_sasl_mechname(VncState *vs, uint8_t *data, size_
 static int protocol_client_auth_sasl_mechname_len(VncState *vs, uint8_t *data, size_t len)
 {
     uint32_t mechlen = read_u32(data, 0);
-    VNC_DEBUG("Got client mechname len %d\n", mechlen);
+
     if (mechlen > 100) {
-        VNC_DEBUG("Too long SASL mechname data %d\n", mechlen);
+        trace_vnc_auth_fail(vs, vs->auth, "SASL mechname too long", "");
         vnc_client_error(vs);
         return -1;
     }
     if (mechlen < 1) {
-        VNC_DEBUG("Too short SASL mechname %d\n", mechlen);
+        trace_vnc_auth_fail(vs, vs->auth, "SASL mechname too short", "");
         vnc_client_error(vs);
         return -1;
     }
@@ -524,19 +508,22 @@ void start_auth_sasl(VncState *vs)
     const char *mechlist = NULL;
     sasl_security_properties_t secprops;
     int err;
+    Error *local_err = NULL;
     char *localAddr, *remoteAddr;
     int mechlistlen;
 
-    VNC_DEBUG("Initialize SASL auth %p\n", vs->ioc);
-
     /* Get local & remote client addresses in form  IPADDR;PORT */
-    localAddr = vnc_socket_ip_addr_string(vs->sioc, true, NULL);
+    localAddr = vnc_socket_ip_addr_string(vs->sioc, true, &local_err);
     if (!localAddr) {
+        trace_vnc_auth_fail(vs, vs->auth, "Cannot format local IP",
+                            error_get_pretty(local_err));
         goto authabort;
     }
 
-    remoteAddr = vnc_socket_ip_addr_string(vs->sioc, false, NULL);
+    remoteAddr = vnc_socket_ip_addr_string(vs->sioc, false, &local_err);
     if (!remoteAddr) {
+        trace_vnc_auth_fail(vs, vs->auth, "Cannot format remote IP",
+                            error_get_pretty(local_err));
         g_free(localAddr);
         goto authabort;
     }
@@ -554,8 +541,8 @@ void start_auth_sasl(VncState *vs)
     localAddr = remoteAddr = NULL;
 
     if (err != SASL_OK) {
-        VNC_DEBUG("sasl context setup failed %d (%s)",
-                  err, sasl_errstring(err, NULL, NULL));
+        trace_vnc_auth_fail(vs, vs->auth,  "SASL context setup failed",
+                            sasl_errstring(err, NULL, NULL));
         vs->sasl.conn = NULL;
         goto authabort;
     }
@@ -570,7 +557,7 @@ void start_auth_sasl(VncState *vs)
         keysize = qcrypto_tls_session_get_key_size(vs->tls,
                                                    &local_err);
         if (keysize < 0) {
-            VNC_DEBUG("cannot TLS get cipher size: %s\n",
+            trace_vnc_auth_fail(vs, vs->auth, "cannot TLS get cipher size",
                                 error_get_pretty(local_err));
             error_free(local_err);
             sasl_dispose(&vs->sasl.conn);
@@ -581,8 +568,8 @@ void start_auth_sasl(VncState *vs)
 
         err = sasl_setprop(vs->sasl.conn, SASL_SSF_EXTERNAL, &ssf);
         if (err != SASL_OK) {
-            VNC_DEBUG("cannot set SASL external SSF %d (%s)\n",
-                      err, sasl_errstring(err, NULL, NULL));
+            trace_vnc_auth_fail(vs, vs->auth, "cannot set SASL external SSF",
+                                sasl_errstring(err, NULL, NULL));
             sasl_dispose(&vs->sasl.conn);
             vs->sasl.conn = NULL;
             goto authabort;
@@ -617,8 +604,8 @@ void start_auth_sasl(VncState *vs)
 
     err = sasl_setprop(vs->sasl.conn, SASL_SEC_PROPS, &secprops);
     if (err != SASL_OK) {
-        VNC_DEBUG("cannot set SASL security props %d (%s)\n",
-                  err, sasl_errstring(err, NULL, NULL));
+        trace_vnc_auth_fail(vs, vs->auth, "cannot set SASL security props",
+                            sasl_errstring(err, NULL, NULL));
         sasl_dispose(&vs->sasl.conn);
         vs->sasl.conn = NULL;
         goto authabort;
@@ -633,13 +620,13 @@ void start_auth_sasl(VncState *vs)
                         NULL,
                         NULL);
     if (err != SASL_OK) {
-        VNC_DEBUG("cannot list SASL mechanisms %d (%s)\n",
-                  err, sasl_errdetail(vs->sasl.conn));
+        trace_vnc_auth_fail(vs, vs->auth, "cannot list SASL mechanisms",
+                            sasl_errdetail(vs->sasl.conn));
         sasl_dispose(&vs->sasl.conn);
         vs->sasl.conn = NULL;
         goto authabort;
     }
-    VNC_DEBUG("Available mechanisms for client: '%s'\n", mechlist);
+    trace_vnc_auth_sasl_mech_list(vs, mechlist);
 
     vs->sasl.mechlist = g_strdup(mechlist);
     mechlistlen = strlen(mechlist);
@@ -647,12 +634,12 @@ void start_auth_sasl(VncState *vs)
     vnc_write(vs, mechlist, mechlistlen);
     vnc_flush(vs);
 
-    VNC_DEBUG("Wait for client mechname length\n");
     vnc_read_when(vs, protocol_client_auth_sasl_mechname_len, 4);
 
     return;
 
  authabort:
+    error_free(local_err);
     vnc_client_error(vs);
 }
 

ui/vnc-auth-vencrypt.c

@@ -28,33 +28,31 @@
 #include "vnc.h"
 #include "qapi/error.h"
 #include "qemu/main-loop.h"
+#include "trace.h"
 
 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";
@@ -72,7 +70,7 @@ static void vnc_tls_handshake_done(QIOTask *task,
     Error *err = NULL;
 
     if (qio_task_propagate_error(task, &err)) {
-        VNC_DEBUG("Handshake failed %s\n",
+        trace_vnc_auth_fail(vs, vs->auth, "TLS handshake failed",
                             error_get_pretty(err));
         vnc_client_error(vs);
         error_free(err);
@@ -88,15 +86,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);
 
@@ -111,16 +109,17 @@ 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");
         vs->tls = qio_channel_tls_get_session(tls);
 
         qio_channel_tls_handshake(tls,
@@ -133,14 +132,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 */

ui/vnc-ws.c

@@ -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)
@@ -50,7 +51,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;
@@ -70,9 +70,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,
@@ -110,7 +110,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;
@@ -121,6 +120,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,

ui/vnc.c

@@ -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);
@@ -1130,6 +1131,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);
@@ -1183,11 +1186,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);
         }
 
@@ -2402,11 +2406,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;
     }
 
@@ -2423,7 +2427,7 @@ 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",
+        trace_vnc_auth_fail(vs, vs->auth, "cannot create cipher",
                             error_get_pretty(err));
         error_free(err);
         goto reject;
@@ -2434,7 +2438,7 @@ 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",
+        trace_vnc_auth_fail(vs, vs->auth, "cannot encrypt challenge response",
                             error_get_pretty(err));
         error_free(err);
         goto reject;
@@ -2442,10 +2446,10 @@ static int protocol_client_auth_vnc(VncState *vs, uint8_t *data, size_t len)
 
     /* 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);
 
@@ -2484,7 +2488,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";
@@ -2493,36 +2497,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";
@@ -2567,10 +2568,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");
@@ -2578,13 +2580,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);
@@ -2884,6 +2886,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);
@@ -3937,12 +3940,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) {