From 837fde1a084fe157d635763bab709d77e6e74ef2 Mon Sep 17 00:00:00 2001 From: Tim Wojtulewicz Date: Wed, 30 Jul 2025 09:43:45 -0700 Subject: [PATCH] Add metrics to track string and container fields limited by length --- src/logging/Manager.cc | 40 ++++++++++++++++--- src/logging/Manager.h | 2 + .../.stdout | 3 ++ .../.stdout | 3 ++ .../.stdout | 3 ++ .../.stdout | 3 ++ .../.stdout | 3 ++ .../.stdout | 3 ++ .../telemetry.log | 6 +++ .../logging/field-length-limiting.zeek | 10 +++++ 10 files changed, 71 insertions(+), 5 deletions(-) create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-2/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-3/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-4/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-5/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-6/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting/.stdout diff --git a/src/logging/Manager.cc b/src/logging/Manager.cc index c0214bdde5..b023506661 100644 --- a/src/logging/Manager.cc +++ b/src/logging/Manager.cc @@ -246,10 +246,17 @@ struct Manager::WriterInfo { std::shared_ptr total_writes; std::shared_ptr total_discarded_writes; + std::shared_ptr total_truncated_string_fields; + std::shared_ptr total_truncated_containers; WriterInfo(std::shared_ptr total_writes, - std::shared_ptr total_discarded_writes) - : total_writes(std::move(total_writes)), total_discarded_writes(std::move(total_discarded_writes)) {} + std::shared_ptr total_discarded_writes, + std::shared_ptr total_truncated_string_fields, + std::shared_ptr total_truncated_containers) + : total_writes(std::move(total_writes)), + total_discarded_writes(std::move(total_discarded_writes)), + total_truncated_string_fields(std::move(total_truncated_string_fields)), + total_truncated_containers(std::move(total_truncated_containers)) {} }; struct Manager::Stream { @@ -491,7 +498,15 @@ Manager::Manager() total_log_writer_discarded_writes_family( telemetry_mgr->CounterFamily("zeek", "log-writer-discarded-writes", {"writer", "module", "stream", "filter-name", "path"}, - "Total number of log writes discarded due to size limitations.")) { + "Total number of log writes discarded due to size limitations.")), + total_log_writer_truncated_string_fields_family( + telemetry_mgr->CounterFamily("zeek", "log-writer-truncated-string-fields", + {"writer", "module", "stream", "filter-name", "path"}, + "Total number of logged string fields limited by length")), + total_log_writer_truncated_container_fields_family( + telemetry_mgr->CounterFamily("zeek", "log-writer-truncated-containers", + {"writer", "module", "stream", "filter-name", "path"}, + "Total number of logged container fields limited by length")) { rotations_pending = 0; } @@ -1486,6 +1501,10 @@ threading::Value Manager::ValToLogVal(WriterInfo* info, std::optional& val size_t allowed_bytes = std::min( {static_cast(s->Len()), max_field_string_bytes, max_total_string_bytes - total_string_bytes}); + if ( allowed_bytes < static_cast(s->Len()) ) + // TODO: this could also log a reporter warning or a weird or something + info->total_truncated_string_fields->Inc(); + if ( allowed_bytes == 0 ) return lval; @@ -1537,6 +1556,10 @@ threading::Value Manager::ValToLogVal(WriterInfo* info, std::optional& val size_t allowed_elements = std::min({static_cast(set->Length()), max_field_container_elements, max_total_container_elements - total_container_elements}); + if ( allowed_elements < static_cast(set->Length()) ) + // TODO: this could also log a reporter warning or a weird or something + info->total_truncated_containers->Inc(); + if ( allowed_elements == 0 ) return lval; @@ -1561,6 +1584,10 @@ threading::Value Manager::ValToLogVal(WriterInfo* info, std::optional& val size_t allowed_elements = std::min({static_cast(vec->Size()), max_field_container_elements, max_total_container_elements - total_container_elements}); + if ( allowed_elements < static_cast(vec->Size()) ) + // TODO: this could also log a reporter warning or a weird or something + info->total_truncated_containers->Inc(); + if ( allowed_elements == 0 ) return lval; @@ -1688,8 +1715,11 @@ WriterFrontend* Manager::CreateWriter(EnumVal* id, EnumVal* writer, WriterBacken {"filter-name", instantiating_filter}, {"path", info->path}}; - WriterInfo* winfo = new WriterInfo(zeek::log_mgr->total_log_writer_writes_family->GetOrAdd(labels), - zeek::log_mgr->total_log_writer_discarded_writes_family->GetOrAdd(labels)); + WriterInfo* winfo = + new WriterInfo(zeek::log_mgr->total_log_writer_writes_family->GetOrAdd(labels), + zeek::log_mgr->total_log_writer_discarded_writes_family->GetOrAdd(labels), + zeek::log_mgr->total_log_writer_truncated_string_fields_family->GetOrAdd(labels), + zeek::log_mgr->total_log_writer_truncated_container_fields_family->GetOrAdd(labels)); winfo->type = writer->Ref()->AsEnumVal(); winfo->writer = nullptr; winfo->open_time = run_state::network_time; diff --git a/src/logging/Manager.h b/src/logging/Manager.h index d54c3ac204..9db48c366e 100644 --- a/src/logging/Manager.h +++ b/src/logging/Manager.h @@ -460,6 +460,8 @@ private: std::shared_ptr total_log_stream_writes_family; std::shared_ptr total_log_writer_writes_family; std::shared_ptr total_log_writer_discarded_writes_family; + std::shared_ptr total_log_writer_truncated_string_fields_family; + std::shared_ptr total_log_writer_truncated_container_fields_family; zeek_uint_t last_delay_token = 0; std::vector active_writes; diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-2/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-2/.stdout new file mode 100644 index 0000000000..e40107ed88 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-2/.stdout @@ -0,0 +1,3 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_string_fields_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 9.0 +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_containers_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 0.0 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-3/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-3/.stdout new file mode 100644 index 0000000000..51e81b6b71 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-3/.stdout @@ -0,0 +1,3 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_string_fields_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 12.0 +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_containers_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 0.0 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-4/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-4/.stdout new file mode 100644 index 0000000000..7094a3c95e --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-4/.stdout @@ -0,0 +1,3 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_string_fields_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 0.0 +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_containers_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 2.0 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-5/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-5/.stdout new file mode 100644 index 0000000000..44df4ae86b --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-5/.stdout @@ -0,0 +1,3 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_string_fields_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 0.0 +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_containers_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 1.0 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-6/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-6/.stdout new file mode 100644 index 0000000000..7094a3c95e --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting-6/.stdout @@ -0,0 +1,3 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_string_fields_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 0.0 +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_containers_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 2.0 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting/.stdout new file mode 100644 index 0000000000..354dee21f9 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.field-length-limiting/.stdout @@ -0,0 +1,3 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_string_fields_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 20.0 +Telemetry::COUNTER, zeek, zeek_log_writer_truncated_containers_total, [filter_name, module, path, stream, writer], [default, Test, test, Test::LOG, Log::WRITER_ASCII], 0.0 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.telemetry/telemetry.log b/testing/btest/Baseline/scripts.base.frameworks.logging.telemetry/telemetry.log index f98d15e8f4..6b52728ce8 100644 --- a/testing/btest/Baseline/scripts.base.frameworks.logging.telemetry/telemetry.log +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.telemetry/telemetry.log @@ -16,4 +16,10 @@ XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_writes_total filter_name,module,p XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_discarded_writes_total filter_name,module,path,stream,writer default,Conn,conn,Conn::LOG,Log::WRITER_ASCII 0.0 XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_discarded_writes_total filter_name,module,path,stream,writer default,DNS,dns,DNS::LOG,Log::WRITER_ASCII 0.0 XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_discarded_writes_total filter_name,module,path,stream,writer default,HTTP,http,HTTP::LOG,Log::WRITER_ASCII 0.0 +XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_truncated_containers_total filter_name,module,path,stream,writer default,Conn,conn,Conn::LOG,Log::WRITER_ASCII 0.0 +XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_truncated_containers_total filter_name,module,path,stream,writer default,DNS,dns,DNS::LOG,Log::WRITER_ASCII 0.0 +XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_truncated_containers_total filter_name,module,path,stream,writer default,HTTP,http,HTTP::LOG,Log::WRITER_ASCII 0.0 +XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_truncated_string_fields_total filter_name,module,path,stream,writer default,Conn,conn,Conn::LOG,Log::WRITER_ASCII 0.0 +XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_truncated_string_fields_total filter_name,module,path,stream,writer default,DNS,dns,DNS::LOG,Log::WRITER_ASCII 0.0 +XXXXXXXXXX.XXXXXX zeek counter zeek_log_writer_truncated_string_fields_total filter_name,module,path,stream,writer default,HTTP,http,HTTP::LOG,Log::WRITER_ASCII 0.0 #close XXXX-XX-XX-XX-XX-XX diff --git a/testing/btest/scripts/base/frameworks/logging/field-length-limiting.zeek b/testing/btest/scripts/base/frameworks/logging/field-length-limiting.zeek index d52f625561..cb05664065 100644 --- a/testing/btest/scripts/base/frameworks/logging/field-length-limiting.zeek +++ b/testing/btest/scripts/base/frameworks/logging/field-length-limiting.zeek @@ -2,9 +2,12 @@ # # @TEST-EXEC: zeek -b test.zeek %INPUT # @TEST-EXEC: btest-diff test.log +# @TEST-EXEC: btest-diff .stdout # @TEST-START-FILE test.zeek +@load base/frameworks/telemetry + module Test; export { @@ -32,6 +35,13 @@ event zeek_init() } Log::write(Test::LOG, rec); + + local storage_metrics = Telemetry::collect_metrics("zeek", "log_writer_truncated*"); + for (i in storage_metrics) + { + local m = storage_metrics[i]; + print m$opts$metric_type, m$opts$prefix, m$opts$name, m$label_names, m$label_values, m$value; + } }