rgw: use coarse_real_clock for req_state::time

Signed-off-by: Casey Bodley <cbodley@redhat.com>
(cherry picked from commit d9284902e1b2e292595696caf11cdead18acec96)

diff --git a/src/rgw/rgw_admin.cc b/src/rgw/rgw_admin.cc
index 6f6de2f29cd0bf45da4968f95c24ed43af384180..65424f7716e929233e522cd5d31e56c5c0a73fa4 100644 (file)
--- a/src/rgw/rgw_admin.cc
+++ b/src/rgw/rgw_admin.cc
@@ -5518,7 +5518,8 @@ int main(int argc, const char **argv)
         formatter->open_array_section("log_entries");
 
       do {
-       uint64_t total_time =  entry.total_time.to_msec();
+        using namespace std::chrono;
+        uint64_t total_time = duration_cast<milliseconds>(entry.total_time).count();
 
         agg_time += total_time;
         agg_bytes_sent += entry.bytes_sent;

diff --git a/src/rgw/rgw_common.cc b/src/rgw/rgw_common.cc
index b4eb0c846a69db112cc87004aa397ea3e9a7f5ca..a296c7a8f6d9a6af9640eb845db940537235ab98 100644 (file)
--- a/src/rgw/rgw_common.cc
+++ b/src/rgw/rgw_common.cc
@@ -284,7 +284,7 @@ req_state::req_state(CephContext* _cct, RGWEnv* e, RGWUserInfo* u)
   enable_usage_log = e->get_enable_usage_log();
   defer_to_bucket_acls = e->get_defer_to_bucket_acls();
 
-  time = ceph_clock_now();
+  time = Clock::now();
 }
 
 req_state::~req_state() {

diff --git a/src/rgw/rgw_common.h b/src/rgw/rgw_common.h
index 2dd5683d89e8d46e6e221ae0a1a51512f12d7c08..499c63b022924c8f831efd5b9397c5ac7c75ccad 100644 (file)
--- a/src/rgw/rgw_common.h
+++ b/src/rgw/rgw_common.h
@@ -1886,7 +1886,11 @@ struct req_state {
   req_info info;
   req_init_state init_state;
 
-  utime_t time;
+  using Clock = ceph::coarse_real_clock;
+  Clock::time_point time;
+
+  Clock::duration time_elapsed() const { return Clock::now() - time; }
+
   void *obj_ctx{nullptr};
   string dialect;
   string req_id;

diff --git a/src/rgw/rgw_file.cc b/src/rgw/rgw_file.cc
index c7795b4a187a48fe633569091f8ef93239bad651..7fd5790dcbd370a8f8e6761087e4500b1be51fba 100644 (file)
--- a/src/rgw/rgw_file.cc
+++ b/src/rgw/rgw_file.cc
@@ -1511,8 +1511,7 @@ namespace rgw {
 
   done:
     dispose_processor(processor);
-    perfcounter->tinc(l_rgw_put_lat,
-                     (ceph_clock_now() - s->time));
+    perfcounter->tinc(l_rgw_put_lat, s->time_elapsed());
     return op_ret;
   } /* exec_finish */
 

diff --git a/src/rgw/rgw_log.cc b/src/rgw/rgw_log.cc
index 16f0a2931b235170ccda4bf7c314577bcca5dc6b..11f856c9d54aabf2e3a14dc40aa638e92dc3f832 100644 (file)
--- a/src/rgw/rgw_log.cc
+++ b/src/rgw/rgw_log.cc
@@ -237,8 +237,11 @@ void rgw_format_ops_log_entry(struct rgw_log_entry& entry, Formatter *formatter)
 {
   formatter->open_object_section("log_entry");
   formatter->dump_string("bucket", entry.bucket);
-  entry.time.gmtime(formatter->dump_stream("time"));      // UTC
-  entry.time.localtime(formatter->dump_stream("time_local"));
+  {
+    auto t = utime_t{entry.time};
+    t.gmtime(formatter->dump_stream("time"));      // UTC
+    t.localtime(formatter->dump_stream("time_local"));
+  }
   formatter->dump_string("remote_addr", entry.remote_addr);
   string obj_owner = entry.object_owner.to_str();
   if (obj_owner.length())
@@ -251,9 +254,11 @@ void rgw_format_ops_log_entry(struct rgw_log_entry& entry, Formatter *formatter)
   formatter->dump_int("bytes_sent", entry.bytes_sent);
   formatter->dump_int("bytes_received", entry.bytes_received);
   formatter->dump_int("object_size", entry.obj_size);
-  uint64_t total_time =  entry.total_time.to_msec();
-
-  formatter->dump_int("total_time", total_time);
+  {
+    using namespace std::chrono;
+    uint64_t total_time = duration_cast<milliseconds>(entry.total_time).count();
+    formatter->dump_int("total_time", total_time);
+  }
   formatter->dump_string("user_agent",  entry.user_agent);
   formatter->dump_string("referrer",  entry.referrer);
   if (entry.x_headers.size() > 0) {
@@ -406,7 +411,7 @@ int rgw_log_op(RGWRados *store, RGWREST* const rest, struct req_state *s,
   uint64_t bytes_received = ACCOUNTING_IO(s)->get_bytes_received();
 
   entry.time = s->time;
-  entry.total_time = ceph_clock_now() - s->time;
+  entry.total_time = s->time_elapsed();
   entry.bytes_sent = bytes_sent;
   entry.bytes_received = bytes_received;
   if (s->err.http_ret) {
@@ -423,7 +428,7 @@ int rgw_log_op(RGWRados *store, RGWREST* const rest, struct req_state *s,
   encode(entry, bl);
 
   struct tm bdt;
-  time_t t = entry.time.sec();
+  time_t t = req_state::Clock::to_time_t(entry.time);
   if (s->cct->_conf->rgw_log_object_name_utc)
     gmtime_r(&t, &bdt);
   else

diff --git a/src/rgw/rgw_log.h b/src/rgw/rgw_log.h
index c2df19a887d010713f05deecd258a50e8c3ff276..23a00c10ecfb97f974cd161997d1ea06873285e1 100644 (file)
--- a/src/rgw/rgw_log.h
+++ b/src/rgw/rgw_log.h
@@ -5,7 +5,6 @@
 #define CEPH_RGW_LOG_H
 #include <boost/container/flat_map.hpp>
 #include "rgw_common.h"
-#include "include/utime.h"
 #include "common/Formatter.h"
 #include "common/OutputDataSocket.h"
 
@@ -14,11 +13,12 @@ class RGWRados;
 struct rgw_log_entry {
 
   using headers_map = boost::container::flat_map<std::string, std::string>;
+  using Clock = req_state::Clock;
 
   rgw_user object_owner;
   rgw_user bucket_owner;
   string bucket;
-  utime_t time;
+  Clock::time_point time;
   string remote_addr;
   string user;
   rgw_obj_key obj;
@@ -29,7 +29,7 @@ struct rgw_log_entry {
   uint64_t bytes_sent;
   uint64_t bytes_received;
   uint64_t obj_size;
-  utime_t total_time;
+  Clock::duration total_time;
   string user_agent;
   string referrer;
   string bucket_id;

diff --git a/src/rgw/rgw_op.cc b/src/rgw/rgw_op.cc
index 4d95edb4255d4f8ae5511ee9b826f254977303a0..bc5d4e8843ebab3e0be863fc5853586d741cece3 100644 (file)
--- a/src/rgw/rgw_op.cc
+++ b/src/rgw/rgw_op.cc
@@ -1719,7 +1719,6 @@ static bool object_is_expired(map<string, bufferlist>& attrs) {
 
 void RGWGetObj::execute()
 {
-  utime_t start_time = s->time;
   bufferlist bl;
   gc_invalidate_time = ceph_clock_now();
   gc_invalidate_time += (s->cct->_conf->rgw_gc_obj_min_wait / 2);
@@ -1876,8 +1875,7 @@ void RGWGetObj::execute()
   if (op_ret >= 0)
     op_ret = filter->flush();
 
-  perfcounter->tinc(l_rgw_get_lat,
-                   (ceph_clock_now() - start_time));
+  perfcounter->tinc(l_rgw_get_lat, s->time_elapsed());
   if (op_ret < 0) {
     goto done_err;
   }
@@ -3812,8 +3810,7 @@ void RGWPutObj::execute()
 
 done:
   dispose_processor(processor);
-  perfcounter->tinc(l_rgw_put_lat,
-                   (ceph_clock_now() - s->time));
+  perfcounter->tinc(l_rgw_put_lat, s->time_elapsed());
 }
 
 int RGWPostObj::verify_permission()

diff --git a/src/rgw/rgw_request.cc b/src/rgw/rgw_request.cc
index dcad1993e25e0f72c49a9f2bc07d8ff83f64a156..11a147629f5c001e53a0fac92be89c75613831b7 100644 (file)
--- a/src/rgw/rgw_request.cc
+++ b/src/rgw/rgw_request.cc
@@ -22,7 +22,6 @@ void RGWRequest::log_format(struct req_state *s, const char *fmt, ...)
 } /* RGWRequest::log_format */
 
 void RGWRequest::log_init() {
-  ts = ceph_clock_now();
 }
 
 void RGWRequest::log(struct req_state *s, const char *msg) {
@@ -31,7 +30,7 @@ void RGWRequest::log(struct req_state *s, const char *msg) {
     req_str.append(" ");
     req_str.append(s->info.request_uri);
   }
-  utime_t t = ceph_clock_now() - ts;
+  auto t = s->time_elapsed();
   dout(2) << "req " << id << ":" << t << ":" << s->dialect << ":"
          << req_str << ":" << (op ? op->name() : "") << ":" << msg
          << dendl;

diff --git a/src/rgw/rgw_request.h b/src/rgw/rgw_request.h
index 11345bb0d230851abd6f0fa8e3cd4549f8ecab88..a30437768d27f9b4bd338960931cc51571bb504b 100644 (file)
--- a/src/rgw/rgw_request.h
+++ b/src/rgw/rgw_request.h
@@ -23,7 +23,6 @@ struct RGWRequest
   struct req_state *s;
   string req_str;
   RGWOp *op;
-  utime_t ts;
 
   explicit RGWRequest(uint64_t id) : id(id), s(NULL), op(NULL) {}