Pull request #4492: stream_tcp: when queue limit thresholds are exceeded in IDS mode...

Merge in SNORT/snort3 from ~DAVMCPHE/snort3:ids_asymmetric_tweaks to master

Squashed commit of the following:

commit 3ea41ca77b1fc9f6f1bb775eb01ed784fdc71ad9
Author: davis mcpherson <davmcphe@cisco.com>
Date:   Tue Oct 22 12:10:15 2024 -0400

    stream_tcp: when queue limit thresholds are exceeded in IDS mode on asymmetric connections only skip a hole at the beginning of the seglist before flushing

diff --git a/src/stream/tcp/tcp_event_logger.cc b/src/stream/tcp/tcp_event_logger.cc
index 11bb79c81b32dc5ec10199bb7aafce9d2fcc42e6..67348e84563d178e01c03ac0516768b21464f0e9 100644 (file)
--- a/src/stream/tcp/tcp_event_logger.cc
+++ b/src/stream/tcp/tcp_event_logger.cc
@@ -89,7 +89,7 @@ void TcpEventLogger::log_tcp_events()
         {
             DetectionEngine::queue_event(GID_STREAM_TCP, tcp_event_sids[idx].sid);
             if ( PacketTracer::is_active() )
-                PacketTracer::log("Stream: TCP raised %u:%u %s\n",
+                PacketTracer::log("stream_tcp: TCP raised %u:%u %s\n",
                     GID_STREAM_TCP, tcp_event_sids[idx].sid,
                     tcp_event_sids[idx].event_description);
             tcp_events ^= tcp_event_sids[idx].event_id;

diff --git a/src/stream/tcp/tcp_module.cc b/src/stream/tcp/tcp_module.cc
index dbef615d80b15390e117bbca0dece87957b611e2..98338572fa98d508435ba24b96c9a5280df8c093 100644 (file)
--- a/src/stream/tcp/tcp_module.cc
+++ b/src/stream/tcp/tcp_module.cc
@@ -188,6 +188,9 @@ static const Parameter stream_queue_limit_params[] =
     { "max_segments", Parameter::PT_INT, "0:max32", "3072",
       "don't queue more than given segments per session and direction, 0 = unlimited" },
 
+    { "asymmetric_ids_flush_threshold", Parameter::PT_INT, "1:max31", "3145728",
+      "max bytes queued on asymmetric flow before flush in IDS mode" },
+
     { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }
 };
 
@@ -238,10 +241,6 @@ static const Parameter s_params[] =
     { "idle_timeout", Parameter::PT_INT, "1:max31", "3600",
       "session deletion on idle " },
 
-    { "asymmetric_ids_flush_threshold", Parameter::PT_INT, "1:max31", "65535",
-      "max bytes queued on asymmetric flow before flush in IDS mode" },
-
-
     { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }
 };
 

diff --git a/src/stream/tcp/tcp_normalizer.cc b/src/stream/tcp/tcp_normalizer.cc
index 62904fc9daf29c5f412e238e94594ec8635741dd..348790096a7461574bda5672cac0b1a5d8c95e1d 100644 (file)
--- a/src/stream/tcp/tcp_normalizer.cc
+++ b/src/stream/tcp/tcp_normalizer.cc
@@ -93,11 +93,13 @@ TcpNormalizer::NormStatus TcpNormalizer::apply_normalizations(
         {
             tcpStats.zero_win_probes++;
             trim_win_payload(tns, tsd, MAX_ZERO_WIN_PROBE_LEN, inline_mode);
-            log_drop_reason(tns, tsd, inline_mode, "stream", "Normalizer: Maximum Zero Window Probe length supported at a time is 1 byte\n");
+            log_drop_reason(tns, tsd, inline_mode, "stream",
+                "Normalizer: Maximum Zero Window Probe length supported at a time is 1 byte\n");
             return NORM_TRIMMED;
         }
 
-        log_drop_reason(tns, tsd, inline_mode, "stream", "Normalizer: Received data during a Zero Window that is not a Zero Window Probe\n");
+        log_drop_reason(tns, tsd, inline_mode, "stream",
+            "Normalizer: Received data during a Zero Window that is not a Zero Window Probe\n");
         trim_win_payload(tns, tsd, 0, inline_mode);
         return NORM_TRIMMED;
     }
