From: Davis McPherson -X (davmcphe - XORIANT CORPORATION at Cisco) Date: Tue, 29 Oct 2024 18:11:29 +0000 (+0000) Subject: Pull request #4492: stream_tcp: when queue limit thresholds are exceeded in IDS mode... X-Git-Tag: 3.5.1.0~5 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=01bd4c251e8fd38a8d9ce9f74e9ec4e39ff28e90;p=thirdparty%2Fsnort3.git Pull request #4492: 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 Merge in SNORT/snort3 from ~DAVMCPHE/snort3:ids_asymmetric_tweaks to master Squashed commit of the following: commit 3ea41ca77b1fc9f6f1bb775eb01ed784fdc71ad9 Author: davis mcpherson 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 11bb79c81..67348e845 100644 --- 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 dbef615d8..98338572f 100644 --- 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 62904fc9d..348790096 100644 --- 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 b8d782593..54518aef4 100644 --- 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 6ed2bd5cf..3795f5c90 100644 --- 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 20d97e29d..a5106c8ad 100644 --- 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 df1a79d7d..5fc87f9cc 100644 --- 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 09ed78728..134989161 100644 --- 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 f730fe3e3..7e720d0d9 100644 --- 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 ba341bcc4..f9b00bd22 100644 --- 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 d106d74fd..aa10e4421 100644 --- 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 54c5d000d..1f5f4b66b 100644 --- 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 ); }