Add metrics to track string and container fields limited by length

src/logging/Manager.cc

@@ -246,10 +246,17 @@ struct Manager::WriterInfo {
 
     std::shared_ptr<telemetry::Counter> total_writes;
     std::shared_ptr<telemetry::Counter> total_discarded_writes;
+    std::shared_ptr<telemetry::Counter> total_truncated_string_fields;
+    std::shared_ptr<telemetry::Counter> total_truncated_containers;
 
     WriterInfo(std::shared_ptr<telemetry::Counter> total_writes,
-               std::shared_ptr<telemetry::Counter> total_discarded_writes)
+               std::shared_ptr<telemetry::Counter> total_discarded_writes,
-        : total_writes(std::move(total_writes)), total_discarded_writes(std::move(total_discarded_writes)) {}
+               std::shared_ptr<telemetry::Counter> total_truncated_string_fields,
+               std::shared_ptr<telemetry::Counter> 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<ZVal>& val
             size_t allowed_bytes = std::min(
                 {static_cast<size_t>(s->Len()), max_field_string_bytes, max_total_string_bytes - total_string_bytes});
 
+            if ( allowed_bytes < static_cast<size_t>(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<ZVal>& val
             size_t allowed_elements = std::min({static_cast<size_t>(set->Length()), max_field_container_elements,
                                                 max_total_container_elements - total_container_elements});
 
+            if ( allowed_elements < static_cast<size_t>(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<ZVal>& val
             size_t allowed_elements = std::min({static_cast<size_t>(vec->Size()), max_field_container_elements,
                                                 max_total_container_elements - total_container_elements});
 
+            if ( allowed_elements < static_cast<size_t>(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),
+    WriterInfo* winfo =
-                                       zeek::log_mgr->total_log_writer_discarded_writes_family->GetOrAdd(labels));
+        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;

src/logging/Manager.h

@@ -460,6 +460,8 @@ private:
     std::shared_ptr<telemetry::CounterFamily> total_log_stream_writes_family;
     std::shared_ptr<telemetry::CounterFamily> total_log_writer_writes_family;
     std::shared_ptr<telemetry::CounterFamily> total_log_writer_discarded_writes_family;
+    std::shared_ptr<telemetry::CounterFamily> total_log_writer_truncated_string_fields_family;
+    std::shared_ptr<telemetry::CounterFamily> total_log_writer_truncated_container_fields_family;
 
     zeek_uint_t last_delay_token = 0;
     std::vector<detail::WriteContext> active_writes;

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

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

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

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

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

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

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

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;
+		}
 	}