From: Juweria Ali Imran (jaliimra) Date: Sat, 27 Sep 2025 12:47:59 +0000 (+0000) Subject: Pull request #4914: Unified batched logger X-Git-Tag: 3.9.6.0~7 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=4025e1f0edd9d75b73ceaf6794dd6a7b9311eee6;p=thirdparty%2Fsnort3.git Pull request #4914: Unified batched logger Merge in SNORT/snort3 from ~JALIIMRA/snort3:unified_batched_logger to master Squashed commit of the following: commit de7b21ebe1c04d596eb93501a8e28dd429892c85 Author: Juweria Ali Imran Date: Sun Aug 31 08:02:00 2025 -0400 log: use batched logger for all kinds of log messages in prod when log_buffer config enabled --- diff --git a/src/log/batched_logger.cc b/src/log/batched_logger.cc index 661c77d1e..b853e2124 100644 --- a/src/log/batched_logger.cc +++ b/src/log/batched_logger.cc @@ -29,12 +29,17 @@ #include #include +#include "control/control.h" #include "control/control_mgmt.h" +#include "main/analyzer_command.h" #include "main/snort_config.h" #include "main/thread_config.h" +#include "time/periodic.h" #include "utils/snort_pcre.h" #include "utils/util.h" +#define LOG_BYTE_LIMIT 4096 + namespace BatchedLogger { @@ -44,6 +49,21 @@ std::thread BatchedLogManager::writer_thread; std::atomic BatchedLogManager::running(false); std::atomic BatchQueue::overwrite_count(0); +class BatchedLoggerPeriodicFlush : public snort::AnalyzerCommand +{ +public: + BatchedLoggerPeriodicFlush(ControlConn* ctrl = nullptr) + : AnalyzerCommand(ctrl) {} + + bool execute(Analyzer&, void**) override + { + BatchedLogManager::flush_thread_buffers(); + return true; + } + + const char* stringify() override { return "BATCHED_LOGGER_PERIODIC_FLUSH"; } +}; + void LogBuffer::append(FILE* fh, bool use_syslog, const char* msg, size_t len) { if (size + len >= LOG_BUFFER_THRESHOLD) @@ -193,7 +213,10 @@ void BatchedLogManager::shutdown() { if (!running) return; + + stop_periodic_flush(); flush_thread_buffers(); + running = false; queue.push({}); @@ -210,6 +233,8 @@ void BatchedLogManager::shutdown() void BatchedLogManager::log(FILE* fh, bool use_syslog, const char* msg, size_t len) { + assert(snort::SnortConfig::get_conf()->use_log_buffered()); + buffer.append(fh, use_syslog, msg, len); auto now = std::chrono::steady_clock::now(); auto elapsed = std::chrono::duration_cast(now - buffer.last_flush_time); @@ -221,12 +246,16 @@ void BatchedLogManager::log(FILE* fh, bool use_syslog, const char* msg, size_t l #endif } -#if 0 void BatchedLogManager::log(FILE* fh, bool use_syslog, const char* format, va_list& ap) { - static char temp[1024]; + assert(snort::SnortConfig::get_conf()->use_log_buffered()); + + thread_local char temp[LOG_BYTE_LIMIT]; int len = vsnprintf(temp, sizeof(temp), format, ap); + assert(len <= LOG_BYTE_LIMIT); + len = std::min(len, LOG_BYTE_LIMIT); + buffer.append(fh, use_syslog, temp, len); auto now = std::chrono::steady_clock::now(); auto elapsed = std::chrono::duration_cast(now - buffer.last_flush_time); @@ -239,7 +268,23 @@ void BatchedLogManager::log(FILE* fh, bool use_syslog, const char* format, va_li #endif } -#endif + +static void s_batched_logger_flush_handler(void*) +{ + BatchedLogManager::flush_thread_buffers(); + main_broadcast_command(new BatchedLoggerPeriodicFlush()); +} + +void BatchedLogManager::start_periodic_flush() +{ + Periodic::register_handler(s_batched_logger_flush_handler, nullptr, 0, 250); +} + +void BatchedLogManager::stop_periodic_flush() +{ + Periodic::unregister_handler(s_batched_logger_flush_handler); +} + void BatchedLogManager::flush_thread_buffers() { buffer.flush(); @@ -250,6 +295,11 @@ void BatchedLogManager::push_batch(LogBatch&& batch) queue.push(std::move(batch)); } +static bool is_packet_tracer_message(const char* data, size_t size) +{ + return memmem(data, size, "PktTracerDbg", 12) != nullptr; +} + void BatchedLogManager::print_batch(const LogBatch& batch) { static bool stop_trace = false; @@ -263,8 +313,9 @@ void BatchedLogManager::print_batch(const LogBatch& batch) } if (stop_trace) return; - - if (!s_filter.filter.empty()) + + // Only apply filters to PacketTracer content + if (!s_filter.filter.empty() && is_packet_tracer_message(batch.data.data(), batch.size)) { int rc = pcre2_match( s_filter.re, reinterpret_cast(batch.data.data()), @@ -307,7 +358,7 @@ void BatchedLogManager::print_batch(const LogBatch& batch) } } #ifdef SHELL - if (stop_trace) + if (stop_trace && is_packet_tracer_message(batch.data.data(), batch.size)) if (!ControlMgmt::send_command_to_socket("packet_tracer.disable()\n")) fprintf(stderr, "Batched_logger: Failed to send command to control socket\n"); #endif @@ -333,6 +384,9 @@ void BatchedLogManager::writer_thread_func() void BatchedLogManager::init() { + if (running) + return; + running = true; snort::ThreadConfig* thread_config = snort::SnortConfig::get_conf()->thread_config; @@ -346,6 +400,8 @@ void BatchedLogManager::init() sched_param sch_params; sch_params.sched_priority = 1; pthread_setschedparam(writer_thread.native_handle(), SCHED_OTHER, &sch_params); + + start_periodic_flush(); } } // namespace BatchedLogger diff --git a/src/log/batched_logger.h b/src/log/batched_logger.h index a68fd8aae..31c69da4a 100644 --- a/src/log/batched_logger.h +++ b/src/log/batched_logger.h @@ -88,10 +88,12 @@ public: static void init(); static void shutdown(); static void log(FILE* fh, bool use_syslog, const char* msg, size_t len); - //static void log(FILE* fh, bool use_syslog, const char* format, va_list& ap); + static void log(FILE* fh, bool use_syslog, const char* format, va_list& ap); static void flush_thread_buffers(); static void push_batch(LogBatch&& batch); static void set_filter(const std::string& filter); + static void start_periodic_flush(); + static void stop_periodic_flush(); private: static thread_local LogBuffer buffer; diff --git a/src/log/messages.cc b/src/log/messages.cc index ded6c39f3..0f41c67a6 100644 --- a/src/log/messages.cc +++ b/src/log/messages.cc @@ -29,6 +29,7 @@ #include #include +#include "log/batched_logger.h" #include "main/snort_config.h" #include "main/thread.h" #include "parser/parser.h" @@ -178,15 +179,25 @@ void ReloadError(const char* format, ...) static void WriteLogMessage(FILE* fh, bool prefer_fh, const char* format, va_list& ap) { - if ( prefer_fh or !SnortConfig::log_syslog() ) - { - vfprintf(fh, format, ap); - return; - } - char buf[STD_BUF+1]; - vsnprintf(buf, STD_BUF, format, ap); - buf[STD_BUF] = '\0'; - syslog(LOG_DAEMON | LOG_NOTICE, "%s", buf); + const SnortConfig* sc = SnortConfig::get_conf(); + + if ( sc && sc->use_log_buffered() ) + { + bool syslog_option = ( prefer_fh or !SnortConfig::log_syslog() ) ? false : true; + BatchedLogger::BatchedLogManager::log(fh, syslog_option, format, ap); + } + else + { + if ( prefer_fh or !SnortConfig::log_syslog() ) + { + vfprintf(fh, format, ap); + return; + } + char buf[STD_BUF+1]; + vsnprintf(buf, STD_BUF, format, ap); + buf[STD_BUF] = '\0'; + syslog(LOG_DAEMON | LOG_NOTICE, "%s", buf); + } } // print an info message to stdout or syslog diff --git a/src/main/modules.cc b/src/main/modules.cc index 18c9e0173..ace375624 100644 --- a/src/main/modules.cc +++ b/src/main/modules.cc @@ -46,6 +46,7 @@ #include "host_tracker/host_cache_module.h" #include "js_norm/js_norm_module.h" #include "latency/latency_module.h" +#include "log/batched_logger.h" #include "log/messages.h" #include "lua/lua.h" #include "managers/module_manager.h" @@ -766,6 +767,9 @@ static const Parameter output_params[] = { "obfuscate", Parameter::PT_BOOL, nullptr, "false", "obfuscate the logged IP addresses (same as -O)" }, + { "log_buffered", Parameter::PT_BOOL, nullptr, "false", + "enable buffered logging for all output" }, + #ifdef REG_TEST { "wide_hex_dump", Parameter::PT_BOOL, nullptr, "true", #else @@ -840,6 +844,16 @@ bool OutputModule::set(const char*, Value& v, SnortConfig* sc) else if ( v.is("obfuscate") ) v.update_mask(sc->output_flags, OUTPUT_FLAG__OBFUSCATE); + + else if ( v.is("log_buffered") ) + { + if ( v.get_bool() ) + BatchedLogger::BatchedLogManager::init(); + else + BatchedLogger::BatchedLogManager::shutdown(); + + v.update_mask(sc->output_flags, OUTPUT_FLAG__LOG_BUFFERED); + } return true; } diff --git a/src/main/snort.cc b/src/main/snort.cc index d092f5a73..aff6f49cd 100644 --- a/src/main/snort.cc +++ b/src/main/snort.cc @@ -93,7 +93,6 @@ #include "catch/snort_catch.h" #endif -#include "log/batched_logger.h" #include "snort_config.h" #include "thread_config.h" @@ -435,7 +434,6 @@ void Snort::setup(int argc, char* argv[]) init(argc, argv); const SnortConfig* sc = SnortConfig::get_conf(); - BatchedLogger::BatchedLogManager::init(); if ( sc->daemon_mode() ) daemonize(); diff --git a/src/main/snort_config.h b/src/main/snort_config.h index 015bb2f8b..a49e4a63c 100644 --- a/src/main/snort_config.h +++ b/src/main/snort_config.h @@ -100,6 +100,7 @@ enum OutputFlag OUTPUT_FLAG__WIDE_HEX = 0x00000800, OUTPUT_FLAG__ALERT_REFS = 0x00001000, + OUTPUT_FLAG__LOG_BUFFERED = 0x00002000, }; enum LoggingFlag @@ -575,6 +576,9 @@ public: bool obfuscate() const { return output_flags & OUTPUT_FLAG__OBFUSCATE; } + bool use_log_buffered() const + { return output_flags & OUTPUT_FLAG__LOG_BUFFERED; } + bool output_app_data() const { return output_flags & OUTPUT_FLAG__APP_DATA; } diff --git a/src/packet_io/packet_tracer.cc b/src/packet_io/packet_tracer.cc index 6d9772f65..2db50f59b 100644 --- a/src/packet_io/packet_tracer.cc +++ b/src/packet_io/packet_tracer.cc @@ -160,16 +160,21 @@ void PacketTracer::dump(Packet* p) const char* drop_reason = p->active->get_drop_reason(); if (drop_reason) PacketTracer::log("Verdict Reason: %s, %s\n", drop_reason, p->active->get_action_string() ); - if (s_pkt_trace->buff_len < max_buff_size - 1) - s_pkt_trace->buffer[s_pkt_trace->buff_len++] = '\n'; - if (s_pkt_trace->log_fh && s_pkt_trace->log_fh != stdout) + if(!snort::SnortConfig::get_conf()->use_log_buffered()) + LogMessage(s_pkt_trace->log_fh, "%s\n", s_pkt_trace->buffer); + else { - fprintf(s_pkt_trace->log_fh, "%.*s", s_pkt_trace->buff_len, s_pkt_trace->buffer); - fflush(s_pkt_trace->log_fh); + if (s_pkt_trace->buff_len < max_buff_size - 1) + s_pkt_trace->buffer[s_pkt_trace->buff_len++] = '\n'; + if (s_pkt_trace->log_fh && s_pkt_trace->log_fh != stdout) + { + fprintf(s_pkt_trace->log_fh, "%.*s", s_pkt_trace->buff_len, s_pkt_trace->buffer); + fflush(s_pkt_trace->log_fh); + } + else + BatchedLogger::BatchedLogManager::log(s_pkt_trace->log_fh, SnortConfig::log_syslog(), + s_pkt_trace->buffer, s_pkt_trace->buff_len); } - else - BatchedLogger::BatchedLogManager::log(s_pkt_trace->log_fh, SnortConfig::log_syslog(), - s_pkt_trace->buffer, s_pkt_trace->buff_len); } s_pkt_trace->reset(false); diff --git a/src/packet_io/packet_tracer_module.cc b/src/packet_io/packet_tracer_module.cc index 164fb8c5b..e45e64fa6 100644 --- a/src/packet_io/packet_tracer_module.cc +++ b/src/packet_io/packet_tracer_module.cc @@ -166,7 +166,20 @@ static int enable(lua_State* L) constraints.set_bits |= PacketConstraints::SetBits::DST_PORT; std::string filter_str = regexstr ? regexstr : ""; - if (!filter_str.empty()) filter_str = (stop_after_match ? "Y" : "N") + filter_str; + if (!filter_str.empty()) + { + if (!snort::SnortConfig::get_conf()->use_log_buffered()) + { + LogMessage("WARNING: Regex filtering requires log_buffered to be enabled.\n"); + LogMessage(" Continuing with packet tracer but ignoring regex filter.\n"); + LogMessage(" To enable regex filtering, add 'log_buffered = true' to output configuration.\n"); + + filter_str.clear(); + } + else + filter_str = (stop_after_match ? "Y" : "N") + filter_str; + } + BatchedLogger::BatchedLogManager::set_filter(filter_str); main_broadcast_command(new PacketTracerDebug(&constraints), ControlConn::query_from_lua(L)); return 0; diff --git a/src/time/periodic.cc b/src/time/periodic.cc index 795bd56b3..39dd3a1ff 100644 --- a/src/time/periodic.cc +++ b/src/time/periodic.cc @@ -66,6 +66,13 @@ void Periodic::check() } } +void Periodic::unregister_handler(PeriodicHook hook) +{ + s_periodic_handlers.remove_if([hook](const PeriodicHookNode& node) { + return node.hook == hook; + }); +} + void Periodic::unregister_all() { s_periodic_handlers.clear(); } diff --git a/src/time/periodic.h b/src/time/periodic.h index b79fb1f02..ab573efbf 100644 --- a/src/time/periodic.h +++ b/src/time/periodic.h @@ -33,6 +33,7 @@ public: static void register_handler(PeriodicHook, void*, uint16_t priority, uint32_t); static void check(); + static void unregister_handler(PeriodicHook hook); static void unregister_all(); };