From e8107b68c8a2ff9f73ef18b8c1f8aa9184fbe7f7 Mon Sep 17 00:00:00 2001
From: Tatsuhiro Tsujikawa <tatsuhiro.t@gmail.com>
Date: Tue, 6 Jan 2015 23:10:11 +0900
Subject: [PATCH] nghttpx: Avoid std::chrono::high_resolution_clock as wall
 clock

This is because std::chrono::high_resolution_clock may not be wall
clock; it may be alias of std::chrono::stead_clock.
---
 src/shrpx_client_handler.cc | 25 ++++++++++++++-----------
 src/shrpx_log.cc            |  2 +-
 src/shrpx_log.h             |  3 ++-
 3 files changed, 17 insertions(+), 13 deletions(-)

diff --git a/src/shrpx_client_handler.cc b/src/shrpx_client_handler.cc
index c00b534e..979d8683 100644
--- a/src/shrpx_client_handler.cc
+++ b/src/shrpx_client_handler.cc
@@ -865,8 +865,9 @@ void ClientHandler::write_accesslog(Downstream *downstream) {
 
       alpn_.c_str(),
 
-      downstream->get_request_start_time(),
-      std::chrono::high_resolution_clock::now(),
+      std::chrono::system_clock::now(),          // time_now
+      downstream->get_request_start_time(),      // request_start_time
+      std::chrono::high_resolution_clock::now(), // request_end_time
 
       downstream->get_request_major(), downstream->get_request_minor(),
       downstream->get_response_http_status(),
@@ -879,18 +880,20 @@ void ClientHandler::write_accesslog(Downstream *downstream) {
 
 void ClientHandler::write_accesslog(int major, int minor, unsigned int status,
                                     int64_t body_bytes_sent) {
+  auto time_now = std::chrono::system_clock::now();
+  auto highres_now = std::chrono::high_resolution_clock::now();
+
   LogSpec lgsp = {
-      nullptr,                                   ipaddr_.c_str(),
+      nullptr,            ipaddr_.c_str(),
       "-", // method
       "-", // path,
-      alpn_.c_str(),
-      std::chrono::high_resolution_clock::now(), // request_start_time TODO is
-                                                 // there a better value?
-      std::chrono::high_resolution_clock::now(), // time_now
-      major,                                     minor, // major, minor
-      status,                                    body_bytes_sent,
-      port_.c_str(),                             get_config()->port,
-      get_config()->pid,
+      alpn_.c_str(),      time_now,
+      highres_now,               // request_start_time TODO is
+                                 // there a better value?
+      highres_now,               // request_end_time
+      major,              minor, // major, minor
+      status,             body_bytes_sent,   port_.c_str(),
+      get_config()->port, get_config()->pid,
   };
 
   upstream_accesslog(get_config()->accesslog_format, &lgsp);
diff --git a/src/shrpx_log.cc b/src/shrpx_log.cc
index 8e5a0c26..a7b517f7 100644
--- a/src/shrpx_log.cc
+++ b/src/shrpx_log.cc
@@ -224,7 +224,7 @@ void upstream_accesslog(const std::vector<LogFragment> &lfv, LogSpec *lgsp) {
       break;
     case SHRPX_LOGF_REQUEST_TIME: {
       auto t = std::chrono::duration_cast<std::chrono::milliseconds>(
-                   lgsp->time_now - lgsp->request_start_time).count();
+                   lgsp->request_end_time - lgsp->request_start_time).count();
 
       auto frac = util::utos(t % 1000);
       auto sec = util::utos(t / 1000);
diff --git a/src/shrpx_log.h b/src/shrpx_log.h
index 901f022a..e4da4305 100644
--- a/src/shrpx_log.h
+++ b/src/shrpx_log.h
@@ -126,8 +126,9 @@ struct LogSpec {
   const char *method;
   const char *path;
   const char *alpn;
+  std::chrono::system_clock::time_point time_now;
   std::chrono::high_resolution_clock::time_point request_start_time;
-  std::chrono::high_resolution_clock::time_point time_now;
+  std::chrono::high_resolution_clock::time_point request_end_time;
   int major, minor;
   unsigned int status;
   int64_t body_bytes_sent;