diff --git a/docs/en/operations/server-configuration-parameters/settings.md b/docs/en/operations/server-configuration-parameters/settings.md index ca4938b1a47..8cc34a93c4a 100644 --- a/docs/en/operations/server-configuration-parameters/settings.md +++ b/docs/en/operations/server-configuration-parameters/settings.md @@ -1643,6 +1643,7 @@ You can specify the log format that will be outputted in the console log. Curren ```json { + "date_time_utc": "2024-11-06T09:06:09Z", "date_time": "1650918987.180175", "thread_name": "#1", "thread_id": "254545", diff --git a/programs/server/config.xml b/programs/server/config.xml index 9807f8c0d5a..8ec49d804bd 100644 --- a/programs/server/config.xml +++ b/programs/server/config.xml @@ -70,12 +70,15 @@ You can specify log format(for now, JSON only). In that case, the console log will be printed in specified format like JSON. For example, as below: + {"date_time":"1650918987.180175","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} + {"date_time_utc":"2024-11-06T09:06:09Z","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} To enable JSON logging support, please uncomment the entire tag below. a) You can modify key names by changing values under tag values inside tag. For example, to change DATE_TIME to MY_DATE_TIME, you can do like: MY_DATE_TIME + MY_UTC_DATE_TIME b) You can stop unwanted log properties to appear in logs. To do so, you can simply comment out (recommended) that property from this file. For example, if you do not want your log to print query_id, you can comment out only tag. @@ -86,6 +89,7 @@ json date_time + date_time_utc thread_name thread_id level diff --git a/src/Loggers/OwnJSONPatternFormatter.cpp b/src/Loggers/OwnJSONPatternFormatter.cpp index 4263ad5925a..3eccb176c1f 100644 --- a/src/Loggers/OwnJSONPatternFormatter.cpp +++ b/src/Loggers/OwnJSONPatternFormatter.cpp @@ -7,12 +7,18 @@ #include #include #include +#include +#include + OwnJSONPatternFormatter::OwnJSONPatternFormatter(Poco::Util::AbstractConfiguration & config) { if (config.has("logger.formatting.names.date_time")) date_time = config.getString("logger.formatting.names.date_time", ""); + if (config.has("logger.formatting.names.date_time_utc")) + date_time_utc= config.getString("logger.formatting.names.date_time_utc", ""); + if (config.has("logger.formatting.names.thread_name")) thread_name = config.getString("logger.formatting.names.thread_name", ""); @@ -41,6 +47,7 @@ OwnJSONPatternFormatter::OwnJSONPatternFormatter(Poco::Util::AbstractConfigurati && logger_name.empty() && message.empty() && source_file.empty() && source_line.empty()) { date_time = "date_time"; + date_time_utc = "date_time_utc"; thread_name = "thread_name"; thread_id = "thread_id"; level = "level"; @@ -62,8 +69,22 @@ void OwnJSONPatternFormatter::formatExtended(const DB::ExtendedLogMessage & msg_ const Poco::Message & msg = msg_ext.base; DB::writeChar('{', wb); + if (!date_time_utc.empty()) + { + writeJSONString(date_time_utc, wb, settings); + DB::writeChar(':', wb); + + DB::writeChar('\"', wb); + static const DateLUTImpl & utc_time_zone = DateLUT::instance("UTC"); + writeDateTimeTextISO(msg_ext.time_seconds, 0, wb, utc_time_zone); + + DB::writeChar('\"', wb); + print_comma = true; + } + if (!date_time.empty()) { + if (print_comma) DB::writeChar(',', wb); writeJSONString(date_time, wb, settings); DB::writeChar(':', wb); @@ -81,6 +102,7 @@ void OwnJSONPatternFormatter::formatExtended(const DB::ExtendedLogMessage & msg_ print_comma = true; } + if (!thread_name.empty()) { if (print_comma) diff --git a/src/Loggers/OwnJSONPatternFormatter.h b/src/Loggers/OwnJSONPatternFormatter.h index 51827f34b22..ab96c4e5bff 100644 --- a/src/Loggers/OwnJSONPatternFormatter.h +++ b/src/Loggers/OwnJSONPatternFormatter.h @@ -33,6 +33,7 @@ public: private: std::string date_time; + std::string date_time_utc; std::string thread_name; std::string thread_id; std::string level; diff --git a/tests/integration/test_structured_logging_json/configs/config_all_keys_json.xml b/tests/integration/test_structured_logging_json/configs/config_all_keys_json.xml index f20fda50319..9336695f098 100644 --- a/tests/integration/test_structured_logging_json/configs/config_all_keys_json.xml +++ b/tests/integration/test_structured_logging_json/configs/config_all_keys_json.xml @@ -6,12 +6,14 @@ in specified format like JSON. For example, as below: {"date_time":"1650918987.180175","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} + {"date_time_utc":"2024-11-06T09:06:09Z","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} To enable JSON logging support, just uncomment tag below. --> json DATE_TIME + DATE_TIME_UTC THREAD_NAME THREAD_ID LEVEL diff --git a/tests/integration/test_structured_logging_json/configs/config_json.xml b/tests/integration/test_structured_logging_json/configs/config_json.xml index d2e9e284f4e..2805d85e504 100644 --- a/tests/integration/test_structured_logging_json/configs/config_json.xml +++ b/tests/integration/test_structured_logging_json/configs/config_json.xml @@ -5,12 +5,14 @@ in specified format like JSON. For example, as below: {"date_time":"1650918987.180175","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} + {"date_time_utc":"2024-11-06T09:06:09Z","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} To enable JSON logging support, just uncomment tag below. --> json DATE_TIME + DATE_TIME_UTC THREAD_NAME THREAD_ID LEVEL diff --git a/tests/integration/test_structured_logging_json/configs/config_no_keys_json.xml b/tests/integration/test_structured_logging_json/configs/config_no_keys_json.xml index 21d1e9b34ec..e27ef328894 100644 --- a/tests/integration/test_structured_logging_json/configs/config_no_keys_json.xml +++ b/tests/integration/test_structured_logging_json/configs/config_no_keys_json.xml @@ -6,12 +6,14 @@ in specified format like JSON. For example, as below: {"date_time":"1650918987.180175","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} + {"date_time_utc":"2024-11-06T09:06:09Z","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"} To enable JSON logging support, just uncomment tag below. --> json json DATE_TIME + DATE_TIME_UTC THREAD_NAME THREAD_ID LEVEL diff --git a/tests/integration/test_structured_logging_json/test.py b/tests/integration/test_structured_logging_json/test.py index a7d048cc4bb..7ea3d26ba94 100644 --- a/tests/integration/test_structured_logging_json/test.py +++ b/tests/integration/test_structured_logging_json/test.py @@ -1,4 +1,5 @@ import json +from datetime import datetime from xml.etree import ElementTree as ET import pytest @@ -58,12 +59,25 @@ def validate_log_level(config, logs): return True +def is_valid_utc_datetime(datetime_str): + try: + datetime.strptime(datetime_str, "%Y-%m-%dT%H:%M:%S.%fZ") + return True + except ValueError: + try: + datetime.strptime(datetime_str, "%Y-%m-%dT%H:%M:%SZ") + return True + except ValueError: + return False + + def validate_log_config_relation(config, logs, config_type): root = ET.fromstring(config) keys_in_config = set() if config_type == "config_no_keys": keys_in_config.add("date_time") + keys_in_config.add("date_time_utc") keys_in_config.add("thread_name") keys_in_config.add("thread_id") keys_in_config.add("level") @@ -80,14 +94,17 @@ def validate_log_config_relation(config, logs, config_type): length = min(10, len(logs)) for i in range(0, length): json_log = json.loads(logs[i]) - keys_in_log = set() - for log_key in json_log.keys(): - keys_in_log.add(log_key) - if log_key not in keys_in_config: - return False - for config_key in keys_in_config: - if config_key not in keys_in_log: - return False + keys_in_log = set(json_log.keys()) + + if not keys_in_config.issubset(keys_in_log): + return False + + # Validate the UTC datetime format in "date_time_utc" if it exists + if "date_time_utc" in json_log and not is_valid_utc_datetime( + json_log["date_time_utc"] + ): + return False + except ValueError as e: return False return True @@ -101,7 +118,7 @@ def validate_logs(logs): return result -def valiade_everything(config, node, config_type): +def validate_everything(config, node, config_type): node.query("SELECT 1") logs = node.grep_in_log("").split("\n") return ( @@ -122,8 +139,11 @@ def test_structured_logging_json_format(start_cluster): ["cat", "/etc/clickhouse-server/config.d/config_no_keys_json.xml"] ) - assert valiade_everything(config_all_keys, node_all_keys, "config_all_keys") == True assert ( - valiade_everything(config_some_keys, node_some_keys, "config_some_keys") == True + validate_everything(config_all_keys, node_all_keys, "config_all_keys") == True ) - assert valiade_everything(config_no_keys, node_no_keys, "config_no_keys") == True + assert ( + validate_everything(config_some_keys, node_some_keys, "config_some_keys") + == True + ) + assert validate_everything(config_no_keys, node_no_keys, "config_no_keys") == True