@@ -148,9 +150,7 @@ void TcpNormalizer::session_blocker(
     p->active->block_session(p, true);
     p->active->set_drop_reason("stream");
     if (PacketTracer::is_active())
-        {
-            PacketTracer::log("Normalizer: TCP Zero Window Probe byte data mismatch\n");
-        }
+        PacketTracer::log("stream_tcp: TCP normalizer - Zero Window Probe byte data mismatch\n");
 }
 
 bool TcpNormalizer::packet_dropper(
@@ -182,7 +182,8 @@ bool TcpNormalizer::trim_syn_payload(
     if (len > max)
     {
         if ( PacketTracer::is_active() && (NormMode)tns.trim_syn == NORM_MODE_ON )
-            PacketTracer::log("Normalizer: Trimming payload of SYN packet with length (%u) to a maximum value of %u\n", len, max);
+            PacketTracer::log("stream_tcp: TCP normalizer - Trimming payload of SYN packet "
+                "with length (%u) to a maximum value of %u\n", len, max);
 
         return trim_payload(tns, tsd, max, (NormMode)tns.trim_syn, PC_TCP_TRIM_SYN);
     }
@@ -197,7 +198,8 @@ void TcpNormalizer::trim_rst_payload(
     if (len > max)
     {
         if ( PacketTracer::is_active() && (NormMode)tns.trim_rst == NORM_MODE_ON )
-            PacketTracer::log("Normalizer: Trimming payload of RST packet with length (%u) to a maximum value of %u\n", len, max);
+            PacketTracer::log("stream_tcp: TCP normalizer - Trimming payload of RST packet "
+                "with length (%u) to a maximum value of %u\n", len, max);
 
         trim_payload(tns, tsd, max, (NormMode)tns.trim_rst, PC_TCP_TRIM_RST);
     }
@@ -211,7 +213,8 @@ void TcpNormalizer::trim_win_payload(
     if (len > max)
     {
         if ( PacketTracer::is_active() && (force || (NormMode)tns.trim_win == NORM_MODE_ON) )
-            PacketTracer::log("Normalizer: Trimming payload with length (%u) to a maximum value of %u\n", len, max);
+            PacketTracer::log("stream_tcp: TCP normalizer - Trimming payload with length (%u) "
+                "to a maximum value of %u\n", len, max);
 
         trim_payload(tns, tsd, max, (NormMode)tns.trim_win, PC_TCP_TRIM_WIN, force);
     }
@@ -225,7 +228,8 @@ void TcpNormalizer::trim_mss_payload(
     if (len > max)
     {
         if ( PacketTracer::is_active() && (NormMode)tns.trim_mss == NORM_MODE_ON )
-            PacketTracer::log("Normalizer: Trimming payload with length (%u) to fit MSS size (%u)\n", len, max);
+            PacketTracer::log("stream_tcp: TCP normalizer - Trimming payload with length (%u) "
+                "to fit MSS size (%u)\n", len, max);
 
         trim_payload(tns, tsd, max, (NormMode)tns.trim_mss, PC_TCP_TRIM_MSS);
     }
@@ -516,7 +520,7 @@ void TcpNormalizer::log_drop_reason(TcpNormalizerState& tns, const TcpSegmentDes
     {
         tsd.get_pkt()->active->set_drop_reason(issuer);
         if (PacketTracer::is_active())
-            PacketTracer::log("%s", log.c_str());
+            PacketTracer::log("stream_tcp: %s", log.c_str());
         if (stream_tcp_trace_enabled)
             trace_logf(TRACE_WARNING_LEVEL, stream_tcp_trace, DEFAULT_TRACE_OPTION_ID, tsd.get_pkt(), "%s", log.c_str());
     }

diff --git a/src/stream/tcp/tcp_reassembler_ids.cc b/src/stream/tcp/tcp_reassembler_ids.cc
index b8d7825933fc09fabf57f74730e85a34c2ce5010..54518aef488df36f4d8b901989790f2564780eb7 100644 (file)
--- a/src/stream/tcp/tcp_reassembler_ids.cc
+++ b/src/stream/tcp/tcp_reassembler_ids.cc
@@ -31,6 +31,7 @@
 #include "log/log.h"
 #include "main/analyzer.h"
 #include "packet_io/active.h"
+#include "packet_io/packet_tracer.h"
 #include "profiler/profiler.h"
 #include "protocols/packet_manager.h"
 #include "time/packet_time.h"
@@ -233,7 +234,7 @@ int TcpReassemblerIds::eval_flush_policy_on_data(Packet* p)
     if ( !p->flow->two_way_traffic() and
         seglist->get_seg_bytes_total() > seglist->session->tcp_config->asymmetric_ids_flush_threshold )
     {
-        seglist->skip_holes();
+        seglist->skip_hole_at_beginning(seglist->head);
         flushed += eval_asymmetric_flush(p);
     }
 
@@ -247,7 +248,11 @@ int TcpReassemblerIds::eval_asymmetric_flush(snort::Packet* p)
 
     uint32_t flushed = eval_flush_policy_on_ack(p);
     if ( flushed )
+    {
+        if (PacketTracer::is_active())
+            PacketTracer::log("stream_tcp: IDS mode - %u bytes flushed on asymmetric flow\n", flushed);
         tcpStats.flush_on_asymmetric_flow++;
+    }
 
     return flushed;
 }

diff --git a/src/stream/tcp/tcp_reassembler_ips.cc b/src/stream/tcp/tcp_reassembler_ips.cc
index 6ed2bd5cf334f1cc007171f3ca82fe475375f0ac..3795f5c90c99a2cc799bdfb51550df159c69d2ca 100644 (file)
--- a/src/stream/tcp/tcp_reassembler_ips.cc
+++ b/src/stream/tcp/tcp_reassembler_ips.cc
@@ -31,6 +31,7 @@
 #include "log/log.h"
 #include "main/analyzer.h"
 #include "packet_io/active.h"
+#include "packet_io/packet_tracer.h"
 #include "profiler/profiler.h"
 #include "protocols/packet_manager.h"
 #include "time/packet_time.h"
@@ -155,6 +156,9 @@ int TcpReassemblerIps::eval_flush_policy_on_data(Packet* p)
 
     if ( asymmetric_flow_flushed(flushed, p) )
     {
+        if (PacketTracer::is_active())
+            PacketTracer::log("stream_tcp: IPS mode - %u bytes flushed on asymmetric flow\n", flushed);
+
         purge_to_seq(seglist->head->start_seq() + flushed);
         tracker->r_win_base = seglist->seglist_base_seq;
         tcpStats.flush_on_asymmetric_flow++;

diff --git a/src/stream/tcp/tcp_reassembly_segments.cc b/src/stream/tcp/tcp_reassembly_segments.cc
index 20d97e29d90866d2728e27d389fa6270ce415f45..a5106c8ad03cdb195fe948feea757fa9a02b99d9 100644 (file)
--- a/src/stream/tcp/tcp_reassembly_segments.cc
+++ b/src/stream/tcp/tcp_reassembly_segments.cc
@@ -367,7 +367,7 @@ void TcpReassemblySegments::purge_segments_left_of_hole(const TcpSegmentNode* en
     tracker->set_order(TcpStreamTracker::OUT_OF_SEQUENCE);
 
     if (PacketTracer::is_active())
-        PacketTracer::log("Stream: Skipped %u packets before seglist hole\n", packets_skipped);
+        PacketTracer::log("stream_tcp: Skipped %u packets before seglist hole\n", packets_skipped);
 }
 
 void TcpReassemblySegments::advance_rcv_nxt(TcpSegmentNode *tsn)
@@ -384,28 +384,52 @@ void TcpReassemblySegments::advance_rcv_nxt(TcpSegmentNode *tsn)
     tracker->set_rcv_nxt(tsn->next_seq());
 }
 
-void TcpReassemblySegments::skip_holes()
+bool TcpReassemblySegments::skip_hole_at_beginning(TcpSegmentNode *tsn)
 {
-    TcpSegmentNode* tsn = head;
-    // if there is a hole at the beginning, skip it...
-    if ( SEQ_GT(tsn->seq, seglist_base_seq) )
+    assert( tsn );
+
+    bool hole_skipped = false;
+
+    if (SEQ_GT(tsn->seq, seglist_base_seq))
     {
+        hole_skipped = true;
         seglist_base_seq = tsn->seq;
         tracker->set_order(TcpStreamTracker::OUT_OF_SEQUENCE);
-
         if (PacketTracer::is_active())
-            PacketTracer::log("Stream: Skipped hole at beginning of the seglist\n");
+            PacketTracer::log("stream_tcp: Skipped hole at beginning of the seglist\n");
     }
 
+    return hole_skipped;
+}
+
+void TcpReassemblySegments::skip_holes()
+{
+    assert( head );
+
+    TcpSegmentNode* tsn = head;
+    uint32_t num_segs = 0, total_segs = 0, num_holes = 0;
+
+    // if there is a hole at the beginning, skip it...
+    if ( skip_hole_at_beginning(tsn) )
+        ++num_holes;
+
     while ( tsn )
     {
+        ++num_segs;
+
         if ( tsn->next and SEQ_GT(tsn->next->start_seq(), tsn->next_seq()) )
         {
+            ++num_holes;
+            total_segs += num_segs;
+            if (PacketTracer::is_active())
+                PacketTracer::log("stream_tcp: Seglist hole(%u): %u-->%u:%u. Segments purged: %u Total purged: %u\n",
+                    tsn->seq, tsn->next->seq, tsn->next->seq - tsn->seq, num_holes, num_segs, total_segs);
             tsn = tsn->next;
             purge_segments_left_of_hole(tsn);
             seglist_base_seq = head->start_seq();
+            num_segs = 0;
         }
-       else
+        else
             tsn = tsn->next;
     }
 

diff --git a/src/stream/tcp/tcp_reassembly_segments.h b/src/stream/tcp/tcp_reassembly_segments.h
index df1a79d7d7786823c112992bc2ede7b9bcdfb6f2..5fc87f9cc42cc1160f02730ba1f9928ccbccdcaa 100644 (file)
--- a/src/stream/tcp/tcp_reassembly_segments.h
+++ b/src/stream/tcp/tcp_reassembly_segments.h
@@ -54,6 +54,7 @@ public:
     void purge_flushed_segments(uint32_t flush_seq);
     void skip_holes();
     void skip_midstream_pickup_seglist_hole(TcpSegmentDescriptor&);
+    bool skip_hole_at_beginning(TcpSegmentNode*);
     void purge_segment_list();
 
     bool is_segment_pending_flush() const;

diff --git a/src/stream/tcp/tcp_segment_descriptor.cc b/src/stream/tcp/tcp_segment_descriptor.cc
index 09ed78728bc6d0dc3f10efff38a7492752039cc5..1349891614a05fe2ecdb99190cbf0ebfb8a82931 100644 (file)
--- a/src/stream/tcp/tcp_segment_descriptor.cc
+++ b/src/stream/tcp/tcp_segment_descriptor.cc
@@ -171,7 +171,7 @@ void TcpSegmentDescriptor::set_retransmit_flag()
 {
     if ( PacketTracer::is_active() )
     {
-        PacketTracer::log("Packet was retransmitted and %s from the retry queue.\n",
+        PacketTracer::log("stream_tcp: Packet was retransmitted and %s from the retry queue.\n",
             pkt->is_retry() ? "is" : "is not");
     }
 

diff --git a/src/stream/tcp/tcp_session.cc b/src/stream/tcp/tcp_session.cc
index f730fe3e3f9da379170fc467c03e090c36ec1273..7e720d0d946556de96b07113fe4a50fe85a290d0 100644 (file)
--- a/src/stream/tcp/tcp_session.cc
+++ b/src/stream/tcp/tcp_session.cc
@@ -279,7 +279,7 @@ void TcpSession::check_flow_missed_3whs()
         return;
 
     if ( PacketTracer::is_active() )
-        PacketTracer::log("Stream TCP did not see the complete 3-Way Handshake. "
+        PacketTracer::log("stream_tcp: TCP did not see the complete 3-Way Handshake. "
         "Not all normalizations will be in effect\n");
 
     client.normalizer.init(StreamPolicy::MISSED_3WHS, this, &client, &server);
@@ -627,7 +627,7 @@ bool TcpSession::check_reassembly_queue_thresholds(TcpSegmentDescriptor& tsd, Tc
                 // FIXIT-M - only alert once per threshold exceeded event
                 tel.set_tcp_event(EVENT_MAX_QUEUED_BYTES_EXCEEDED);
                 listener->normalizer.log_drop_reason(tsd, inline_mode, "stream",
-                    "Stream: Flow exceeded the configured max byte threshold (" + std::to_string(tcp_config->max_queued_bytes) +
+                    "stream_tcp: Flow exceeded the configured max byte threshold (" + std::to_string(tcp_config->max_queued_bytes) +
                     "). You may want to adjust the 'max_bytes' parameter in the NAP policy"
                     " to a higher value, or '0' for unlimited.\n");
             }
@@ -657,7 +657,7 @@ bool TcpSession::check_reassembly_queue_thresholds(TcpSegmentDescriptor& tsd, Tc
                 // FIXIT-M - only alert once per threshold exceeded event
                 tel.set_tcp_event(EVENT_MAX_QUEUED_SEGS_EXCEEDED);
                 listener->normalizer.log_drop_reason(tsd, inline_mode, "stream",
-                    "Stream: Flow exceeded the configured max segment threshold (" + std::to_string(tcp_config->max_queued_segs) +
+                    "stream_tcp: Flow exceeded the configured max segment threshold (" + std::to_string(tcp_config->max_queued_segs) +
                     "). You may want to adjust the 'max_segments' parameter in the NAP policy"
                     " to a higher value, or '0' for unlimited.\n");
             }
@@ -1344,7 +1344,7 @@ StreamSplitter* TcpSession::get_splitter(bool to_server)
 void TcpSession::start_proxy()
 {
     if ( PacketTracer::is_active() )
-        PacketTracer::log("Stream TCP normalization policy set to Proxy mode. Normalizations will be skipped\n");
+        PacketTracer::log("stream_tcp: TCP normalization policy set to Proxy mode. Normalizations will be skipped\n");
 
     client.normalizer.init(StreamPolicy::OS_PROXY, this, &client, &server);
     server.normalizer.init(StreamPolicy::OS_PROXY, this, &server, &client);

diff --git a/src/stream/tcp/tcp_state_listen.cc b/src/stream/tcp/tcp_state_listen.cc
index ba341bcc4736ad4e5c49f14747eebcfb99f590ab..f9b00bd22f2d5462bd22221bd89394389e46ed21 100644 (file)
--- a/src/stream/tcp/tcp_state_listen.cc
+++ b/src/stream/tcp/tcp_state_listen.cc
@@ -72,7 +72,7 @@ bool TcpStateListen::data_seg_sent(TcpSegmentDescriptor& tsd, TcpStreamTracker&
         flow->set_session_flags(SSNFLAG_MIDSTREAM);
 
         if ( PacketTracer::is_active() )
-            PacketTracer::log("Stream TCP did not see the complete 3-Way Handshake. "
+            PacketTracer::log("stream_tcp: TCP did not see the complete 3-Way Handshake. "
             "Not all normalizations will be in effect\n");
 
         DataBus::publish(Stream::get_pub_id(), StreamEventIds::TCP_MIDSTREAM, tsd.get_pkt());

diff --git a/src/stream/tcp/tcp_state_none.cc b/src/stream/tcp/tcp_state_none.cc
index d106d74fdbddd5f96c477b00b85b788ece1c49c9..aa10e4421b2fe22e4f17bb8dbc46d0d24a169eea 100644 (file)
--- a/src/stream/tcp/tcp_state_none.cc
+++ b/src/stream/tcp/tcp_state_none.cc
@@ -72,7 +72,7 @@ bool TcpStateNone::data_seg_sent(TcpSegmentDescriptor& tsd, TcpStreamTracker& tr
         flow->set_session_flags(SSNFLAG_MIDSTREAM);
 
         if ( PacketTracer::is_active() )
-            PacketTracer::log("Stream TCP did not see the complete 3-Way Handshake. "
+            PacketTracer::log("stream_tcp: TCP did not see the complete 3-Way Handshake. "
             "Not all normalizations will be in effect\n");
 
         DataBus::publish(Stream::get_pub_id(), StreamEventIds::TCP_MIDSTREAM, tsd.get_pkt());

diff --git a/src/stream/tcp/tcp_stream_tracker.cc b/src/stream/tcp/tcp_stream_tracker.cc
index 54c5d000de465041641b638b97ea38c7443ebbb5..1f5f4b66b72a25dc7a01ee72f0e48bc64b1016c8 100644 (file)
--- a/src/stream/tcp/tcp_stream_tracker.cc
+++ b/src/stream/tcp/tcp_stream_tracker.cc
@@ -448,7 +448,7 @@ void TcpStreamTracker::fallback()
 #endif
 
     if (PacketTracer::is_active())
-        PacketTracer::log("Stream: %s tracker fallback to the Atom splitter.\n",
+        PacketTracer::log("stream_tcp: %s tracker fallback to the Atom splitter.\n",
             client_tracker ? "client" : "server");
 
     set_splitter(new AtomSplitter(!client_tracker));
@@ -850,13 +850,13 @@ int32_t TcpStreamTracker::kickstart_asymmetric_flow(const TcpSegmentDescriptor&
     {
         set_tcp_state(TcpStreamTracker::TCP_ESTABLISHED);
         if (PacketTracer::is_active())
-            PacketTracer::log("Stream: Kickstart of midstream asymmetric flow! Seglist queue space: %u\n",
+            PacketTracer::log("stream_tcp: Kickstart of midstream asymmetric flow! Seglist queue space: %u\n",
                 space_left );
     }
     else
     {
         if (PacketTracer::is_active())
-            PacketTracer::log("Stream: Kickstart of asymmetric flow! Seglist queue space: %u\n",
+            PacketTracer::log("stream_tcp: Kickstart of asymmetric flow! Seglist queue space: %u\n",
                 space_left );
     }