Merge pull request ClickHouse#79836 from Dolso/sync-system-error_log-and-system-errors

Sync system.error_log and system.errors

Author: antaljanosbenjamin

docs/en/operations/server-configuration-parameters/_server_settings_outside_source.md

@@ -244,6 +244,7 @@ To manually turn on error history collection [`system.error_log`](../../operatio
         <reserved_size_rows>8192</reserved_size_rows>
         <buffer_size_rows_flush_threshold>524288</buffer_size_rows_flush_threshold>
         <flush_on_crash>false</flush_on_crash>
+        <symbolize>true</symbolize>
     </error_log>
 </clickhouse>
 ```

docs/en/operations/system-tables/error_log.md

@@ -18,8 +18,16 @@ Columns:
 - `event_time` ([DateTime](../../sql-reference/data-types/datetime.md)) — Event time.
 - `code` ([Int32](../../sql-reference/data-types/int-uint.md)) — Code number of the error.
 - `error` ([LowCardinality(String)](../../sql-reference/data-types/string.md)) - Name of the error.
+- `last_error_time` ([DateTime](../../sql-reference/data-types/datetime.md))  — The time when the last error happened.
+- `last_error_message` ([String](../../sql-reference/data-types/string.md)) — Message for the last error.
 - `value` ([UInt64](../../sql-reference/data-types/int-uint.md)) — The number of times this error happened.
 - `remote` ([UInt8](../../sql-reference/data-types/int-uint.md)) — Remote exception (i.e. received during one of the distributed queries).
+- `last_error_query_id` ([String](../../sql-reference/data-types/string.md)) — Id of a query that caused the last error (if available).
+- `last_error_trace` ([Array(UInt64)](../../sql-reference/data-types/array.md)) — A stack trace that represents a list of physical addresses where the called methods are stored.
+- `last_error_symbols` ([Array(LowCardinality(String))](../../sql-reference/data-types/array.md)), If the symbolization is enabled, contains demangled symbol names, corresponding to the `last_error_trace`.
+- `last_error_lines` ([Array(LowCardinality(String))](../../sql-reference/data-types/array.md)), If the symbolization is enabled, contains strings with file names with line numbers, corresponding to the `last_error_trace`.
+
+The symbolization can be enabled or disabled in the `symbolize` under `error_log` in the server's configuration file.
 
 **Example**
 

docs/en/operations/system-tables/errors.md

@@ -21,6 +21,9 @@ Columns:
 - `last_error_message` ([String](../../sql-reference/data-types/string.md)) — message for the last error.
 - `last_error_trace` ([Array(UInt64)](../../sql-reference/data-types/array.md)) — A [stack trace](https://en.wikipedia.org/wiki/Stack_trace) that represents a list of physical addresses where the called methods are stored.
 - `remote` ([UInt8](../../sql-reference/data-types/int-uint.md)) — remote exception (i.e. received during one of the distributed queries).
+- `last_error_query_id` ([String](../../sql-reference/data-types/string.md)) — Id of a query that caused the last error (if available).
+- `last_error_symbols` ([Array(LowCardinality(String))](../../sql-reference/data-types/array.md)) — Contains demangled symbol names, corresponding to the `last_error_trace`.
+- `last_error_lines` ([Array(LowCardinality(String))](../../sql-reference/data-types/array.md)) — Contains strings with file names with line numbers, corresponding to the `last_error_trace`.
 
 :::note
 Counters for some errors may increase during successful query execution. It's not recommended to use this table for server monitoring purposes unless you are sure that corresponding error can not be a false positive.

src/Common/AddressToLineCache.cpp

@@ -0,0 +1,65 @@
+#if defined(__ELF__) && !defined(OS_FREEBSD)
+#include <Common/AddressToLineCache.h>
+#include <Common/SymbolIndex.h>
+#include <IO/WriteHelpers.h>
+
+#include <filesystem>
+
+namespace DB
+{
+
+
+void AddressToLineCache::setResult(StringRef & result, const Dwarf::LocationInfo & location, const std::vector<Dwarf::SymbolizedFrame> &)
+{
+    const char * arena_begin = nullptr;
+    WriteBufferFromArena out(arena, arena_begin);
+
+    writeString(location.file.toString(), out);
+    writeChar(':', out);
+    writeIntText(location.line, out);
+
+    out.finalize();
+    result = out.complete();
+}
+
+StringRef AddressToLineCache::impl(uintptr_t addr)
+{
+    const SymbolIndex & symbol_index = SymbolIndex::instance();
+
+    if (const auto * object = symbol_index.findObject(reinterpret_cast<const void *>(addr)))
+    {
+        auto dwarf_it = dwarfs.try_emplace(object->name, object->elf).first;
+        if (!std::filesystem::exists(object->name))
+            return {};
+
+        Dwarf::LocationInfo location;
+        std::vector<Dwarf::SymbolizedFrame> frames; // NOTE: not used in FAST mode.
+        StringRef result;
+        if (dwarf_it->second.findAddress(addr - uintptr_t(object->address_begin), location, Dwarf::LocationInfoMode::FAST, frames))
+        {
+            setResult(result, location, frames);
+            return result;
+        }
+        return {object->name};
+    }
+    return {};
+}
+
+StringRef AddressToLineCache::implCached(uintptr_t addr)
+{
+    typename Map::LookupResult it;
+    bool inserted;
+    map.emplace(addr, it, inserted);
+    if (inserted)
+        it->getMapped() = impl(addr);
+    return it->getMapped();
+}
+
+StringRef AddressToLineCache::get(uintptr_t addr)
+{
+    static AddressToLineCache cache;
+    return cache.implCached(addr);
+}
+
+}
+#endif

src/Common/AddressToLineCache.h

@@ -0,0 +1,30 @@
+#pragma once
+#if defined(__ELF__) && !defined(OS_FREEBSD)
+
+#include <IO/WriteBufferFromArena.h>
+#include <Common/Dwarf.h>
+#include <Common/HashTable/HashMap.h>
+
+
+namespace DB
+{
+
+class AddressToLineCache
+{
+public:
+    static StringRef get(uintptr_t addr);
+
+protected:
+    void setResult(StringRef & result, const Dwarf::LocationInfo & location, const std::vector<Dwarf::SymbolizedFrame> &);
+    StringRef impl(uintptr_t addr);
+    StringRef implCached(uintptr_t addr);
+
+private:
+    using Map = HashMap<uintptr_t, StringRef>;
+    Arena arena;
+    Map map;
+    std::unordered_map<std::string, Dwarf> dwarfs;
+};
+
+}
+#endif

src/Common/SymbolsHelper.cpp

@@ -0,0 +1,46 @@
+#if defined(__ELF__) && !defined(OS_FREEBSD)
+#include <Core/Field.h>
+#include <base/demangle.h>
+#include <Common/SymbolIndex.h>
+#include <Common/AddressToLineCache.h>
+
+
+namespace DB
+{
+
+std::pair<Array, Array> generateArraysSymbolsLines(const std::vector<UInt64> & trace)
+{
+    Array symbols;
+    Array lines;
+    size_t num_frames = trace.size();
+    symbols.reserve(num_frames);
+    lines.reserve(num_frames);
+
+    const SymbolIndex & symbol_index = SymbolIndex::instance();
+
+    for (size_t frame = 0; frame < num_frames; ++frame)
+    {
+        if (const auto * symbol = symbol_index.findSymbol(reinterpret_cast<const void *>(trace[frame])))
+        {
+            std::string_view mangled_symbol(symbol->name);
+
+            auto demangled = tryDemangle(symbol->name);
+            if (demangled)
+                symbols.emplace_back(std::string_view(demangled.get()));
+            else
+                symbols.emplace_back(std::string_view(symbol->name));
+
+            lines.emplace_back(AddressToLineCache::get(trace[frame]).toView());
+        }
+        else
+        {
+            symbols.emplace_back(String());
+            lines.emplace_back(String());
+        }
+    }
+
+    return {symbols, lines};
+}
+
+}
+#endif

src/Common/SymbolsHelper.h

@@ -0,0 +1,15 @@
+#pragma once
+#if defined(__ELF__) && !defined(OS_FREEBSD)
+#include <base/demangle.h>
+#include <Core/Field.h>
+#include <Common/AddressToLineCache.h>
+
+#include <vector>
+
+namespace DB
+{
+
+std::pair<Array, Array> generateArraysSymbolsLines(const std::vector<UInt64> & trace);
+
+}
+#endif

src/Interpreters/ErrorLog.cpp

@@ -10,15 +10,16 @@
 #include <Interpreters/ErrorLog.h>
 #include <Parsers/ExpressionElementParsers.h>
 #include <Parsers/parseQuery.h>
+#include <Common/SymbolsHelper.h>
 
-#include <vector>
 
 namespace DB
 {
 
 ColumnsDescription ErrorLogElement::getColumnsDescription()
 {
     ParserCodec codec_parser;
+    DataTypePtr symbolized_type = std::make_shared<DataTypeArray>(std::make_shared<DataTypeLowCardinality>(std::make_shared<DataTypeString>()));
     return ColumnsDescription {
         {
                 "hostname",
@@ -50,6 +51,18 @@ ColumnsDescription ErrorLogElement::getColumnsDescription()
                 parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
                 "Error name."
             },
+        {
+                "last_error_time",
+                std::make_shared<DataTypeDateTime>(),
+                parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
+                "The time when the last error happened."
+            },
+        {
+                "last_error_message",
+                std::make_shared<DataTypeString>(),
+                parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
+                "Message for the last error."
+            },
         {
                 "value",
                 std::make_shared<DataTypeUInt64>(),
@@ -61,6 +74,30 @@ ColumnsDescription ErrorLogElement::getColumnsDescription()
                 std::make_shared<DataTypeUInt8>(),
                 parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
                 "Remote exception (i.e. received during one of the distributed queries)."
+            },
+        {
+                "last_error_query_id",
+                std::make_shared<DataTypeString>(),
+                parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
+                "Id of a query that caused the last error (if available)."
+            },
+        {
+                "last_error_trace",
+                std::make_shared<DataTypeArray>(std::make_shared<DataTypeUInt64>()),
+                parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
+                "A stack trace that represents a list of physical addresses where the called methods are stored."
+            },
+        {
+                "symbols",
+                symbolized_type,
+                parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
+                "If the symbolization is enabled, contains demangled symbol names, corresponding to the `trace`."
+            },
+        {
+                "lines",
+                symbolized_type,
+                parseQuery(codec_parser, "(ZSTD(1))", 0, DBMS_DEFAULT_MAX_PARSER_DEPTH, DBMS_DEFAULT_MAX_PARSER_BACKTRACKS),
+                "If the symbolization is enabled, contains strings with file names with line numbers, corresponding to the `trace`."
             }
     };
 }
@@ -74,8 +111,33 @@ void ErrorLogElement::appendToBlock(MutableColumns & columns) const
     columns[column_idx++]->insert(event_time);
     columns[column_idx++]->insert(code);
     columns[column_idx++]->insert(ErrorCodes::getName(code));
+    columns[column_idx++]->insert(error_time_ms / 1000);
+    columns[column_idx++]->insert(error_message);
     columns[column_idx++]->insert(value);
     columns[column_idx++]->insert(remote);
+    columns[column_idx++]->insert(query_id);
+
+    std::vector<UInt64> error_trace_array;
+    error_trace_array.reserve(error_trace.size());
+    for (auto * ptr : error_trace)
+        error_trace_array.emplace_back(reinterpret_cast<UInt64>(ptr));
+
+    columns[column_idx++]->insert(Array(error_trace_array.begin(), error_trace_array.end()));
+
+#if defined(__ELF__) && !defined(OS_FREEBSD)
+    if (symbolize)
+    {
+        auto [symbols, lines] = generateArraysSymbolsLines(error_trace_array);
+
+        columns[column_idx++]->insert(symbols);
+        columns[column_idx++]->insert(lines);
+    }
+    else
+#endif
+    {
+        columns[column_idx++]->insertDefault();
+        columns[column_idx++]->insertDefault();
+    }
 }
 
 struct ValuePair
@@ -99,8 +161,13 @@ void ErrorLog::stepFunction(TimePoint current_time)
             ErrorLogElement local_elem {
                 .event_time=event_time,
                 .code=code,
+                .error_time_ms=error.local.error_time_ms,
+                .error_message=error.local.message,
                 .value=error.local.count - previous_values.at(code).local,
-                .remote=false
+                .remote=false,
+                .query_id=error.local.query_id,
+                .error_trace=error.local.trace,
+                .symbolize=symbolize
             };
             this->add(std::move(local_elem));
             previous_values[code].local = error.local.count;
@@ -110,8 +177,13 @@ void ErrorLog::stepFunction(TimePoint current_time)
             ErrorLogElement remote_elem {
                 .event_time=event_time,
                 .code=code,
+                .error_time_ms=error.remote.error_time_ms,
+                .error_message=error.remote.message,
                 .value=error.remote.count - previous_values.at(code).remote,
-                .remote=true
+                .remote=true,
+                .query_id=error.remote.query_id,
+                .error_trace=error.remote.trace,
+                .symbolize=symbolize
             };
             add(std::move(remote_elem));
             previous_values[code].remote = error.remote.count;

src/Interpreters/ErrorLog.h

@@ -4,8 +4,11 @@
 #include <Common/ErrorCodes.h>
 #include <Core/NamesAndTypes.h>
 #include <Core/NamesAndAliases.h>
+#include <DataTypes/DataTypeArray.h>
 #include <Storages/ColumnsDescription.h>
 
+#include <vector>
+
 
 namespace DB
 {
@@ -17,8 +20,13 @@ struct ErrorLogElement
 {
     time_t event_time{};
     ErrorCodes::ErrorCode code{};
+    UInt64 error_time_ms = 0;
+    std::string error_message{};
     ErrorCodes::Value value{};
     bool remote{};
+    std::string query_id;
+    std::vector<void *> error_trace{};
+    bool symbolize = false;
 
     static std::string name() { return "ErrorLog"; }
     static ColumnsDescription getColumnsDescription();
@@ -31,8 +39,20 @@ class ErrorLog : public PeriodicLog<ErrorLogElement>
 {
     using PeriodicLog<ErrorLogElement>::PeriodicLog;
 
+public:
+    ErrorLog(ContextPtr context_,
+             const SystemLogSettings & settings_,
+             std::shared_ptr<SystemLogQueue<ErrorLogElement>> queue_ = nullptr)
+        : PeriodicLog<ErrorLogElement>(context_, settings_, queue_),
+        symbolize(settings_.symbolize_traces)
+    {
+    }
+
 protected:
     void stepFunction(TimePoint current_time) override;
+
+private:
+    bool symbolize;
 };
 
 }

src/Interpreters/SystemLog.cpp

@@ -14,7 +14,6 @@
 #include <Interpreters/Context.h>
 #include <Interpreters/CrashLog.h>
 #include <Interpreters/DatabaseCatalog.h>
-#include <Interpreters/ErrorLog.h>
 #include <Interpreters/FilesystemCacheLog.h>
 #include <Interpreters/FilesystemReadPrefetchesLog.h>
 #include <Interpreters/InterpreterCreateQuery.h>
@@ -34,6 +33,7 @@
 #include <Interpreters/SessionLog.h>
 #include <Interpreters/TextLog.h>
 #include <Interpreters/TraceLog.h>
+#include <Interpreters/ErrorLog.h>
 #include <Interpreters/TransactionsInfoLog.h>
 #include <Interpreters/ZooKeeperLog.h>
 #include <IO/WriteHelpers.h>
@@ -279,7 +279,7 @@ std::shared_ptr<TSystemLog> createSystemLog(
     log_settings.queue_settings.notify_flush_on_crash = config.getBool(config_prefix + ".flush_on_crash",
                                                                        TSystemLog::shouldNotifyFlushOnCrash());
 
-    if constexpr (std::is_same_v<TSystemLog, TraceLog>)
+    if constexpr (std::is_same_v<TSystemLog, TraceLog> || std::is_same_v<TSystemLog, ErrorLog>)
         log_settings.symbolize_traces = config.getBool(config_prefix + ".symbolize", false);
 
     log_settings.queue_settings.turn_off_logger = TSystemLog::shouldTurnOffLogger();