* [Qemu-devel] [PATCH 0/2] Add more trace points to VNC code
@ 2017-09-21 12:15 Daniel P. Berrange
2017-09-21 12:15 ` [Qemu-devel] [PATCH 1/2] ui: add tracing of VNC operations related to QIOChannel Daniel P. Berrange
2017-09-21 12:15 ` [Qemu-devel] [PATCH 2/2] ui: add tracing of VNC authentication process Daniel P. Berrange
0 siblings, 2 replies; 3+ messages in thread
From: Daniel P. Berrange @ 2017-09-21 12:15 UTC (permalink / raw)
To: qemu-devel; +Cc: Gerd Hoffmann, Daniel P. Berrange
Add many more trace points to the VNC server, removing a bunch of
VNC_DEBUG lines where appropriate
Daniel P. Berrange (2):
ui: add tracing of VNC operations related to QIOChannel
ui: add tracing of VNC authentication process
ui/trace-events | 21 +++++++++
ui/vnc-auth-sasl.c | 113 ++++++++++++++++++++++---------------------------
ui/vnc-auth-vencrypt.c | 23 +++++-----
ui/vnc-ws.c | 6 +--
ui/vnc.c | 47 +++++++++++---------
5 files changed, 111 insertions(+), 99 deletions(-)
--
2.13.5
^ permalink raw reply [flat|nested] 3+ messages in thread
* [Qemu-devel] [PATCH 1/2] ui: add tracing of VNC operations related to QIOChannel
2017-09-21 12:15 [Qemu-devel] [PATCH 0/2] Add more trace points to VNC code Daniel P. Berrange
@ 2017-09-21 12:15 ` Daniel P. Berrange
2017-09-21 12:15 ` [Qemu-devel] [PATCH 2/2] ui: add tracing of VNC authentication process Daniel P. Berrange
1 sibling, 0 replies; 3+ messages in thread
From: Daniel P. Berrange @ 2017-09-21 12:15 UTC (permalink / raw)
To: qemu-devel; +Cc: Gerd Hoffmann, Daniel P. Berrange
Trace anything which opens/closes/wraps a QIOChannel in the
VNC server.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
---
ui/trace-events | 6 ++++++
ui/vnc-auth-vencrypt.c | 2 ++
ui/vnc-ws.c | 6 +++---
ui/vnc.c | 11 ++++++++---
4 files changed, 19 insertions(+), 6 deletions(-)
diff --git a/ui/trace-events b/ui/trace-events
index 34c2213700..e4c02e47f5 100644
--- a/ui/trace-events
+++ b/ui/trace-events
@@ -29,6 +29,12 @@ 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"
# 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-vencrypt.c b/ui/vnc-auth-vencrypt.c
index c3eece4fa7..2a3766aa64 100644
--- a/ui/vnc-auth-vencrypt.c
+++ b/ui/vnc-auth-vencrypt.c
@@ -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,
diff --git a/ui/vnc-ws.c b/ui/vnc-ws.c
index eaf309553c..6ccad22cef 100644
--- a/ui/vnc-ws.c
+++ b/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)
@@ -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,
diff --git a/ui/vnc.c b/ui/vnc.c
index 62f7a3f30a..47dacc47b6 100644
--- a/ui/vnc.c
+++ b/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);
@@ -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);
--
2.13.5
^ permalink raw reply related [flat|nested] 3+ messages in thread
* [Qemu-devel] [PATCH 2/2] ui: add tracing of VNC authentication process
2017-09-21 12:15 [Qemu-devel] [PATCH 0/2] Add more trace points to VNC code Daniel P. Berrange
2017-09-21 12:15 ` [Qemu-devel] [PATCH 1/2] ui: add tracing of VNC operations related to QIOChannel Daniel P. Berrange
@ 2017-09-21 12:15 ` Daniel P. Berrange
1 sibling, 0 replies; 3+ messages in thread
From: Daniel P. Berrange @ 2017-09-21 12:15 UTC (permalink / raw)
To: qemu-devel; +Cc: Gerd Hoffmann, Daniel P. Berrange
Trace anything related to authentication in the VNC protocol
handshake
Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
---
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 e4c02e47f5..1a9f126330 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 3ade4a4918..23f28280e7 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 2a3766aa64..7833631275 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 47dacc47b6..9f8d5a1b1f 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")) != SASL_OK) {
--
2.13.5
^ permalink raw reply related [flat|nested] 3+ messages in thread
end of thread, other threads:[~2017-09-21 12:15 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-09-21 12:15 [Qemu-devel] [PATCH 0/2] Add more trace points to VNC code Daniel P. Berrange
2017-09-21 12:15 ` [Qemu-devel] [PATCH 1/2] ui: add tracing of VNC operations related to QIOChannel Daniel P. Berrange
2017-09-21 12:15 ` [Qemu-devel] [PATCH 2/2] ui: add tracing of VNC authentication process Daniel P. Berrange
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.