From 1081131aa5151e4e8546823b26212a2b598bcba3 Mon Sep 17 00:00:00 2001
From: Michael Jumper <mjumper@apache.org>
Date: Wed, 29 Mar 2017 22:32:26 -0700
Subject: [PATCH] GUACAMOLE-259: Log server and user frame timing information
 at TRACE level.

---
 src/libguac/client.c        | 6 ++++++
 src/libguac/user-handlers.c | 7 +++++++
 2 files changed, 13 insertions(+)

diff --git a/src/libguac/client.c b/src/libguac/client.c
index a88de74d..4f3051d9 100644
--- a/src/libguac/client.c
+++ b/src/libguac/client.c
@@ -35,6 +35,7 @@
 #include "user.h"
 
 #include <dlfcn.h>
+#include <inttypes.h>
 #include <pthread.h>
 #include <stdarg.h>
 #include <stdio.h>
@@ -414,6 +415,11 @@ int guac_client_end_frame(guac_client* client) {
 
     /* Update and send timestamp */
     client->last_sent_timestamp = guac_timestamp_current();
+
+    /* Log received timestamp and calculated lag (at TRACE level only) */
+    guac_client_log(client, GUAC_LOG_TRACE, "Server completed "
+            "frame %" PRIu64 "ms.", client->last_sent_timestamp);
+
     return guac_protocol_send_sync(client->socket, client->last_sent_timestamp);
 
 }
diff --git a/src/libguac/user-handlers.c b/src/libguac/user-handlers.c
index 4f1f59b0..0e8ed38b 100644
--- a/src/libguac/user-handlers.c
+++ b/src/libguac/user-handlers.c
@@ -27,6 +27,7 @@
 #include "user.h"
 #include "user-handlers.h"
 
+#include <inttypes.h>
 #include <stdio.h>
 #include <stdint.h>
 #include <stdlib.h>
@@ -124,6 +125,12 @@ int __guac_handle_sync(guac_user* user, int argc, char** argv) {
 
     }
 
+    /* Log received timestamp and calculated lag (at TRACE level only) */
+    guac_user_log(user, GUAC_LOG_TRACE,
+            "User confirmation of frame %" PRIu64 "ms received "
+            "at %" PRIu64 "ms (processing_lag=%ims)",
+            timestamp, current, user->processing_lag);
+
     if (user->sync_handler)
         return user->sync_handler(user, timestamp);
     return 0;