From d22fb15220016b86cca81f73f27c748f5a5c1183 Mon Sep 17 00:00:00 2001 From: "Daniel P. Berrange" Date: Mon, 5 Feb 2018 11:09:57 +0100 Subject: [PATCH 03/20] ui: add tracing of VNC authentication process RH-Author: Daniel P. Berrange Message-id: <20180205111012.6210-3-berrange@redhat.com> Patchwork-id: 78881 O-Subject: [RHV-7.5 qemu-kvm-rhev PATCH v2 02/17] ui: add tracing of VNC authentication process Bugzilla: 1527404 RH-Acked-by: Gerd Hoffmann RH-Acked-by: Laszlo Ersek RH-Acked-by: Thomas Huth From: "Daniel P. Berrange" Trace anything related to authentication in the VNC protocol handshake Signed-off-by: Daniel P. Berrange Message-id: 20170921121528.23935-3-berrange@redhat.com Signed-off-by: Gerd Hoffmann (cherry picked from commit 7364dbdabb7824d5bde1e341bb6d928282f01c83) Signed-off-by: Miroslav Rezanina --- ui/trace-events | 15 +++++++ ui/vnc-auth-sasl.c | 113 ++++++++++++++++++++++--------------------------- ui/vnc-auth-vencrypt.c | 21 ++++----- ui/vnc.c | 36 ++++++++-------- 4 files changed, 92 insertions(+), 93 deletions(-) diff --git a/ui/trace-events b/ui/trace-events index e4c02e4..1a9f126 100644 --- a/ui/trace-events +++ b/ui/trace-events @@ -35,6 +35,21 @@ 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" diff --git a/ui/vnc-auth-sasl.c b/ui/vnc-auth-sasl.c index 3ade4a4..23f2828 100644 --- a/ui/vnc-auth-sasl.c +++ b/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,8 +557,8 @@ 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", - error_get_pretty(local_err)); + 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); vs->sasl.conn = NULL; @@ -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); } diff --git a/ui/vnc-auth-vencrypt.c b/ui/vnc-auth-vencrypt.c index 2a3766a..7833631 100644 --- a/ui/vnc-auth-vencrypt.c +++ b/ui/vnc-auth-vencrypt.c @@ -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 */ diff --git a/ui/vnc.c b/ui/vnc.c index 66783ec..1275bba 100644 --- a/ui/vnc.c +++ b/ui/vnc.c @@ -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-kvm")) != SASL_OK) { -- 1.8.3.1