From 7f7ef9a4bfbbc093139dbb4ba7fb1721db1ebbef Mon Sep 17 00:00:00 2001
From: Jason Volk <jason@zemos.net>
Date: Sat, 23 Sep 2017 19:46:17 -0700
Subject: [PATCH] ircd: Add client request timer related.

---
 include/ircd/client.h |  1 +
 ircd/client.cc        |  5 ++++-
 ircd/resource.cc      | 13 +++++++------
 3 files changed, 12 insertions(+), 7 deletions(-)

diff --git a/include/ircd/client.h b/include/ircd/client.h
index dc46f36f1..a6e7790f6 100644
--- a/include/ircd/client.h
+++ b/include/ircd/client.h
@@ -56,6 +56,7 @@ struct ircd::client
 
 	unique_const_iterator<list> clit;
 	std::shared_ptr<socket> sock;
+	ircd::timer request_timer;
 
 	bool main() noexcept;
 
diff --git a/ircd/client.cc b/ircd/client.cc
index 46eb7b270..c68fdfe0a 100644
--- a/ircd/client.cc
+++ b/ircd/client.cc
@@ -232,6 +232,7 @@ ircd::client::client(const host_port &host_port,
 ircd::client::client(std::shared_ptr<socket> sock)
 :clit{clients, clients.emplace(end(clients), this)}
 ,sock{std::move(sock)}
+,request_timer{ircd::timer::stopped}
 {
 }
 
@@ -310,6 +311,7 @@ ircd::handle_request(client &client,
                      parse::capstan &pc)
 try
 {
+	client.request_timer = ircd::timer{};
 	client.sock->set_timeout(request_timeout, [&client]
 	(const error_code &ec)
 	{
@@ -331,9 +333,10 @@ try
 }
 catch(const http::error &e)
 {
-	log::debug("client[%s] HTTP %s %s",
+	log::debug("client[%s] HTTP %s in %ld$us %s",
 	           string(remote_addr(client)),
 	           e.what(),
+	           client.request_timer.at<microseconds>().count(),
 	           e.content);
 
 	switch(e.code)
diff --git a/ircd/resource.cc b/ircd/resource.cc
index ee6921ae3..3b5b437f7 100644
--- a/ircd/resource.cc
+++ b/ircd/resource.cc
@@ -359,13 +359,14 @@ ircd::resource::response::response(client &client,
 		}
 	};
 
-	log::debug("client[%s] HTTP %d %s (%s) content-length: %zu %s...",
+	log::debug("client[%s] HTTP %d %s in %ld$us (%s) content-length: %zu %s...",
 	           string(remote_addr(client)),
 	           int(code),
                http::reason[code],
-               content_type,
-               str.size(),
-               startswith(content_type, "text") ||
-               content_type == "application/json" ||
-               content_type == "application/javascript"? str.substr(0, 96) : string_view{});
+	           client.request_timer.at<microseconds>().count(),
+	           content_type,
+	           str.size(),
+	           startswith(content_type, "text") ||
+	           content_type == "application/json" ||
+	           content_type == "application/javascript"? str.substr(0, 96) : string_view{});
 }