From f83e33fc1364de8cebe08bb63afa40bd5987abe8 Mon Sep 17 00:00:00 2001 From: Vlad Zolotarov Date: Wed, 10 Aug 2016 20:15:27 +0300 Subject: [PATCH] tracing: make "elapsed" be std::chrono::duration - Define an tracing::elapsed_clock type (std::chrono::steady_clock). Use it instead of trace_state::clock_type. - Store the "elapsed" information in a form of elapsed_clock::duration. - Make all keyspace_backend specific conversions inside the trace_keyspace_helper class, where they belong. Signed-off-by: Vlad Zolotarov --- tracing/trace_keyspace_helper.cc | 4 ++-- tracing/trace_keyspace_helper.hh | 17 +++++++++++++++++ tracing/trace_state.hh | 21 +++++++-------------- tracing/tracing.hh | 12 ++++++++---- 4 files changed, 34 insertions(+), 20 deletions(-) diff --git a/tracing/trace_keyspace_helper.cc b/tracing/trace_keyspace_helper.cc index 5c2a0b632a..f3abdb2a42 100644 --- a/tracing/trace_keyspace_helper.cc +++ b/tracing/trace_keyspace_helper.cc @@ -226,7 +226,7 @@ mutation trace_keyspace_helper::make_session_mutation(const one_session_records& auto millis_since_epoch = std::chrono::duration_cast(record.started_at.time_since_epoch()).count(); cells.apply(*_started_at_column, atomic_cell::make_live(timestamp, timestamp_type->decompose(millis_since_epoch), ttl)); cells.apply(*_command_column, atomic_cell::make_live(timestamp, utf8_type->decompose(type_to_string(record.command)), ttl)); - cells.apply(*_duration_column, atomic_cell::make_live(timestamp, int32_type->decompose((int32_t)record.elapsed), ttl)); + cells.apply(*_duration_column, atomic_cell::make_live(timestamp, int32_type->decompose(elapsed_to_micros(record.elapsed)), ttl)); std::vector> map_cell; for (auto& param_pair : record.parameters) { @@ -255,7 +255,7 @@ mutation trace_keyspace_helper::make_event_mutation(one_session_records& session cells.apply(*_activity_column, atomic_cell::make_live(timestamp, utf8_type->decompose(record.message), ttl)); cells.apply(*_source_column, atomic_cell::make_live(timestamp, inet_addr_type->decompose(utils::fb_utilities::get_broadcast_address().addr()), ttl)); cells.apply(*_thread_column, atomic_cell::make_live(timestamp, utf8_type->decompose(_local_tracing.get_thread_name()), ttl)); - cells.apply(*_source_elapsed_column, atomic_cell::make_live(timestamp, int32_type->decompose(record.elapsed), ttl)); + cells.apply(*_source_elapsed_column, atomic_cell::make_live(timestamp, int32_type->decompose(elapsed_to_micros(record.elapsed)), ttl)); return m; } diff --git a/tracing/trace_keyspace_helper.hh b/tracing/trace_keyspace_helper.hh index 81399b7a27..5558397ef8 100644 --- a/tracing/trace_keyspace_helper.hh +++ b/tracing/trace_keyspace_helper.hh @@ -236,6 +236,23 @@ private: * @return the relevant mutation */ mutation make_event_mutation(one_session_records& session_records, const event_record& record); + + /** + * Converts a @param elapsed to an int32_t value of microseconds. + * + * @param elapsed the duration to convert + * + * @return the amount of microseconds in a @param elapsed or a std::numeric_limits::max() + * if their amount doesn't fit in the int32_t type. + */ + int32_t elapsed_to_micros(elapsed_clock::duration elapsed) { + auto elapsed_micros = std::chrono::duration_cast(elapsed).count(); + if (elapsed_micros > std::numeric_limits::max()) { + return std::numeric_limits::max(); + } + + return elapsed_micros; + } }; struct bad_column_family : public std::exception { diff --git a/tracing/trace_state.hh b/tracing/trace_state.hh index f4abaff596..c792624304 100644 --- a/tracing/trace_state.hh +++ b/tracing/trace_state.hh @@ -53,14 +53,12 @@ namespace tracing { extern logging::logger trace_state_logger; class trace_state final { - using clock_type = std::chrono::steady_clock; - private: lw_shared_ptr _records; bool _write_on_close; // Used for calculation of time passed since the beginning of a tracing // session till each tracing event. - clock_type::time_point _start; + elapsed_clock::time_point _start; // TRUE for a primary trace_state object bool _primary; bool _tracing_began = false; @@ -132,12 +130,11 @@ public: private: /** - * Returns the number of microseconds passed since the beginning of this - * tracing session. + * Returns the amount of time passed since the beginning of this tracing session. * - * @return number of microseconds passed since the beginning of this session + * @return the amount of time passed since the beginning of this session */ - int elapsed(); + elapsed_clock::duration elapsed(); /** * Initiates a tracing session. @@ -147,7 +144,7 @@ private: */ void begin() { std::atomic_signal_fence(std::memory_order::memory_order_seq_cst); - _start = clock_type::now(); + _start = elapsed_clock::now(); std::atomic_signal_fence(std::memory_order::memory_order_seq_cst); _tracing_began = true; } @@ -348,16 +345,12 @@ void trace_state::trace(const char* fmt, A&&... a) { } } -inline int trace_state::elapsed() { +inline elapsed_clock::duration trace_state::elapsed() { using namespace std::chrono; std::atomic_signal_fence(std::memory_order::memory_order_seq_cst); - auto elapsed = duration_cast(clock_type::now() - _start).count(); + elapsed_clock::duration elapsed = elapsed_clock::now() - _start; std::atomic_signal_fence(std::memory_order::memory_order_seq_cst); - if (elapsed > std::numeric_limits::max()) { - return std::numeric_limits::max(); - } - return elapsed; } diff --git a/tracing/tracing.hh b/tracing/tracing.hh index 1f58bdb8d2..effe19eb1b 100644 --- a/tracing/tracing.hh +++ b/tracing/tracing.hh @@ -51,6 +51,8 @@ namespace tracing { +using elapsed_clock = std::chrono::steady_clock; + extern logging::logger tracing_logger; class trace_state; @@ -138,10 +140,10 @@ private: struct event_record { sstring message; - int elapsed; + elapsed_clock::duration elapsed; i_tracing_backend_helper::wall_clock::time_point event_time_point; - event_record(sstring message_, int elapsed_, i_tracing_backend_helper::wall_clock::time_point event_time_point_) + event_record(sstring message_, elapsed_clock::duration elapsed_, i_tracing_backend_helper::wall_clock::time_point event_time_point_) : message(std::move(message_)) , elapsed(elapsed_) , event_time_point(event_time_point_) {} @@ -153,10 +155,12 @@ struct session_record { sstring request; std::chrono::system_clock::time_point started_at; trace_type command = trace_type::NONE; - int elapsed = -1; + elapsed_clock::duration elapsed; + + session_record() : elapsed(-1) {} bool ready() const { - return elapsed >= 0; + return elapsed.count() >= 0; } };