From bbe20b3f9f083fa04979294c6025796891614eb3 Mon Sep 17 00:00:00 2001 From: Nikita Mikhaylov Date: Tue, 13 Aug 2019 17:31:46 +0300 Subject: [PATCH] done --- dbms/src/Interpreters/Context.cpp | 17 +++-- dbms/src/Interpreters/Context.h | 2 + .../Interpreters/InterpreterSystemQuery.cpp | 4 +- dbms/src/Interpreters/MetricLog.cpp | 68 +++++++++++++++++++ dbms/src/Interpreters/MetricLog.h | 23 +++++++ dbms/src/Interpreters/SystemLog.cpp | 39 +++++++++++ dbms/src/Interpreters/SystemLog.h | 10 ++- .../MergeTreeSequentialBlockInputStream.cpp | 4 +- docker/test/stateful/Dockerfile | 1 + docker/test/stateful_with_coverage/run.sh | 1 + docker/test/stateless/Dockerfile | 1 + docker/test/stateless_with_coverage/run.sh | 1 + 12 files changed, 162 insertions(+), 9 deletions(-) create mode 100644 dbms/src/Interpreters/MetricLog.cpp create mode 100644 dbms/src/Interpreters/MetricLog.h diff --git a/dbms/src/Interpreters/Context.cpp b/dbms/src/Interpreters/Context.cpp index 83f3763bb11..ea78df25485 100644 --- a/dbms/src/Interpreters/Context.cpp +++ b/dbms/src/Interpreters/Context.cpp @@ -38,10 +38,6 @@ #include #include #include -#include -#include -#include -#include #include #include #include @@ -1701,6 +1697,7 @@ std::shared_ptr Context::getPartLog(const String & part_database) return shared->system_logs->part_log; } + std::shared_ptr Context::getTraceLog() { auto lock = getLock(); @@ -1711,6 +1708,7 @@ std::shared_ptr Context::getTraceLog() return shared->system_logs->trace_log; } + std::shared_ptr Context::getTextLog() { auto lock = getLock(); @@ -1722,6 +1720,17 @@ std::shared_ptr Context::getTextLog() } +std::shared_ptr Context::getMetricLog() +{ + auto lock = getLock(); + + if (!shared->system_logs || !shared->system_logs->metric_log) + return {}; + + return shared->system_logs->metric_log; +} + + CompressionCodecPtr Context::chooseCompressionCodec(size_t part_size, double part_size_ratio) const { auto lock = getLock(); diff --git a/dbms/src/Interpreters/Context.h b/dbms/src/Interpreters/Context.h index 50b7ab3eba2..2ef123b74b1 100644 --- a/dbms/src/Interpreters/Context.h +++ b/dbms/src/Interpreters/Context.h @@ -64,6 +64,7 @@ class QueryThreadLog; class PartLog; class TextLog; class TraceLog; +class MetricLog; struct MergeTreeSettings; class IDatabase; class DDLGuard; @@ -434,6 +435,7 @@ public: std::shared_ptr getQueryThreadLog(); std::shared_ptr getTraceLog(); std::shared_ptr getTextLog(); + std::shared_ptr getMetricLog(); /// Returns an object used to log opertaions with parts if it possible. /// Provide table name to make required cheks. diff --git a/dbms/src/Interpreters/InterpreterSystemQuery.cpp b/dbms/src/Interpreters/InterpreterSystemQuery.cpp index 818aae6d048..0797a3deab4 100644 --- a/dbms/src/Interpreters/InterpreterSystemQuery.cpp +++ b/dbms/src/Interpreters/InterpreterSystemQuery.cpp @@ -16,6 +16,7 @@ #include #include #include +#include #include #include #include @@ -232,7 +233,8 @@ BlockIO InterpreterSystemQuery::execute() [&] () { if (auto part_log = context.getPartLog("")) part_log->flush(); }, [&] () { if (auto query_thread_log = context.getQueryThreadLog()) query_thread_log->flush(); }, [&] () { if (auto trace_log = context.getTraceLog()) trace_log->flush(); }, - [&] () { if (auto text_log = context.getTextLog()) text_log->flush(); } + [&] () { if (auto text_log = context.getTextLog()) text_log->flush(); }, + [&] () { if (auto metric_log = context.getMetricLog()) metric_log->flush(); } ); break; case Type::STOP_LISTEN_QUERIES: diff --git a/dbms/src/Interpreters/MetricLog.cpp b/dbms/src/Interpreters/MetricLog.cpp new file mode 100644 index 00000000000..69d9425b17e --- /dev/null +++ b/dbms/src/Interpreters/MetricLog.cpp @@ -0,0 +1,68 @@ +#include +#include +#include +#include +#include + +namespace DB +{ + +Block MetricLogElement::createBlock() +{ + ColumnsWithTypeAndName columns_with_type_and_name; + + columns_with_type_and_name.emplace_back(std::make_shared(), "event_date"); + columns_with_type_and_name.emplace_back(std::make_shared(), "event_time"); + + //ProfileEvents + for (size_t i = 0, end = ProfileEvents::end(); i < end; ++i) + { + std::string name; + name += "ProfileEvent_"; + name += ProfileEvents::getName(ProfileEvents::Event(i)); + columns_with_type_and_name.emplace_back(std::make_shared(), name); + } + + //CurrentMetrics + for (size_t i = 0, end = CurrentMetrics::end(); i < end; ++i) + { + + std::string name; + name += "CurrentMetric_"; + name += CurrentMetrics::getName(ProfileEvents::Event(i)); + columns_with_type_and_name.emplace_back(std::make_shared(), name); + + } + + return Block(columns_with_type_and_name); +} + +void MetricLogElement::appendToBlock(Block & block) const +{ + MutableColumns columns = block.mutateColumns(); + + size_t iter = 0; + + columns[iter++]->insert(DateLUT::instance().toDayNum(event_time)); + columns[iter++]->insert(event_time); + + //ProfileEvents + for (size_t i = 0, end = ProfileEvents::end(); i < end; ++i) + { + UInt64 value = ProfileEvents::global_counters[i]; + + columns[iter++]->insert(value); + + } + + //CurrentMetrics + for (size_t i = 0, end = CurrentMetrics::end(); i < end; ++i) + { + UInt64 value = CurrentMetrics::values[i]; + + columns[iter++]->insert(value); + + } +} + +} diff --git a/dbms/src/Interpreters/MetricLog.h b/dbms/src/Interpreters/MetricLog.h new file mode 100644 index 00000000000..13112d4934e --- /dev/null +++ b/dbms/src/Interpreters/MetricLog.h @@ -0,0 +1,23 @@ +#pragma once +#include +#include + +namespace DB +{ + +using Poco::Message; + +struct MetricLogElement +{ + time_t event_time{}; + static std::string name() { return "MetricLog"; } + static Block createBlock(); + void appendToBlock(Block & block) const; +}; + +class MetricLog : public SystemLog +{ + using SystemLog::SystemLog; +}; + +} diff --git a/dbms/src/Interpreters/SystemLog.cpp b/dbms/src/Interpreters/SystemLog.cpp index f1f65dfe883..6e63951d9ec 100644 --- a/dbms/src/Interpreters/SystemLog.cpp +++ b/dbms/src/Interpreters/SystemLog.cpp @@ -4,6 +4,7 @@ #include #include #include +#include #include @@ -48,7 +49,10 @@ SystemLogs::SystemLogs(Context & global_context, const Poco::Util::AbstractConfi part_log = createSystemLog(global_context, "system", "part_log", config, "part_log"); trace_log = createSystemLog(global_context, "system", "trace_log", config, "trace_log"); text_log = createSystemLog(global_context, "system", "text_log", config, "text_log"); + metric_log = createSystemLog(global_context, "system", "metric_log", config, "metric_log"); + if (metric_log) + metric_flush_thread = ThreadFromGlobalPool([this] { metricThreadFunction(); }); part_log_database = config.getString("part_log.database", "system"); } @@ -70,6 +74,41 @@ void SystemLogs::shutdown() trace_log->shutdown(); if (text_log) text_log->shutdown(); + if (metric_log) + { + bool old_val = false; + if (!is_shutdown_metric_thread.compare_exchange_strong(old_val, true)) + return; + metric_flush_thread.join(); + metric_log->shutdown(); + } +} + +void SystemLogs::metricThreadFunction() +{ + const size_t flush_interval_milliseconds = 1000; + while (true) + { + try + { + const auto prev_timepoint = std::chrono::system_clock::now(); + + if (is_shutdown_metric_thread) + break; + + MetricLogElement elem; + elem.event_time = std::time(nullptr); + metric_log->add(elem); + + const auto next_timepoint = prev_timepoint + std::chrono::milliseconds(flush_interval_milliseconds); + std::this_thread::sleep_until(next_timepoint); + } + catch (...) + { + tryLogCurrentException(__PRETTY_FUNCTION__); + } + + } } } diff --git a/dbms/src/Interpreters/SystemLog.h b/dbms/src/Interpreters/SystemLog.h index 3dd329d577b..545519aeb9d 100644 --- a/dbms/src/Interpreters/SystemLog.h +++ b/dbms/src/Interpreters/SystemLog.h @@ -61,6 +61,7 @@ class QueryThreadLog; class PartLog; class TextLog; class TraceLog; +class MetricLog; /// System logs should be destroyed in destructor of the last Context and before tables, /// because SystemLog destruction makes insert query while flushing data into underlying tables @@ -76,6 +77,11 @@ struct SystemLogs std::shared_ptr part_log; /// Used to log operations with parts std::shared_ptr trace_log; /// Used to log traces from query profiler std::shared_ptr text_log; /// Used to log all text messages. + std::shared_ptr metric_log; /// Used to log all metrics. + + ThreadFromGlobalPool metric_flush_thread; + void metricThreadFunction(); + std::atomic is_shutdown_metric_thread{false}; String part_log_database; }; @@ -115,6 +121,8 @@ public: /// Stop the background flush thread before destructor. No more data will be written. void shutdown(); + size_t getFlushInterval() { return flush_interval_milliseconds; } + protected: Context & context; const String database_name; @@ -179,7 +187,7 @@ SystemLog::SystemLog(Context & context_, flush_interval_milliseconds(flush_interval_milliseconds_) { log = &Logger::get("SystemLog (" + database_name + "." + table_name + ")"); - +qq data.reserve(DBMS_SYSTEM_LOG_QUEUE_SIZE); saving_thread = ThreadFromGlobalPool([this] { threadFunction(); }); } diff --git a/dbms/src/Storages/MergeTree/MergeTreeSequentialBlockInputStream.cpp b/dbms/src/Storages/MergeTree/MergeTreeSequentialBlockInputStream.cpp index 1c9c3457fe5..74cff479e5f 100644 --- a/dbms/src/Storages/MergeTree/MergeTreeSequentialBlockInputStream.cpp +++ b/dbms/src/Storages/MergeTree/MergeTreeSequentialBlockInputStream.cpp @@ -27,9 +27,7 @@ MergeTreeSequentialBlockInputStream::MergeTreeSequentialBlockInputStream( std::stringstream message; message << "Reading " << data_part->getMarksCount() << " marks from part " << data_part->name << ", total " << data_part->rows_count - << " rows starting from the beginning of the part, columns: "; - for (size_t i = 0, size = columns_to_read.size(); i < size; ++i) - message << (i == 0 ? "" : ", ") << columns_to_read[i]; + << " rows starting from the beginning of the part"; LOG_TRACE(log, message.rdbuf()); } diff --git a/docker/test/stateful/Dockerfile b/docker/test/stateful/Dockerfile index 516d63fa330..cab4ebbe8bb 100644 --- a/docker/test/stateful/Dockerfile +++ b/docker/test/stateful/Dockerfile @@ -20,6 +20,7 @@ CMD dpkg -i package_folder/clickhouse-common-static_*.deb; \ ln -s /usr/share/clickhouse-test/config/listen.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/part_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/text_log.xml /etc/clickhouse-server/config.d/; \ + ln -s /usr/share/clickhouse-test/config/metric_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/log_queries.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/readonly.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/ints_dictionary.xml /etc/clickhouse-server/; \ diff --git a/docker/test/stateful_with_coverage/run.sh b/docker/test/stateful_with_coverage/run.sh index 6253a07c745..a6d2ba0e9e8 100755 --- a/docker/test/stateful_with_coverage/run.sh +++ b/docker/test/stateful_with_coverage/run.sh @@ -46,6 +46,7 @@ ln -s /usr/share/clickhouse-test/config/zookeeper.xml /etc/clickhouse-server/con ln -s /usr/share/clickhouse-test/config/listen.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/part_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/text_log.xml /etc/clickhouse-server/config.d/; \ + ln -s /usr/share/clickhouse-test/config/metric_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/log_queries.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/readonly.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/ints_dictionary.xml /etc/clickhouse-server/; \ diff --git a/docker/test/stateless/Dockerfile b/docker/test/stateless/Dockerfile index eea48c3c032..60ab18cd5f2 100644 --- a/docker/test/stateless/Dockerfile +++ b/docker/test/stateless/Dockerfile @@ -40,6 +40,7 @@ CMD dpkg -i package_folder/clickhouse-common-static_*.deb; \ ln -s /usr/share/clickhouse-test/config/listen.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/part_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/text_log.xml /etc/clickhouse-server/config.d/; \ + ln -s /usr/share/clickhouse-test/config/metric_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/query_masking_rules.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/log_queries.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/readonly.xml /etc/clickhouse-server/users.d/; \ diff --git a/docker/test/stateless_with_coverage/run.sh b/docker/test/stateless_with_coverage/run.sh index 5d63f9f49d0..ccf3e53f715 100755 --- a/docker/test/stateless_with_coverage/run.sh +++ b/docker/test/stateless_with_coverage/run.sh @@ -48,6 +48,7 @@ ln -s /usr/share/clickhouse-test/config/zookeeper.xml /etc/clickhouse-server/con ln -s /usr/share/clickhouse-test/config/listen.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/part_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/text_log.xml /etc/clickhouse-server/config.d/; \ + ln -s /usr/share/clickhouse-test/config/metric_log.xml /etc/clickhouse-server/config.d/; \ ln -s /usr/share/clickhouse-test/config/log_queries.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/readonly.xml /etc/clickhouse-server/users.d/; \ ln -s /usr/share/clickhouse-test/config/ints_dictionary.xml /etc/clickhouse-server/; \