From 927a06b9abd74eb01dc9fb94b405edf5ae53c4a5 Mon Sep 17 00:00:00 2001 From: Arne Welzel Date: Tue, 14 Jan 2025 10:30:44 +0100 Subject: [PATCH 1/3] logging: Fix HookLogInit() and HookLogWrite() info usage There's two instances of WriterBackend::WriterInfo for a given writer. One in Manager::WriterInfo that's accessible via stream.writers and a copy within WriterFrontend. Commit 78999d147d7a98a064d25854eea38468c1af7c5e switched to use the address of the frontend's info instance for HookLogWrite() invocations, breaking users using the address for identification purposes. --- src/logging/Manager.cc | 21 ++++++++++++------- .../logging-hooks-plugin/src/Plugin.cc | 14 +++++++++++++ .../plugins/logging-hooks-plugin/src/Plugin.h | 5 +++++ 3 files changed, 32 insertions(+), 8 deletions(-) diff --git a/src/logging/Manager.cc b/src/logging/Manager.cc index 571b61c020..fd6072d3b5 100644 --- a/src/logging/Manager.cc +++ b/src/logging/Manager.cc @@ -1115,19 +1115,21 @@ bool Manager::WriteToFilters(const Manager::Stream* stream, zeek::RecordValPtr c path = filter->path = filter->path_val->AsString()->CheckString(); } + WriterBackend::WriterInfo* info = nullptr; WriterFrontend* writer = nullptr; if ( w != stream->writers.end() ) { // We know this writer already. - writer = w->second->writer; + auto* wi = w->second; + writer = wi->writer; + info = wi->info; - if ( ! w->second->hook_initialized ) { - auto wi = w->second; + if ( ! wi->hook_initialized ) { wi->hook_initialized = true; PLUGIN_HOOK_VOID(HOOK_LOG_INIT, HookLogInit(filter->writer->GetType()->AsEnumType()->Lookup( filter->writer->InternalInt()), wi->instantiating_filter, filter->local, filter->remote, - *wi->info, filter->num_fields, filter->fields)); + *info, filter->num_fields, filter->fields)); } } @@ -1141,9 +1143,12 @@ bool Manager::WriteToFilters(const Manager::Stream* stream, zeek::RecordValPtr c // Find the newly inserted WriterInfo record. w = stream->writers.find(wpp); assert(w != stream->writers.end()); + + info = w->second->info; } assert(writer); + assert(info); // Alright, can do the write now. auto rec = RecordToLogRecord(stream, filter, columns.get()); @@ -1156,10 +1161,10 @@ bool Manager::WriteToFilters(const Manager::Stream* stream, zeek::RecordValPtr c for ( auto& v : rec ) vals.emplace_back(&v); - bool res = zeek::plugin_mgr->HookLogWrite(filter->writer->GetType()->AsEnumType()->Lookup( - filter->writer->InternalInt()), - filter->name, *writer->info, filter->num_fields, filter->fields, - &vals[0]); + bool res = + zeek::plugin_mgr->HookLogWrite(filter->writer->GetType()->AsEnumType()->Lookup( + filter->writer->InternalInt()), + filter->name, *info, filter->num_fields, filter->fields, &vals[0]); if ( ! res ) { DBG_LOG(DBG_LOGGING, "Hook prevented writing to filter '%s' on stream '%s'", filter->name.c_str(), stream->name.c_str()); diff --git a/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc index 65f3a1a896..af151069c9 100644 --- a/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc +++ b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc @@ -49,6 +49,8 @@ void Plugin::HookLogInit(const std::string& writer, const std::string& instantia fprintf(stderr, "%.6f %-15s %s %d/%d %s\n", zeek::run_state::network_time, "| HookLogInit", info.path, local, remote, d.Description()); + + info_addr_init = &info; } bool Plugin::HookLogWrite(const std::string& writer, const std::string& filter, @@ -62,5 +64,17 @@ bool Plugin::HookLogWrite(const std::string& writer, const std::string& filter, else if ( round == 3 ) vals[1]->present = false; + if ( ! info_addr_write ) + info_addr_write = &info; + else if ( info_addr_write != &info ) + fprintf(stderr, "FAIL: subsequent info addr %p differs from %p\n", &info, info_addr_write); + return true; } + +void Plugin::Done() { + if ( ! info_addr_init || ! info_addr_write || info_addr_init != info_addr_write ) { + fprintf(stderr, "FAIL: info_addr_init=%p info_addr_write=%p\n", info_addr_init, info_addr_write); + exit(1); + } +} diff --git a/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h index 8ada633a20..50ff4b6cdf 100644 --- a/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h +++ b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h @@ -17,8 +17,13 @@ protected: // Overridden from plugin::Plugin. zeek::plugin::Configuration Configure() override; + // Overridden from plugin::Plugin. + void Done() override; + private: int round; + const zeek::logging::WriterBackend::WriterInfo* info_addr_init = nullptr; + const zeek::logging::WriterBackend::WriterInfo* info_addr_write = nullptr; }; extern Plugin plugin; From 345c4ca28a8e85fd5dced1d303e89a751374f9ad Mon Sep 17 00:00:00 2001 From: Arne Welzel Date: Tue, 14 Jan 2025 10:41:34 +0100 Subject: [PATCH 2/3] logging: Avoid repeated writer name lookups for plugin hooks If a plugin provides a write hook, the invocation for HookLogWrite() would redo looking up the writer's name from the enum value and instantiating a new std::string instance for every write. Avoid doing this. --- src/logging/Manager.cc | 20 +++++++++----------- 1 file changed, 9 insertions(+), 11 deletions(-) diff --git a/src/logging/Manager.cc b/src/logging/Manager.cc index fd6072d3b5..4f5fc5aaa0 100644 --- a/src/logging/Manager.cc +++ b/src/logging/Manager.cc @@ -204,6 +204,7 @@ struct Manager::Filter { string path; Val* path_val = nullptr; EnumVal* writer = nullptr; + std::string writer_name; TableVal* config = nullptr; TableVal* field_name_map = nullptr; string scope_sep; @@ -882,6 +883,7 @@ bool Manager::AddFilter(EnumVal* id, RecordVal* fval) { filter->policy = policy ? policy->AsFunc() : stream->policy; filter->path_func = path_func ? path_func->AsFunc() : nullptr; filter->writer = writer->Ref()->AsEnumVal(); + filter->writer_name = writer->GetType()->AsEnumType()->Lookup(writer->InternalInt()); filter->local = log_local->AsBool(); filter->remote = log_remote->AsBool(); filter->interval = interv->AsInterval(); @@ -1126,10 +1128,9 @@ bool Manager::WriteToFilters(const Manager::Stream* stream, zeek::RecordValPtr c if ( ! wi->hook_initialized ) { wi->hook_initialized = true; - PLUGIN_HOOK_VOID(HOOK_LOG_INIT, HookLogInit(filter->writer->GetType()->AsEnumType()->Lookup( - filter->writer->InternalInt()), - wi->instantiating_filter, filter->local, filter->remote, - *info, filter->num_fields, filter->fields)); + PLUGIN_HOOK_VOID(HOOK_LOG_INIT, + HookLogInit(filter->writer_name, wi->instantiating_filter, filter->local, + filter->remote, *info, filter->num_fields, filter->fields)); } } @@ -1161,10 +1162,8 @@ bool Manager::WriteToFilters(const Manager::Stream* stream, zeek::RecordValPtr c for ( auto& v : rec ) vals.emplace_back(&v); - bool res = - zeek::plugin_mgr->HookLogWrite(filter->writer->GetType()->AsEnumType()->Lookup( - filter->writer->InternalInt()), - filter->name, *info, filter->num_fields, filter->fields, &vals[0]); + bool res = zeek::plugin_mgr->HookLogWrite(filter->writer_name, filter->name, *info, filter->num_fields, + filter->fields, &vals[0]); if ( ! res ) { DBG_LOG(DBG_LOGGING, "Hook prevented writing to filter '%s' on stream '%s'", filter->name.c_str(), stream->name.c_str()); @@ -1684,9 +1683,8 @@ WriterFrontend* Manager::CreateWriter(EnumVal* id, EnumVal* writer, WriterBacken if ( ! from_remote ) { winfo->hook_initialized = true; - PLUGIN_HOOK_VOID(HOOK_LOG_INIT, - HookLogInit(writer->GetType()->AsEnumType()->Lookup(writer->InternalInt()), - instantiating_filter, local, remote, *winfo->info, num_fields, fields)); + PLUGIN_HOOK_VOID(HOOK_LOG_INIT, HookLogInit(writer_name, instantiating_filter, local, remote, *winfo->info, + num_fields, fields)); } InstallRotationTimer(winfo); From fd2229e7bbfaf597023676f2801bbe512e175101 Mon Sep 17 00:00:00 2001 From: Arne Welzel Date: Tue, 14 Jan 2025 10:09:12 +0100 Subject: [PATCH 3/3] logging: Fix reporter message --- src/logging/Manager.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/logging/Manager.cc b/src/logging/Manager.cc index 4f5fc5aaa0..c01e89f929 100644 --- a/src/logging/Manager.cc +++ b/src/logging/Manager.cc @@ -1737,7 +1737,7 @@ WriterFrontend* Manager::CreateWriterForFilter(Filter* filter, const std::string bool Manager::WriteBatchFromRemote(const detail::LogWriteHeader& header, std::vector&& records) { Stream* stream = FindStream(header.stream_id.get()); if ( ! stream ) { - reporter->Error("Failed to find stream for !"); + reporter->Error("Failed to find stream %s for remote write", header.stream_name.c_str()); return false; }