[jira] [Comment Edited] (GUACAMOLE-259) Log metrics for gauging user experience

["Michael Jumper (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/GUACAMOLE-259?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15948643#comment-15948643 ] 

Michael Jumper edited comment on GUACAMOLE-259 at 3/30/17 8:21 AM:
-------------------------------------------------------------------

I've added a TRACE log level, and messages like:

{code:none}
...
guacd[26565]: TRACE:	Server completed frame 968247885ms.
guacd[26565]: TRACE:	User confirmation of frame 968247885ms received at 968247907ms (processing_lag=8ms)
guacd[26565]: TRACE:	Server completed frame 968248118ms.
guacd[26565]: TRACE:	Server completed frame 968248126ms.
...
{code}

Pulling the timing information from the logs and graphing each for a test RDP connection:

 !guacamole-frame-timing-example.png|width=100%!

Bottom axis is the number of frames rendered at that point in time. You can see:

# The client and server stay pretty close to each other with respect to frame time.
# The calculated "processing lag" (estimated time spent by the client rendering a frame) is shifted from "round trip time" (total time between the end of a frame and receipt of the client's response for that frame) by a generally-constant amount (the network lag).

The nice constant shift between RTT and the processing lag approximation makes me happy, as it suggests that those calculations are working exactly as intended. The client takes longer for more complex operations, the server compensates accordingly, and both stay in time with each other, independent of network delays (network latency results only in latency, not reduced framerate/smoothness).


was (Author: mike.jumper):
I've added a TRACE log level, and messages like:

{code:none}
...
guacd[26565]: TRACE:	Server completed frame 968247885ms.
guacd[26565]: TRACE:	User confirmation of frame 968247885ms received at 968247907ms (processing_lag=8ms)
guacd[26565]: TRACE:	Server completed frame 968248118ms.
guacd[26565]: TRACE:	Server completed frame 968248126ms.
...
{code}

Pulling the timing information from the logs and graphing each for a test RDP connection:

 !guacamole-frame-timing-example.png|width=100%!

Bottom access is the number of frames rendered at that point in time. You can see:

# The client and server stay pretty close to each other with respect to frame time.
# The calculated "processing lag" (estimated time spent by the client rendering a frame) is shifted from "round trip time" (total time between the end of a frame and receipt of the client's response for that frame) by a generally-constant amount (the network lag).

The nice constant shift between RTT and the processing lag approximation makes me happy, as it suggests that those calculations are working exactly as intended. The client takes longer for more complex operations, the server compensates accordingly, and both stay in time with each other, independent of network delays (network latency results only in latency, not reduced framerate/smoothness).

> Log metrics for gauging user experience
> ---------------------------------------
>
>                 Key: GUACAMOLE-259
>                 URL: https://issues.apache.org/jira/browse/GUACAMOLE-259
>             Project: Guacamole
>          Issue Type: Improvement
>          Components: guacamole-server
>            Reporter: Michael Jumper
>            Assignee: Michael Jumper
>            Priority: Minor
>         Attachments: guacamole-frame-timing-example.png
>
>
> guacd currently logs information primarily geared toward debugging issues with the remote desktop itself, but does not log anything which can be used to debug issues with user experience. If a user becomes unresponsive, a message is logged accordingly, but there is no way to know that the remote desktop connection itself was still responsive, that frames are only being withheld due to network conditions, etc.
> guacd should be modified such that user experience and the server-side responsiveness of the remote desktop can be objectively measured.



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)