From c692c864e295c4dc6d156934d3b3b61e46e0fe2e Mon Sep 17 00:00:00 2001 From: Niclas Antti Date: Mon, 5 Nov 2018 16:15:16 +0200 Subject: [PATCH] MXS-2078 Take new statistics into use --- maxutils/maxbase/include/maxbase/stopwatch.hh | 8 +++-- maxutils/maxbase/src/stopwatch.cc | 9 ++++- server/core/CMakeLists.txt | 1 + .../routing/readwritesplit/readwritesplit.cc | 35 +++++++++++++------ .../routing/readwritesplit/readwritesplit.hh | 19 ++-------- .../readwritesplit/rwsplit_route_stmt.cc | 2 ++ .../routing/readwritesplit/rwsplitsession.cc | 12 +++++++ 7 files changed, 55 insertions(+), 31 deletions(-) diff --git a/maxutils/maxbase/include/maxbase/stopwatch.hh b/maxutils/maxbase/include/maxbase/stopwatch.hh index 5c82b4a94..b0069f915 100644 --- a/maxutils/maxbase/include/maxbase/stopwatch.hh +++ b/maxutils/maxbase/include/maxbase/stopwatch.hh @@ -37,12 +37,14 @@ struct Duration : public Clock::duration { using Clock::duration::duration; Duration() = default; - Duration(Clock::duration d) : Clock::duration(d) + Duration(Clock::duration d) + : Clock::duration(d) { } /** From seconds */ - explicit Duration(double secs) : Duration{rep(secs * period::den / period::num)} + explicit Duration(double secs) + : Duration{rep(secs * period::den / period::num)} { } @@ -125,7 +127,7 @@ public: /** Resume measuring time. Ok to call multiple times without an end_interval(). */ void start_interval(); - /** Pause measuring time. */ + /** Pause measuring time. Ok to call without a start_interval. */ void end_interval(); /** Total duration of intervals (thus far). */ diff --git a/maxutils/maxbase/src/stopwatch.cc b/maxutils/maxbase/src/stopwatch.cc index e25f7c73e..94af95635 100644 --- a/maxutils/maxbase/src/stopwatch.cc +++ b/maxutils/maxbase/src/stopwatch.cc @@ -47,7 +47,8 @@ Duration StopWatch::restart() return split; } -IntervalTimer::IntervalTimer() : m_total(0) +IntervalTimer::IntervalTimer() + : m_total(0) { } @@ -58,6 +59,12 @@ void IntervalTimer::start_interval() void IntervalTimer::end_interval() { + if (m_last_start == maxbase::TimePoint()) + { + // m_last_start is defaulted. Ignore, avoids extra logic at call sites. + return; + } + m_total += Clock::now() - m_last_start; // reset to make it easier to spot usage bugs, like calling end_interval(); end_interval(); m_last_start = TimePoint(); diff --git a/server/core/CMakeLists.txt b/server/core/CMakeLists.txt index aef9ac2c7..53238e5c4 100644 --- a/server/core/CMakeLists.txt +++ b/server/core/CMakeLists.txt @@ -46,6 +46,7 @@ add_library(maxscale-common SHARED ssl.cc users.cc utils.cc + session_stats.cc ) target_link_libraries(maxscale-common diff --git a/server/modules/routing/readwritesplit/readwritesplit.cc b/server/modules/routing/readwritesplit/readwritesplit.cc index 41db783ab..356b1623a 100644 --- a/server/modules/routing/readwritesplit/readwritesplit.cc +++ b/server/modules/routing/readwritesplit/readwritesplit.cc @@ -112,7 +112,7 @@ ServerStats& RWSplit::server_stats(SERVER* server) return (*m_server_stats)[server]; } -RWSplit::SrvStatMap RWSplit::all_server_stats() const +maxscale::SrvStatMap RWSplit::all_server_stats() const { SrvStatMap stats; @@ -325,10 +325,10 @@ void RWSplit::diagnostics(DCB* dcb) stats().n_all, all_pct); dcb_printf(dcb, - "\tNumber of read-write transactions: %" PRIu64 "\n", + "\tNumber of read-write transactions: %" PRIu64 "\n", stats().n_rw_trx); dcb_printf(dcb, - "\tNumber of read-only transactions: %" PRIu64 "\n", + "\tNumber of read-only transactions: %" PRIu64 "\n", stats().n_ro_trx); dcb_printf(dcb, "\tNumber of replayed transactions: %" PRIu64 "\n", @@ -360,16 +360,23 @@ void RWSplit::diagnostics(DCB* dcb) if (!srv_stats.empty()) { - dcb_printf(dcb, " Server Total Read Write\n"); + dcb_printf(dcb, " %10s %10s %10s %10s Sess Avg:%9s %10s %10s\n", + "Server", "Total", "Read", "Write", + "dur", "active", "selects"); for (const auto& s : srv_stats) { mxb_assert(s.second.total == s.second.read + s.second.write); + ServerStats::CurrentStats cs = s.second.current_stats(); + dcb_printf(dcb, - " %s %10lu %10lu %10lu\n", + " %10s %10ld %10ld %10ld %9s %10.02f%% %10ld\n", s.first->name, - s.second.total, - s.second.read, - s.second.write); + cs.total_queries, + cs.total_read_queries, + cs.total_write_queries, + to_string(cs.ave_session_dur).c_str(), + cs.ave_session_active_pct, + cs.ave_session_selects); } } } @@ -400,11 +407,17 @@ json_t* RWSplit::diagnostics_json() const for (const auto& a : all_server_stats()) { mxb_assert(a.second.total == a.second.read + a.second.write); + + ServerStats::CurrentStats stats = a.second.current_stats(); + json_t* obj = json_object(); json_object_set_new(obj, "id", json_string(a.first->name)); - json_object_set_new(obj, "total", json_integer(a.second.total)); - json_object_set_new(obj, "read", json_integer(a.second.read)); - json_object_set_new(obj, "write", json_integer(a.second.write)); + json_object_set_new(obj, "total", json_integer(stats.total_queries)); + json_object_set_new(obj, "read", json_integer(stats.total_read_queries)); + json_object_set_new(obj, "write", json_integer(stats.total_write_queries)); + json_object_set_new(obj, "avg_sess_duration", json_string(to_string(stats.ave_session_dur).c_str())); + json_object_set_new(obj, "avg_sess_active_pct", json_real(stats.ave_session_active_pct)); + json_object_set_new(obj, "avg_selects_per_session", json_integer(stats.ave_session_selects)); json_array_append_new(arr, obj); } diff --git a/server/modules/routing/readwritesplit/readwritesplit.hh b/server/modules/routing/readwritesplit/readwritesplit.hh index ae2641100..02823f6ef 100644 --- a/server/modules/routing/readwritesplit/readwritesplit.hh +++ b/server/modules/routing/readwritesplit/readwritesplit.hh @@ -36,6 +36,7 @@ #include #include #include +#include enum backend_type_t { @@ -241,20 +242,8 @@ struct Stats uint64_t n_rw_trx = 0; /**< Read-write transaction count */ }; -// Statistics for one server -struct ServerStats -{ - uint64_t total = 0; // Sum of master + slave + all - uint64_t read = 0; // Write queries - uint64_t write = 0; // Read queries - - void operator+=(const ServerStats& rhs) - { - total += rhs.total; - read += rhs.read; - write += rhs.write; - } -}; +using maxscale::ServerStats; +using maxscale::SrvStatMap; class RWSplitSession; @@ -268,8 +257,6 @@ class RWSplit : public mxs::Router public: - using SrvStatMap = std::map; - RWSplit(SERVICE* service, const Config& config); ~RWSplit(); diff --git a/server/modules/routing/readwritesplit/rwsplit_route_stmt.cc b/server/modules/routing/readwritesplit/rwsplit_route_stmt.cc index f63130324..d673de23d 100644 --- a/server/modules/routing/readwritesplit/rwsplit_route_stmt.cc +++ b/server/modules/routing/readwritesplit/rwsplit_route_stmt.cc @@ -254,6 +254,8 @@ bool RWSplitSession::route_single_stmt(GWBUF* querybuf) bool is_sql = command == MXS_COM_QUERY || command == MXS_COM_STMT_EXECUTE; if (is_sql) { + target->select_started(); + target->response_stat().query_started(); if (m_config.retry_failed_reads) diff --git a/server/modules/routing/readwritesplit/rwsplitsession.cc b/server/modules/routing/readwritesplit/rwsplitsession.cc index 08bdf281a..dd0c33d79 100644 --- a/server/modules/routing/readwritesplit/rwsplitsession.cc +++ b/server/modules/routing/readwritesplit/rwsplitsession.cc @@ -80,6 +80,11 @@ RWSplitSession* RWSplitSession::create(RWSplit* router, MXS_SESSION* session) { router->stats().n_sessions += 1; } + + for (auto& b : backends) + { + router->server_stats(b->server()).start_session(); + } } } @@ -115,6 +120,11 @@ void RWSplitSession::close() stat.num_samples()); } backend->response_stat().reset(); + + m_router->server_stats(backend->server()).end_session( + backend->session_timer().split(), + backend->select_timer().total(), + backend->num_selects()); } } @@ -621,6 +631,8 @@ void RWSplitSession::clientReply(GWBUF* writebuf, DCB* backend_dcb) session_set_load_active(m_pSession, true); } + backend->select_ended(); + if (m_otrx_state == OTRX_ROLLBACK) { // Transaction rolled back, start replaying it on the master