From a28d25cbf56172a8c0d10939699d40fdd1989601 Mon Sep 17 00:00:00 2001 From: "Raza Shafiq (rshafiq)" Date: Mon, 27 Oct 2025 14:50:32 +0000 Subject: [PATCH] Pull request #4884: flow: add new flow prune reason Merge in SNORT/snort3 from ~RSHAFIQ/snort3:flow_release to master Squashed commit of the following: commit c6c4c580d3aa46a09b9063b08347c6071de631f6 Author: rshafiq Date: Tue Aug 26 16:51:20 2025 -0400 flow: new pegs and packet tracer log for flow prune --- src/flow/CMakeLists.txt | 1 + src/flow/flow.cc | 3 ++- src/flow/flow_cache.cc | 18 +++++++++++++++++- src/flow/flow_cache.h | 5 ++++- src/flow/prune_stats.h | 19 +++++++++++++++++-- src/flow/test/flow_cache_test.cc | 2 -- src/flow/test/flow_control_test.cc | 1 - src/flow/test/flow_stubs.h | 1 + src/packet_io/packet_tracer.cc | 20 ++++++++++++++++++++ src/packet_io/packet_tracer.h | 20 ++++++++++++++++++++ src/stream/base/stream_base.cc | 18 ++++++++++++++++++ src/stream/base/stream_module.h | 9 +++++++++ src/stream/stream.cc | 6 +++--- src/stream/stream.h | 2 ++ src/utils/util.h | 7 +++++++ 15 files changed, 121 insertions(+), 11 deletions(-) diff --git a/src/flow/CMakeLists.txt b/src/flow/CMakeLists.txt index 5ea36dac1..f54f2fcb2 100644 --- a/src/flow/CMakeLists.txt +++ b/src/flow/CMakeLists.txt @@ -6,6 +6,7 @@ set (FLOW_INCLUDES flow_key.h flow_stash.h ha.h + prune_stats.h session.h stream_flow.h ) diff --git a/src/flow/flow.cc b/src/flow/flow.cc index 9221ea2ef..69a9aab39 100644 --- a/src/flow/flow.cc +++ b/src/flow/flow.cc @@ -483,7 +483,8 @@ bool Flow::handle_allowlist() { if ( flow_con->move_to_allowlist(this) ) { - PacketTracer::log("Flow: flow has been moved to allowlist cache\n"); + if ( PacketTracer::is_active() ) + PacketTracer::log("Flow: flow has been moved to allowlist cache\n"); return true; } } diff --git a/src/flow/flow_cache.cc b/src/flow/flow_cache.cc index 546402701..e61092bb8 100644 --- a/src/flow/flow_cache.cc +++ b/src/flow/flow_cache.cc @@ -438,6 +438,9 @@ bool FlowCache::release(Flow* flow, PruneReason reason, bool do_cleanup) } } + if ( UNLIKELY(PacketTracer::is_active()) ) + log_flow_release(flow, reason); + uint8_t in_allowlist = flow->flags.in_allowlist; flow->reset(do_cleanup); prune_stats.update(reason, ( in_allowlist ? static_cast(allowlist_lru_index) : flow->key->pkt_type )); @@ -1017,7 +1020,8 @@ bool FlowCache::filter_flows(const Flow& flow, const FilterFlowCriteria& ffc) co return true; } -void FlowCache::output_flow(std::fstream& stream, const Flow& flow, const struct timeval& now) const +template +void FlowCache::output_flow(StreamType& stream, const Flow& flow, const struct timeval& now) const { char src_ip[INET6_ADDRSTRLEN]; src_ip[0] = 0; @@ -1226,4 +1230,16 @@ size_t FlowCache::count_flows_in_lru(uint8_t lru_index) const } #endif +inline void FlowCache::log_flow_release(const snort::Flow* flow, PruneReason reason) const +{ + PacketTracerUnsuspend pt_unsusp; + + std::stringstream temp_stream; + struct timeval now; + packet_gettimeofday(&now); + output_flow(temp_stream, *flow, now); + std::string flow_info = temp_stream.str(); + + PacketTracer::log("Flow: Releasing flow due to %s: %s", prune_reason_to_string(reason), flow_info.c_str()); +} diff --git a/src/flow/flow_cache.h b/src/flow/flow_cache.h index 572d808a9..f57755357 100644 --- a/src/flow/flow_cache.h +++ b/src/flow/flow_cache.h @@ -180,7 +180,8 @@ public: bool move_to_allowlist(snort::Flow* f); virtual bool filter_flows(const snort::Flow&, const FilterFlowCriteria&) const; - virtual void output_flow(std::fstream&, const snort::Flow&, const struct timeval&) const; + template + void output_flow(StreamType&, const snort::Flow&, const struct timeval&) const; unsigned get_flows_allocated() const; @@ -229,6 +230,8 @@ private: empty_lru_masks |= lru_mask; } + inline void log_flow_release(const snort::Flow* flow, PruneReason reason) const; + private: uint8_t timeout_idx; static const unsigned cleanup_flows = 1; diff --git a/src/flow/prune_stats.h b/src/flow/prune_stats.h index 544d6d7d9..ba7220043 100644 --- a/src/flow/prune_stats.h +++ b/src/flow/prune_stats.h @@ -23,6 +23,7 @@ #include #include +#include #include "framework/counts.h" @@ -33,12 +34,26 @@ enum class PruneReason : uint8_t MEMCAP, HA, STALE, - IDLE_MAX_FLOWS, - IDLE_PROTOCOL_TIMEOUT, + IDLE_MAX_FLOWS, + IDLE_PROTOCOL_TIMEOUT, + STREAM_CLOSED, + END_OF_FLOW, NONE, MAX }; +inline const char* prune_reason_to_string(PruneReason reason) +{ + static constexpr const char* names[] = { + "EXCESS", "UNI", "MEMCAP", "HA", "STALE", + "IDLE_MAX_FLOWS", "IDLE_PROTOCOL_TIMEOUT", + "STREAM_CLOSED", "EOF", "NONE" + }; + + auto idx = static_cast(reason); + return (idx < static_cast(PruneReason::MAX)) ? names[idx] : "UNKNOWN"; +} + struct LRUPruneStats { using lru_t = std::underlying_type_t; diff --git a/src/flow/test/flow_cache_test.cc b/src/flow/test/flow_cache_test.cc index 679f7ab6e..9ecd8edf1 100644 --- a/src/flow/test/flow_cache_test.cc +++ b/src/flow/test/flow_cache_test.cc @@ -151,7 +151,6 @@ class DummyCache : public FlowCache public: DummyCache(const FlowCacheConfig& cfg) : FlowCache(cfg) {} ~DummyCache() = default; - void output_flow(std::fstream& stream, const Flow& flow, const struct timeval& now) const override { (void)stream, (void)flow, (void)now; }; bool filter_flows(const Flow& flow, const FilterFlowCriteria& ffc) const override { (void)flow; (void)ffc; return true; }; }; @@ -160,7 +159,6 @@ class DummyCacheWithFilter : public FlowCache public: DummyCacheWithFilter(const FlowCacheConfig& cfg) : FlowCache(cfg) {} ~DummyCacheWithFilter() = default; - void output_flow(std::fstream& stream, const Flow& flow, const struct timeval& now) const override { (void)stream, (void)flow, (void)now; }; }; TEST_GROUP(flow_prune) { }; diff --git a/src/flow/test/flow_control_test.cc b/src/flow/test/flow_control_test.cc index 4a88e0fc3..c05301357 100644 --- a/src/flow/test/flow_control_test.cc +++ b/src/flow/test/flow_control_test.cc @@ -77,7 +77,6 @@ const SnortConfig* SnortConfig::get_conf() { return nullptr; } void FlowCache::unlink_uni(Flow*) { } bool FlowCache::dump_flows(std::fstream&, unsigned, const FilterFlowCriteria&, bool, uint8_t) const { return false; } bool FlowCache::dump_flows_summary(FlowsSummary&, const FilterFlowCriteria&) const { return false; } -void FlowCache::output_flow(std::fstream&, const Flow&, const struct timeval& ) const { } bool FlowCache::filter_flows(const Flow&, const FilterFlowCriteria&) const { return true; }; void Flow::set_client_initiate(Packet*) { } void Flow::set_direction(Packet*) { } diff --git a/src/flow/test/flow_stubs.h b/src/flow/test/flow_stubs.h index d929409c3..46d42877c 100644 --- a/src/flow/test/flow_stubs.h +++ b/src/flow/test/flow_stubs.h @@ -57,6 +57,7 @@ void PacketTracer::dump_to_daq(Packet*) { } void PacketTracer::reset(bool) { } void PacketTracer::pause() { } void PacketTracer::unpause() { } +bool PacketTracer::is_paused() { return true; } bool PacketTracer::is_active() { return false; } namespace layer diff --git a/src/packet_io/packet_tracer.cc b/src/packet_io/packet_tracer.cc index 2db50f59b..f67905fe1 100644 --- a/src/packet_io/packet_tracer.cc +++ b/src/packet_io/packet_tracer.cc @@ -132,6 +132,26 @@ void PacketTracer::thread_init() void PacketTracer::thread_term() { + if ( s_pkt_trace and s_pkt_trace->buff_len > 0 + and ( s_pkt_trace->user_enabled or s_pkt_trace->shell_enabled ) ) + { + if ( !snort::SnortConfig::get_conf()->use_log_buffered() ) + LogMessage(s_pkt_trace->log_fh, "%s\n", s_pkt_trace->buffer); + else + { + if ( s_pkt_trace->log_fh and s_pkt_trace->log_fh != stdout ) + { + fprintf(s_pkt_trace->log_fh, "%.*s\n", 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); + } + } + } + BatchedLogger::BatchedLogManager::flush_thread_buffers(); delete s_pkt_trace; s_pkt_trace = nullptr; diff --git a/src/packet_io/packet_tracer.h b/src/packet_io/packet_tracer.h index eb1422aa4..961039c4e 100644 --- a/src/packet_io/packet_tracer.h +++ b/src/packet_io/packet_tracer.h @@ -135,5 +135,25 @@ struct PacketTracerSuspend { PacketTracer::unpause(); } }; +struct PacketTracerUnsuspend +{ + unsigned saved_pause_count = 0; + + PacketTracerUnsuspend() + { + while (PacketTracer::is_paused()) + { + PacketTracer::unpause(); + saved_pause_count++; + } + } + + ~PacketTracerUnsuspend() noexcept + { + for (unsigned i = 0; i < saved_pause_count; i++) + PacketTracer::pause(); + } +}; + } #endif diff --git a/src/stream/base/stream_base.cc b/src/stream/base/stream_base.cc index eb27ffb1a..df706971f 100644 --- a/src/stream/base/stream_base.cc +++ b/src/stream/base/stream_base.cc @@ -70,6 +70,7 @@ const PegInfo base_pegs[] = { CountType::SUM, "memcap_prunes", "sessions pruned due to memcap" }, { CountType::SUM, "ha_prunes", "sessions pruned by high availability sync" }, { CountType::SUM, "stale_prunes", "sessions pruned due to stale connection" }, + { CountType::SUM, "closed_prunes", "sessions pruned due to stream closed" }, { CountType::SUM, "expected_flows", "total expected flows created within snort" }, { CountType::SUM, "expected_realized", "number of expected flows realized" }, { CountType::SUM, "expected_pruned", "number of expected flows pruned" }, @@ -97,6 +98,14 @@ const PegInfo base_pegs[] = { CountType::SUM, "file_memcap_prunes", "number of FILE flows pruned due to memcap" }, { CountType::SUM, "pdu_memcap_prunes", "number of PDU flows pruned due to memcap" }, { CountType::SUM, "allowlist_memcap_prunes", "number of allowlist flows pruned due to memcap" }, + { CountType::SUM, "ip_eof_prunes", "number of IP flows pruned due to EOF" }, + { CountType::SUM, "tcp_eof_prunes", "number of TCP flows pruned due to EOF" }, + { CountType::SUM, "udp_eof_prunes", "number of UDP flows pruned due to EOF" }, + { CountType::SUM, "icmp_eof_prunes", "number of ICMP flows pruned due to EOF" }, + { CountType::SUM, "user_eof_prunes", "number of USER flows pruned due to EOF" }, + { CountType::SUM, "file_eof_prunes", "number of FILE flows pruned due to EOF" }, + { CountType::SUM, "pdu_eof_prunes", "number of PDU flows pruned due to EOF" }, + { CountType::SUM, "allowlist_eof_prunes", "number of allowlist flows pruned due to EOF" }, { CountType::SUM, "excess_to_allowlist", "number of flows moved to the allowlist due to excess" }, // Keep the NOW stats at the bottom as it requires special sum_stats logic @@ -124,6 +133,7 @@ void base_prep() stream_base_stats.memcap_prunes = flow_con->get_prunes(PruneReason::MEMCAP); stream_base_stats.ha_prunes = flow_con->get_prunes(PruneReason::HA); stream_base_stats.stale_prunes = flow_con->get_prunes(PruneReason::STALE); + stream_base_stats.closed_prunes = flow_con->get_prunes(PruneReason::STREAM_CLOSED); stream_base_stats.reload_freelist_flow_deletes = flow_con->get_deletes(FlowDeleteState::FREELIST); stream_base_stats.reload_allowed_flow_deletes = flow_con->get_deletes(FlowDeleteState::ALLOWED); stream_base_stats.reload_offloaded_flow_deletes= flow_con->get_deletes(FlowDeleteState::OFFLOADED); @@ -143,6 +153,14 @@ void base_prep() stream_base_stats.file_memcap_prunes = flow_con->get_proto_prune_count(PruneReason::MEMCAP, PktType::FILE); stream_base_stats.pdu_memcap_prunes = flow_con->get_proto_prune_count(PruneReason::MEMCAP, PktType::PDU); stream_base_stats.allowlist_memcap_prunes = flow_con->get_proto_prune_count(PruneReason::MEMCAP, static_cast(allowlist_lru_index)); + stream_base_stats.ip_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::IP); + stream_base_stats.tcp_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::TCP); + stream_base_stats.udp_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::UDP); + stream_base_stats.icmp_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::ICMP); + stream_base_stats.user_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::USER); + stream_base_stats.file_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::FILE); + stream_base_stats.pdu_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, PktType::PDU); + stream_base_stats.allowlist_eof_prunes = flow_con->get_proto_prune_count(PruneReason::END_OF_FLOW, static_cast(allowlist_lru_index)); stream_base_stats.excess_to_allowlist = flow_con->get_excess_to_allowlist_count(); stream_base_stats.allowlist_flows = flow_con->get_allowlist_flow_count(); diff --git a/src/stream/base/stream_module.h b/src/stream/base/stream_module.h index 208eda2d4..89dd2552e 100644 --- a/src/stream/base/stream_module.h +++ b/src/stream/base/stream_module.h @@ -77,6 +77,7 @@ struct BaseStats PegCount memcap_prunes; PegCount ha_prunes; PegCount stale_prunes; + PegCount closed_prunes; PegCount expected_flows; PegCount expected_realized; PegCount expected_pruned; @@ -104,6 +105,14 @@ struct BaseStats PegCount file_memcap_prunes; PegCount pdu_memcap_prunes; PegCount allowlist_memcap_prunes; + PegCount ip_eof_prunes; + PegCount tcp_eof_prunes; + PegCount udp_eof_prunes; + PegCount icmp_eof_prunes; + PegCount user_eof_prunes; + PegCount file_eof_prunes; + PegCount pdu_eof_prunes; + PegCount allowlist_eof_prunes; PegCount excess_to_allowlist; // Keep the NOW stats at the bottom as it requires special sum_stats logic diff --git a/src/stream/stream.cc b/src/stream/stream.cc index 625e2c60f..3d88004a7 100644 --- a/src/stream/stream.cc +++ b/src/stream/stream.cc @@ -81,8 +81,8 @@ Flow* Stream::new_flow(const FlowKey* key) void Stream::delete_flow(const FlowKey* key) { flow_con->release_flow(key); } -void Stream::delete_flow(Flow* flow) -{ flow_con->release_flow(flow, PruneReason::NONE); } +void Stream::delete_flow(Flow* flow, PruneReason reason) +{ flow_con->release_flow(flow, reason); } //------------------------------------------------------------------------- // key foo @@ -194,7 +194,7 @@ void Stream::check_flow_closed(Packet* p) // eventually all onloads will occur and delete will be called if ( not flow->is_suspended() ) { - flow_con->release_flow(flow, PruneReason::NONE); + flow_con->release_flow(flow, PruneReason::STREAM_CLOSED); return; } } diff --git a/src/stream/stream.h b/src/stream/stream.h index f8c40eb47..77e714e3d 100644 --- a/src/stream/stream.h +++ b/src/stream/stream.h @@ -29,6 +29,7 @@ #include #include "flow/flow.h" +#include "flow/prune_stats.h" #include "main/policy.h" #include "protocols/packet.h" #include "time/packet_time.h" @@ -113,6 +114,7 @@ public: // the resources allocated to that flow to the free list. static void delete_flow(const FlowKey*); static void delete_flow(Flow*); + static void delete_flow(Flow*, PruneReason reason = PruneReason::NONE); // Examines the source and destination ip addresses and ports to determine if the // packet is from the client or server side of the flow and sets bits in the diff --git a/src/utils/util.h b/src/utils/util.h index f3302b512..b17431f3d 100644 --- a/src/utils/util.h +++ b/src/utils/util.h @@ -57,6 +57,13 @@ #endif +#ifdef __GNUC__ +#define UNLIKELY(x) __builtin_expect(!!(x), 0) +#else +#define UNLIKELY(x) (x) +#endif + + #define TIMEBUF_SIZE 27 #define SECONDS_PER_DAY 86400 /* number of seconds in a day */ -- 2.47.3