proxy: log time now relative to resp lifetime

Originally I envisioned taking an inbound request object, tagging it
with the time, and at the very end of a function logging is called. This
would give you the total time of the "backend" part of a request.

On rethinking, the timing information that's most useful in the proxy's
perspective is the time it takes for a response to happen + the status
of a response. One request may generate several sub-responses and it is
impossible to check the timing of each of those and log outliers.

You now cannot get the total time elapsed in a function anymore, but I
believe that is less useful information to the user of a proxy. The best
picture of latency will still be from the client, and response latency
can educate the proxy on issues with backends.

resp:elapsed() has been added as a compromise; it returns the elapsed
microseconds that a response took, so you can add the time together and
get an approximation of total time (if running req/resp's sequentially).

This change also means that calling mcp.await() and waiting for multiple
responses will give the timing of each sub-response accurately.

1 files changed, 2 insertions, 1 deletions

diff --git a/proxy.h b/proxy.h
index dbd217e..c5a42fb 100644
--- a/proxy.h
+++ b/proxy.h
@@ -281,7 +281,6 @@ struct mcp_parser_s {
 #define MAX_REQ_TOKENS 2
 struct mcp_request_s {
     mcp_parser_t pr; // non-lua-specific parser handling.
-    struct timeval start; // time this object was created.
     mcp_backend_t *be; // backend handling this request.
     bool ascii_multiget; // ascii multiget mode. (hide errors/END)
     bool was_modified; // need to rewrite the request
@@ -396,6 +395,8 @@ typedef struct {
     mcmc_resp_t resp;
     char *buf; // response line + potentially value.
     size_t blen; // total size of the value to read.
+    struct timeval start; // time this object was created.
+    long elapsed; // time elapsed once handled.
     int status; // status code from mcmc_read()
     int bread; // amount of bytes read into value so far.
     uint8_t cmd; // from parser (pr.command)