From: Tom Peters (thopeter) Date: Fri, 20 Apr 2018 15:04:47 +0000 (-0400) Subject: Merge pull request #1195 in SNORT/snort3 from debug_specific_dir to master X-Git-Tag: 3.0.0-245~38 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=182e5a940c36d1964e6fdeca506d48eff384ac16;p=thirdparty%2Fsnort3.git Merge pull request #1195 in SNORT/snort3 from debug_specific_dir to master Squashed commit of the following: commit b7b5a6b70aaaa42cbaece10e785d2887d8ae2cd3 Author: Nihal Desai Date: Wed Apr 18 10:47:53 2018 -0400 debug: Remove debug messages from stream --- diff --git a/src/flow/flow_control.cc b/src/flow/flow_control.cc index 6971e82b9..42753d8df 100644 --- a/src/flow/flow_control.cc +++ b/src/flow/flow_control.cc @@ -24,7 +24,6 @@ #include "detection/detection_engine.h" #include "main/snort_config.h" -#include "main/snort_debug.h" #include "managers/inspector_manager.h" #include "memory/memory_cap.h" #include "packet_io/active.h" @@ -499,10 +498,6 @@ bool FlowControl::expected_flow(Flow* flow, Packet* p) if ( ignore ) { - DebugFormat(DEBUG_STREAM_STATE, - "Stream: Ignoring packet from %s. Marking flow marked as ignore.\n", - (p->packet_flags & PKT_FROM_CLIENT) ? "sender" : "responder"); - flow->ssn_state.ignore_direction = ignore; DetectionEngine::disable_all(p); } diff --git a/src/main/snort_debug.h b/src/main/snort_debug.h index ddd214496..a25c16425 100644 --- a/src/main/snort_debug.h +++ b/src/main/snort_debug.h @@ -52,10 +52,7 @@ // this env var uses the upper 32 bits of the flags: #define DEBUG_PLUGIN "SNORT_PP_DEBUG" -#define DEBUG_FRAG 0x0000000100000000LL #define DEBUG_STREAM 0x0000000200000000LL -#define DEBUG_STREAM_STATE 0x0000000400000000LL -#define DEBUG_STREAM_PAF 0x0000000800000000LL #define DEBUG_CODEC 0x0001000000000000LL #define DEBUG_IPS_ACTION 0x0004000000000000LL diff --git a/src/stream/base/stream_ha.cc b/src/stream/base/stream_ha.cc index c0a519fdc..f5f69c19b 100644 --- a/src/stream/base/stream_ha.cc +++ b/src/stream/base/stream_ha.cc @@ -27,7 +27,6 @@ #include "binder/binder.h" #include "flow/flow_key.h" -#include "main/snort_debug.h" #include "managers/inspector_manager.h" #include "stream/stream.h" @@ -91,8 +90,6 @@ static bool is_client_lower(Flow* flow) bool StreamHAClient::consume(Flow*& flow, FlowKey* key, HAMessage* msg) { - DebugMessage(DEBUG_HA,"StreamHAClient::consume()\n"); - assert(key); assert(msg); @@ -145,7 +142,6 @@ bool StreamHAClient::consume(Flow*& flow, FlowKey* key, HAMessage* msg) bool StreamHAClient::produce(Flow* flow, HAMessage* msg) { - DebugMessage(DEBUG_HA,"StreamHAClient::produce()\n"); assert(flow); assert(msg); @@ -229,8 +225,6 @@ static void update_flags(Flow* flow) bool StreamHAClient::is_update_required(Flow* flow) { - DebugMessage(DEBUG_HA,"StreamHAClient::update_required()\n"); - assert(flow); assert(flow->ha_state); @@ -253,14 +247,11 @@ bool StreamHAClient::is_update_required(Flow* flow) bool StreamHAClient::is_delete_required(Flow*) { - DebugMessage(DEBUG_HA,"StreamHAClient::update_required()\n"); return true; } ProtocolHA::ProtocolHA(PktType protocol) { - DebugFormat(DEBUG_HA,"ProtocolHA::ProtocolHA(): protocol: %d\n",(int)protocol); - if ( proto_map == nullptr ) proto_map = new ProtocolMap; diff --git a/src/stream/icmp/icmp_session.cc b/src/stream/icmp/icmp_session.cc index b2907267f..43ecb379e 100644 --- a/src/stream/icmp/icmp_session.cc +++ b/src/stream/icmp/icmp_session.cc @@ -164,8 +164,6 @@ static int ProcessIcmpUnreach(Packet* p) if (ssn) { /* Mark this session as dead. */ - DebugMessage(DEBUG_STREAM_STATE, - "Marking session as dead, per ICMP Unreachable!\n"); ssn->ssn_state.session_flags |= SSNFLAG_DROP_CLIENT; ssn->ssn_state.session_flags |= SSNFLAG_DROP_SERVER; ssn->session_state |= STREAM_STATE_UNREACH; diff --git a/src/stream/ip/ip_defrag.cc b/src/stream/ip/ip_defrag.cc index c18a687c3..2cdfdcf6e 100644 --- a/src/stream/ip/ip_defrag.cc +++ b/src/stream/ip/ip_defrag.cc @@ -648,8 +648,6 @@ static void FragRebuild(FragTracker* ft, Packet* p) trace_log(stream_ip, "[^^] Walking fraglist:\n"); - DebugMessage(DEBUG_FRAG, - "[^^] Walking fraglist:\n"); } /* diff --git a/src/stream/ip/ip_session.cc b/src/stream/ip/ip_session.cc index 44792435f..9a80d5ab7 100644 --- a/src/stream/ip/ip_session.cc +++ b/src/stream/ip/ip_session.cc @@ -87,25 +87,16 @@ static inline void UpdateSession(Packet* p, Flow* lws) { if ( p->is_from_client() ) { - DebugMessage(DEBUG_STREAM_STATE, - "Stream: Updating on packet from client\n"); - lws->ssn_state.session_flags |= SSNFLAG_SEEN_CLIENT; } else { - DebugMessage(DEBUG_STREAM_STATE, - "Stream: Updating on packet from server\n"); - lws->ssn_state.session_flags |= SSNFLAG_SEEN_SERVER; } if ( (lws->ssn_state.session_flags & SSNFLAG_SEEN_CLIENT) && (lws->ssn_state.session_flags & SSNFLAG_SEEN_SERVER) ) { - DebugMessage(DEBUG_STREAM_STATE, - "Stream: session established!\n"); - lws->ssn_state.session_flags |= SSNFLAG_ESTABLISHED; lws->set_ttl(p, false); @@ -142,8 +133,6 @@ void IpSession::clear() bool IpSession::setup(Packet* p) { - DebugMessage(DEBUG_STREAM, "Stream IP session created!\n"); - SESSION_STATS_ADD(ip_stats); memset(&tracker, 0, sizeof(tracker)); diff --git a/src/stream/libtcp/tcp_segment_descriptor.cc b/src/stream/libtcp/tcp_segment_descriptor.cc index 2aa2c9c0e..88c5fcc23 100644 --- a/src/stream/libtcp/tcp_segment_descriptor.cc +++ b/src/stream/libtcp/tcp_segment_descriptor.cc @@ -26,7 +26,6 @@ #include "tcp_segment_descriptor.h" #include "detection/rules.h" -#include "main/snort_debug.h" #include "protocols/tcp_options.h" #include "stream/tcp/tcp_defs.h" @@ -55,30 +54,23 @@ TcpSegmentDescriptor::TcpSegmentDescriptor(Flow* flow, Packet* pkt, TcpEventLogg uint32_t TcpSegmentDescriptor::init_mss(uint16_t* value) { - DebugMessage(DEBUG_STREAM_STATE, "Getting MSS...\n"); - tcp::TcpOptIterator iter(tcph, pkt); for ( const tcp::TcpOption& opt : iter ) { if ( opt.code == tcp::TcpOptCode::MAXSEG ) { *value = extract_16bits(opt.data); - DebugFormat(DEBUG_STREAM_STATE, "Found MSS %hu\n", *value); return TF_MSS; } } *value = 0; - DebugMessage(DEBUG_STREAM_STATE, "No MSS...\n"); - return TF_NONE; } uint32_t TcpSegmentDescriptor::init_wscale(uint16_t* value) { - DebugMessage(DEBUG_STREAM_STATE, "Getting wscale...\n"); - tcp::TcpOptIterator iter(tcph, pkt); for (const tcp::TcpOption& opt : iter) @@ -86,7 +78,6 @@ uint32_t TcpSegmentDescriptor::init_wscale(uint16_t* value) if (opt.code == tcp::TcpOptCode::WSCALE) { *value = (uint16_t)opt.data[0]; - DebugFormat(DEBUG_STREAM_STATE, "Found wscale %d\n", *value); // If scale specified in option is larger than 14, use 14 because of limitation // in the math of shifting a 32bit value (max scaled window is 2^30th). @@ -99,7 +90,6 @@ uint32_t TcpSegmentDescriptor::init_wscale(uint16_t* value) } *value = 0; - DebugMessage(DEBUG_STREAM_STATE, "No wscale...\n"); return TF_NONE; } @@ -108,8 +98,6 @@ bool TcpSegmentDescriptor::has_wscale() { uint16_t wscale; - DebugMessage(DEBUG_STREAM_STATE, "Checking for wscale...\n"); - if ( !(pkt->ptrs.decode_flags & DECODE_WSCALE) ) return false; diff --git a/src/stream/libtcp/tcp_state_handler.cc b/src/stream/libtcp/tcp_state_handler.cc index a89e9ecfb..92b8adcd7 100644 --- a/src/stream/libtcp/tcp_state_handler.cc +++ b/src/stream/libtcp/tcp_state_handler.cc @@ -27,7 +27,6 @@ #include -#include "main/snort_debug.h" #include "tcp_segment_descriptor.h" #include "tcp_state_machine.h" diff --git a/src/stream/libtcp/tcp_stream_session.cc b/src/stream/libtcp/tcp_stream_session.cc index df9bc4099..17f6d7da9 100644 --- a/src/stream/libtcp/tcp_stream_session.cc +++ b/src/stream/libtcp/tcp_stream_session.cc @@ -26,7 +26,6 @@ #include "tcp_stream_session.h" #include "log/messages.h" -#include "main/snort_debug.h" #include "stream/tcp/tcp_ha.h" using namespace snort; @@ -91,8 +90,6 @@ void TcpStreamSession::update_session_on_ack() void TcpStreamSession::update_session_on_server_packet(TcpSegmentDescriptor& tsd) { - DebugMessage(DEBUG_STREAM_STATE, "Stream: Updating on packet from server\n"); - flow->set_session_flags(SSNFLAG_SEEN_SERVER); talker = &server; listener = &client; @@ -120,8 +117,6 @@ void TcpStreamSession::update_session_on_server_packet(TcpSegmentDescriptor& tsd void TcpStreamSession::update_session_on_client_packet(TcpSegmentDescriptor& tsd) { - DebugMessage(DEBUG_STREAM_STATE, "Stream: Updating on packet from client\n"); - /* if we got here we had to see the SYN already... */ flow->set_session_flags(SSNFLAG_SEEN_CLIENT); talker = &client; diff --git a/src/stream/libtcp/tcp_stream_tracker.cc b/src/stream/libtcp/tcp_stream_tracker.cc index 47ddc23a0..36831c545 100644 --- a/src/stream/libtcp/tcp_stream_tracker.cc +++ b/src/stream/libtcp/tcp_stream_tracker.cc @@ -290,8 +290,6 @@ void TcpStreamTracker::init_on_synack_sent(TcpSegmentDescriptor& tsd) { Profile profile(s5TcpNewSessPerfStats); - DebugMessage(DEBUG_STREAM_STATE, "Creating new session tracker on SYN_ACK!\n"); - tsd.get_flow()->set_session_flags(SSNFLAG_SEEN_SERVER); if (tsd.get_tcph()->are_flags_set(TH_CWR | TH_ECE)) tsd.get_flow()->set_session_flags(SSNFLAG_ECN_SERVER_REPLY); @@ -528,9 +526,6 @@ bool TcpStreamTracker::update_on_3whs_ack(TcpSegmentDescriptor& tsd) } else { - DebugFormat(DEBUG_STREAM_STATE, - "Pkt Ack is Out of Bounds (%X, %X, %X) = (snd_una, snd_nxt, cur)\n", - snd_una, snd_nxt, tsd.get_seg_ack()); inc_tcp_discards(); normalizer.trim_win_payload(tsd); good_ack = false; @@ -548,14 +543,12 @@ bool TcpStreamTracker::update_on_rst_recv(TcpSegmentDescriptor& tsd) { Flow* flow = tsd.get_flow(); - DebugMessage(DEBUG_STREAM_STATE, "Received Valid RST, bailing\n"); flow->set_session_flags(SSNFLAG_RESET); if ( normalizer.is_tcp_ips_enabled() ) tcp_state = TcpStreamTracker::TCP_CLOSED; } else { - DebugMessage(DEBUG_STREAM_STATE, "Received RST with bad sequence number, bailing\n"); inc_tcp_discards(); normalizer.packet_dropper(tsd, NORM_TCP_BLOCK); good_rst = false; @@ -586,7 +579,6 @@ bool TcpStreamTracker::update_on_fin_recv(TcpSegmentDescriptor& tsd) { if ( SEQ_LT(tsd.get_end_seq(), r_win_base) ) { - DebugMessage(DEBUG_STREAM_STATE, "FIN inside r_win_base, bailing\n"); return false; } @@ -623,11 +615,6 @@ bool TcpStreamTracker::is_segment_seq_valid(TcpSegmentDescriptor& tsd) int right_ok; uint32_t left_seq; - DebugFormat(DEBUG_STREAM_STATE, - "Checking end_seq (%X) > r_win_base (%X) && seq (%X) < r_nxt_ack(%X)\n", - tsd.get_end_seq(), r_win_base, tsd.get_seg_seq(), - r_nxt_ack + normalizer.get_stream_window(tsd)); - if ( SEQ_LT(r_nxt_ack, r_win_base) ) left_seq = r_nxt_ack; else @@ -644,17 +631,15 @@ bool TcpStreamTracker::is_segment_seq_valid(TcpSegmentDescriptor& tsd) if ( SEQ_LEQ(tsd.get_seg_seq(), r_win_base + win) ) { - DebugMessage(DEBUG_STREAM_STATE, "seq is within window!\n"); + return true; } else { - DebugMessage(DEBUG_STREAM_STATE, "seq is past the end of the window!\n"); valid_seq = false; } } else { - DebugMessage(DEBUG_STREAM_STATE, "end_seq is before win_base\n"); valid_seq = false; } diff --git a/src/stream/paf.cc b/src/stream/paf.cc index 315491309..9847742e1 100644 --- a/src/stream/paf.cc +++ b/src/stream/paf.cc @@ -25,7 +25,6 @@ #include "paf.h" -#include "main/snort_debug.h" #include "protocols/packet.h" using namespace snort; @@ -64,10 +63,6 @@ static uint32_t paf_flush (PAF_State* ps, PafAux& px, uint32_t* flags) uint32_t at = 0; *flags &= ~(PKT_PDU_HEAD | PKT_PDU_TAIL); - DebugFormat(DEBUG_STREAM_PAF, - "%s: type=%d, fpt=%u, len=%u, tot=%u\n", - __func__, px.ft, ps->fpt, px.len, ps->tot); - switch ( px.ft ) { case FT_NOP: @@ -161,10 +156,6 @@ static inline bool paf_eval ( StreamSplitter* ss, PAF_State* ps, PafAux& px, Flow* ssn, uint32_t flags, const uint8_t* data, uint32_t len) { - DebugFormat(DEBUG_STREAM_PAF, - "%s: paf=%d, idx=%u, len=%u, fpt=%u\n", - __func__, ps->paf, px.idx, px.len, ps->fpt); - uint16_t fuzz = 0; // FIXIT-L PAF add a little zippedy-do-dah switch ( ps->paf ) @@ -262,10 +253,6 @@ int32_t paf_check ( const uint8_t* data, uint32_t len, uint32_t total, uint32_t seq, uint32_t* flags) { - DebugFormat(DEBUG_STREAM_PAF, - "%s: len=%u, amt=%u, seq=%u, cur=%u, pos=%u, fpt=%u, tot=%u, paf=%d\n", - __func__, len, total, seq, ps->seq, ps->pos, ps->fpt, ps->tot, ps->paf); - PafAux px; if ( !paf_initialized(ps) ) diff --git a/src/stream/stream.cc b/src/stream/stream.cc index 184896649..1e061ace1 100644 --- a/src/stream/stream.cc +++ b/src/stream/stream.cc @@ -32,7 +32,6 @@ #include "flow/prune_stats.h" #include "main/snort.h" #include "main/snort_config.h" -#include "main/snort_debug.h" #include "packet_io/active.h" #include "protocols/vlan.h" #include "stream/base/stream_module.h" @@ -616,10 +615,6 @@ bool Stream::blocked_flow(Flow* flow, Packet* p) ((p->is_from_client()) && (flow->ssn_state.session_flags & SSNFLAG_DROP_CLIENT)) ) { - DebugFormat(DEBUG_STREAM_STATE, - "Blocking %s packet as session was blocked\n", - p->is_from_server() ? "server" : "client"); - DetectionEngine::disable_content(p); Active::drop_packet(p); active_response(p, flow); @@ -635,10 +630,6 @@ bool Stream::ignored_flow(Flow* flow, Packet* p) ((p->is_from_client()) && (flow->ssn_state.ignore_direction & SSN_DIR_FROM_SERVER)) ) { - DebugFormat(DEBUG_STREAM_STATE, - "Stream Ignoring packet from %s. Session marked as ignore\n", - p->is_from_client() ? "sender" : "responder"); - DetectionEngine::disable_all(p); return true; } @@ -665,7 +656,6 @@ bool Stream::expired_flow(Flow* flow, Packet* p) if ( (flow->session_state & STREAM_STATE_TIMEDOUT) || StreamExpire(p, flow) ) { - DebugMessage(DEBUG_STREAM, "Stream IP session timeout!\n"); flow->ssn_state.session_flags |= SSNFLAG_TIMEDOUT; return true; } diff --git a/src/stream/tcp/segment_overlap_editor.cc b/src/stream/tcp/segment_overlap_editor.cc index 43db0bc74..71902e9e4 100644 --- a/src/stream/tcp/segment_overlap_editor.cc +++ b/src/stream/tcp/segment_overlap_editor.cc @@ -142,9 +142,6 @@ int SegmentOverlapEditor::eval_right(TcpReassemblerState& trs) assert(SEQ_LEQ(trs.sos.seq, trs.sos.right->seq)); trs.sos.overlap = ( int )( trs.sos.seq_end - trs.sos.right->seq ); - DebugFormat(DEBUG_STREAM_STATE, "right overlap(%d): len: %d right->seq: 0x%X seq: 0x%X\n", - trs.sos.overlap, trs.sos.len, trs.sos.right->seq, trs.sos.seq); - // Treat sequence number overlap as a retransmission, only check right side since // left side happens rarely trs.sos.session->retransmit_handle(trs.sos.tsd->get_pkt()); @@ -193,10 +190,6 @@ int SegmentOverlapEditor::eval_right(TcpReassemblerState& trs) void SegmentOverlapEditor::drop_old_segment(TcpReassemblerState& trs) { - DebugFormat(DEBUG_STREAM_STATE, - "full right overlap, dropping old segment at seq %u, size %hu\n", - trs.sos.right->seq, trs.sos.right->payload_size); - TcpSegmentNode* drop_seg = trs.sos.right; trs.sos.right = trs.sos.right->next; delete_reassembly_segment(trs, drop_seg); @@ -204,8 +197,6 @@ void SegmentOverlapEditor::drop_old_segment(TcpReassemblerState& trs) int SegmentOverlapEditor::left_overlap_keep_first(TcpReassemblerState& trs) { - DebugFormat(DEBUG_STREAM_STATE, "left overlap %d\n", trs.sos.overlap); - // NOTE that overlap will always be less than left->size since // seq is always greater than left->seq assert(SEQ_GT(trs.sos.seq, trs.sos.left->seq)); @@ -221,8 +212,6 @@ int SegmentOverlapEditor::left_overlap_keep_first(TcpReassemblerState& trs) tcpStats.overlaps++; trs.sos.overlap_count++; - DebugMessage(DEBUG_STREAM_STATE, "left overlap, honoring old data\n"); - if ( SEQ_GT(trs.sos.left->seq + trs.sos.left->payload_size, trs.sos.seq_end) ) { if (trs.sos.tcp_ips_data == NORM_MODE_ON) @@ -257,7 +246,6 @@ int SegmentOverlapEditor::left_overlap_keep_first(TcpReassemblerState& trs) int SegmentOverlapEditor::left_overlap_trim_first(TcpReassemblerState& trs) { - DebugFormat(DEBUG_STREAM_STATE, "left overlap %d\n", trs.sos.overlap); assert(SEQ_GT(trs.sos.seq, trs.sos.left->seq)); trs.sos.len = trs.sos.tsd->get_seg_len(); @@ -271,7 +259,6 @@ int SegmentOverlapEditor::left_overlap_trim_first(TcpReassemblerState& trs) if ( SEQ_GEQ(trs.sos.left->seq + trs.sos.left->payload_size, trs.sos.seq + trs.sos.len) ) { // existing packet overlaps new on both sides. Drop the new data. - DebugMessage(DEBUG_STREAM_STATE, "left overlap, honoring old data\n"); trs.sos.seq += trs.sos.len; } else @@ -279,7 +266,6 @@ int SegmentOverlapEditor::left_overlap_trim_first(TcpReassemblerState& trs) /* Otherwise, trim the old data accordingly */ trs.sos.left->payload_size -= ( int16_t )trs.sos.overlap; trs.sos.seg_bytes_logical -= trs.sos.overlap; - DebugMessage(DEBUG_STREAM_STATE, "left overlap, honoring new data\n"); } } @@ -288,7 +274,6 @@ int SegmentOverlapEditor::left_overlap_trim_first(TcpReassemblerState& trs) int SegmentOverlapEditor::left_overlap_keep_last(TcpReassemblerState& trs) { - DebugFormat(DEBUG_STREAM_STATE, "left overlap %d\n", trs.sos.overlap); assert(SEQ_GT(trs.sos.seq, trs.sos.left->seq)); trs.sos.len = trs.sos.tsd->get_seg_len(); @@ -333,7 +318,6 @@ int SegmentOverlapEditor::left_overlap_keep_last(TcpReassemblerState& trs) void SegmentOverlapEditor::right_overlap_truncate_existing(TcpReassemblerState& trs) { - DebugMessage(DEBUG_STREAM_STATE, "Got partial right overlap\n"); if ( SEQ_EQ(trs.sos.right->seq, trs.sos.seq) && ( trs.sos.reassembly_policy != ReassemblyPolicy::OS_LAST ) ) { trs.sos.slide = ( trs.sos.right->seq + trs.sos.right->payload_size - trs.sos.seq ); @@ -370,8 +354,6 @@ void SegmentOverlapEditor::right_overlap_truncate_new(TcpReassemblerState& trs) // REASSEMBLY_POLICY_VISTA: int SegmentOverlapEditor::full_right_overlap_truncate_new(TcpReassemblerState& trs) { - DebugMessage(DEBUG_STREAM_STATE, "Got full right overlap, truncating new\n"); - if ( trs.sos.tcp_ips_data == NORM_MODE_ON ) { unsigned offset = trs.sos.right->seq - trs.sos.tsd->get_seg_seq(); diff --git a/src/stream/tcp/tcp_event_logger.cc b/src/stream/tcp/tcp_event_logger.cc index 72610762d..87c546eb9 100644 --- a/src/stream/tcp/tcp_event_logger.cc +++ b/src/stream/tcp/tcp_event_logger.cc @@ -94,7 +94,6 @@ void TcpEventLogger::log_internal_event(uint32_t eventSid) { tcpStats.internalEvents++; snort::DetectionEngine::queue_event(GENERATOR_INTERNAL, eventSid); - DebugFormat(DEBUG_STREAM, "Stream raised internal event %u\n", eventSid); } } diff --git a/src/stream/tcp/tcp_ha.cc b/src/stream/tcp/tcp_ha.cc index 75238afda..9ee7cdf5c 100644 --- a/src/stream/tcp/tcp_ha.cc +++ b/src/stream/tcp/tcp_ha.cc @@ -23,7 +23,6 @@ #include "tcp_ha.h" -#include "main/snort_debug.h" #include "stream/stream.h" #include "tcp_session.h" @@ -48,7 +47,6 @@ Flow* TcpHA::create_session(FlowKey* key) void TcpHA::deactivate_session(Flow* flow) { - DebugMessage(DEBUG_HA,"TcpHA::deactivate_session)\n"); assert( flow ); if ( flow->session ) ((TcpSession*)(flow->session))->clear_session(true, true, false); diff --git a/src/stream/tcp/tcp_normalizer.cc b/src/stream/tcp/tcp_normalizer.cc index 40fb2d83c..a90676eae 100644 --- a/src/stream/tcp/tcp_normalizer.cc +++ b/src/stream/tcp/tcp_normalizer.cc @@ -28,7 +28,6 @@ #include "stream/libtcp/tcp_stream_session.h" #include "stream/libtcp/tcp_stream_tracker.h" -#include "main/snort_debug.h" #include "packet_io/active.h" using namespace snort; @@ -189,8 +188,6 @@ uint32_t TcpNormalizer::get_stream_window( uint32_t TcpNormalizer::get_tcp_timestamp( TcpNormalizerState& tns, TcpSegmentDescriptor& tsd, bool strip) { - DebugMessage(DEBUG_STREAM_STATE, "Getting timestamp...\n"); - tcp::TcpOptIterator iter(tsd.get_tcph(), tsd.get_pkt() ); // using const because non-const is not supported @@ -206,45 +203,30 @@ uint32_t TcpNormalizer::get_tcp_timestamp( if (!stripped) { tsd.set_ts(extract_32bits(opt.data) ); - DebugFormat(DEBUG_STREAM_STATE, "Found timestamp %u\n", tsd.get_ts()); return TF_TSTAMP; } } } tsd.set_ts(0); - DebugMessage(DEBUG_STREAM_STATE, "No timestamp...\n"); - return TF_NONE; } bool TcpNormalizer::validate_rst_seq_geq( TcpNormalizerState& tns, TcpSegmentDescriptor& tsd) { - DebugFormat(DEBUG_STREAM_STATE, - "Checking end_seq (%X) > r_win_base (%X) && seq (%X) < r_nxt_ack(%X)\n", - tsd.get_end_seq(), tns.tracker->r_win_base, tsd.get_seg_seq(), tns.tracker->r_nxt_ack + - get_stream_window(tns, tsd)); - // FIXIT-H check for r_win_base == 0 is hack for uninitialized r_win_base, fix this if ( ( tns.tracker->r_nxt_ack == 0 ) || SEQ_GEQ(tsd.get_seg_seq(), tns.tracker->r_nxt_ack) ) { - DebugMessage(DEBUG_STREAM_STATE, "rst is valid seq (>= next seq)!\n"); return true; } - DebugMessage(DEBUG_STREAM_STATE, "rst is not valid seq (>= next seq)!\n"); return false; } bool TcpNormalizer::validate_rst_end_seq_geq( TcpNormalizerState& tns, TcpSegmentDescriptor& tsd) { - DebugFormat(DEBUG_STREAM_STATE, - "Checking end_seq (%X) > r_win_base (%X) && seq (%X) < r_nxt_ack(%X)\n", - tsd.get_end_seq(), tns.tracker->r_win_base, tsd.get_seg_seq(), tns.tracker->r_nxt_ack + - get_stream_window(tns, tsd)); - // FIXIT-H check for r_win_base == 0 is hack for uninitialized r_win_base, fix this if ( tns.tracker->r_win_base == 0 ) return true; @@ -254,31 +236,22 @@ bool TcpNormalizer::validate_rst_end_seq_geq( // reset must be admitted when window closed if (SEQ_LEQ(tsd.get_seg_seq(), tns.tracker->r_win_base + get_stream_window(tns, tsd))) { - DebugMessage(DEBUG_STREAM_STATE, "rst is valid seq (within window)!\n"); return true; } } - DebugMessage(DEBUG_STREAM_STATE, "rst is not valid seq (within window)!\n"); return false; } bool TcpNormalizer::validate_rst_seq_eq( TcpNormalizerState& tns, TcpSegmentDescriptor& tsd) { - DebugFormat(DEBUG_STREAM_STATE, - "Checking end_seq (%X) > r_win_base (%X) && seq (%X) < r_nxt_ack(%X)\n", - tsd.get_end_seq(), tns.tracker->r_win_base, tsd.get_seg_seq(), - tns.tracker->r_nxt_ack + get_stream_window(tns, tsd)); - // FIXIT-H check for r_nxt_ack == 0 is hack for uninitialized r_nxt_ack, fix this if ( ( tns.tracker->r_nxt_ack == 0 ) || SEQ_EQ(tsd.get_seg_seq(), tns.tracker->r_nxt_ack) ) { - DebugMessage(DEBUG_STREAM_STATE, "rst is valid seq (next seq)!\n"); return true; } - DebugMessage(DEBUG_STREAM_STATE, "rst is not valid seq (next seq)!\n"); return false; } @@ -297,7 +270,6 @@ int TcpNormalizer::validate_paws_timestamp( { if ( ( (int)( ( tsd.get_ts() - tns.peer_tracker->get_ts_last() ) + tns.paws_ts_fudge ) ) < 0 ) { - DebugMessage(DEBUG_STREAM_STATE, "Packet outside PAWS window, dropping\n"); /* bail, we've got a packet outside the PAWS window! */ //inc_tcp_discards(); tns.session->tel.set_tcp_event(EVENT_BAD_TIMESTAMP); @@ -309,9 +281,6 @@ int TcpNormalizer::validate_paws_timestamp( PAWS_24DAYS ) ) { /* this packet is from way too far into the future */ - DebugFormat(DEBUG_STREAM_STATE, - "packet PAWS timestamp way too far ahead of last packet %ld %u...\n", - tsd.get_pkt()->pkth->ts.tv_sec, tns.peer_tracker->get_ts_last_packet() ); //inc_tcp_discards(); tns.session->tel.set_tcp_event(EVENT_BAD_TIMESTAMP); packet_dropper(tns, tsd, NORM_TCP_OPT); @@ -319,7 +288,6 @@ int TcpNormalizer::validate_paws_timestamp( } else { - DebugMessage(DEBUG_STREAM_STATE, "packet PAWS ok...\n"); return ACTION_NOTHING; } } @@ -348,8 +316,6 @@ int TcpNormalizer::validate_paws( // we've got a packet with no timestamp, but 3whs indicated talker was doing // timestamps. This breaks protocol, however, some servers still ack the packet // with the missing timestamp. Log an alert, but continue to process the packet - DebugMessage(DEBUG_STREAM_STATE, - "packet no timestamp, had one earlier from this side...ok for now...\n"); tns.session->tel.set_tcp_event(EVENT_NO_TIMESTAMP); /* Ignore the timestamp for this first packet, next one will checked. */ @@ -381,7 +347,6 @@ int TcpNormalizer::handle_paws_no_timestamps( if ( ( tns.paws_drop_zero_ts && ( tsd.get_ts() == 0 ) ) && ( tns.tracker->get_tf_flags() & TF_TSTAMP ) ) { - DebugMessage(DEBUG_STREAM_STATE, "Packet with 0 timestamp, dropping\n"); tns.session->tel.set_tcp_event(EVENT_BAD_TIMESTAMP); return ACTION_BAD_PKT; } @@ -408,7 +373,6 @@ int TcpNormalizer::handle_paws( if ((tns.peer_tracker->get_tf_flags() & TF_TSTAMP) && (tns.tracker->get_tf_flags() & TF_TSTAMP)) { - DebugMessage(DEBUG_STREAM_STATE, "Checking timestamps for PAWS\n"); return validate_paws(tns, tsd); } else if (tsd.get_tcph()->is_syn_only()) diff --git a/src/stream/tcp/tcp_normalizers.cc b/src/stream/tcp/tcp_normalizers.cc index f54158d5a..9be5a22c3 100644 --- a/src/stream/tcp/tcp_normalizers.cc +++ b/src/stream/tcp/tcp_normalizers.cc @@ -192,16 +192,12 @@ static inline int handle_repeated_syn_mswin( */ if (SEQ_EQ(tsd.get_seg_seq(), listener->r_nxt_ack)) { - DebugMessage(DEBUG_STREAM_STATE, - "Got syn on established windows ssn, which causes Reset, bailing\n"); session->flow->set_session_flags(SSNFLAG_RESET); talker->set_tcp_state(TcpStreamTracker::TCP_CLOSED); return ACTION_RST; } else { - DebugMessage(DEBUG_STREAM_STATE, - "Got syn on established windows ssn, not causing Reset, bailing\n"); inc_tcp_discards(); return ACTION_NOTHING; } @@ -213,16 +209,12 @@ static inline int handle_repeated_syn_bsd( /* If its not a retransmission of the actual SYN... RESET */ if (!SEQ_EQ(tsd.get_seg_seq(), talker->get_iss())) { - DebugMessage(DEBUG_STREAM_STATE, - "Got syn on established ssn, which causes Reset, bailing\n"); session->flow->set_session_flags(SSNFLAG_RESET); talker->set_tcp_state(TcpStreamTracker::TCP_CLOSED); return ACTION_RST; } else { - DebugMessage(DEBUG_STREAM_STATE, - "Got syn on established ssn, not causing Reset, bailing\n"); inc_tcp_discards(); return ACTION_NOTHING; } @@ -358,8 +350,6 @@ int TcpNormalizerMacOS::handle_repeated_syn( TcpNormalizerState&, TcpSegmentDescriptor&) { /* MACOS ignores a 2nd SYN, regardless of the sequence number. */ - DebugMessage(DEBUG_STREAM_STATE, - "Got syn on established macos ssn, not causing Reset, bailing\n"); inc_tcp_discards(); return ACTION_NOTHING; } @@ -448,21 +438,9 @@ int TcpNormalizerVista::handle_repeated_syn( } bool TcpNormalizerProxy::validate_rst( - TcpNormalizerState& tns, TcpSegmentDescriptor& tsd) -{ -#ifndef DEBUG_MSGS - UNUSED(tsd); -#endif - - // FIXIT-L will session->flow ever be null? convert to assert if possible - if ( tns.session->flow ) - { - DebugFormat(DEBUG_STREAM_STATE, - "Proxy Normalizer - Not Valid\n end_seq (%X) > r_win_base (%X) && seq (%X) < r_nxt_ack(%X)\n", - tsd.get_end_seq(), tns.tracker->r_win_base, tsd.get_seg_seq(), tns.tracker->r_nxt_ack + - get_stream_window(tns, tsd)); - } + TcpNormalizerState&, TcpSegmentDescriptor&) +{ return false; } diff --git a/src/stream/tcp/tcp_reassembler.cc b/src/stream/tcp/tcp_reassembler.cc index 69b24d1a9..2d4089b0c 100644 --- a/src/stream/tcp/tcp_reassembler.cc +++ b/src/stream/tcp/tcp_reassembler.cc @@ -121,9 +121,6 @@ int TcpReassembler::delete_reassembly_segment(TcpReassemblerState& trs, TcpSegme int ret; assert(tsn); - DebugFormat(DEBUG_STREAM_STATE, "Dropping segment at seq %X, len %d\n", tsn->seq, - tsn->payload_size); - if (tsn->prev) tsn->prev->next = tsn->next; else @@ -163,9 +160,6 @@ int TcpReassembler::trim_delete_reassembly_segment( if (delta < tsn->payload_size) { - DebugFormat(DEBUG_STREAM_STATE, "Left-Trimming segment at seq %X, len %d, delta %u\n", - tsn->seq, tsn->payload_size, delta); - tsn->seq = flush_seq; tsn->payload_size -= (uint16_t)delta; trs.sos.seg_bytes_logical -= delta; @@ -189,9 +183,6 @@ void TcpReassembler::queue_reassembly_segment( bool TcpReassembler::is_segment_fasttrack( TcpReassemblerState&, TcpSegmentNode* tail, TcpSegmentDescriptor& tsd) { - DebugFormat(DEBUG_STREAM_STATE, "Checking seq for fast track: %X > %X\n", - tsd.get_seg_seq(), tail->seq + tail->payload_size); - if ( SEQ_EQ(tsd.get_seg_seq(), tail->seq + tail->payload_size) ) return true; @@ -211,8 +202,6 @@ int TcpReassembler::add_reassembly_segment( //assert(newSize == 0); // zero size data because of trimming. Don't insert it - DebugFormat(DEBUG_STREAM_STATE, "zero size TCP data after left & right trimming " - "(len: %hd slide: %u trunc: %u)\n", len, slide, trunc_len); inc_tcp_discards(); trs.tracker->normalizer.trim_win_payload(tsd); @@ -238,10 +227,6 @@ int TcpReassembler::add_reassembly_segment( trs.sos.total_bytes_queued += tsn->payload_size; tsd.get_pkt()->packet_flags |= PKT_STREAM_INSERT; - DebugFormat(DEBUG_STREAM_STATE, - "added %hu bytes on segment list @ seq: 0x%X, total %u, %u segments queued\n", - tsn->payload_size, tsn->seq, trs.sos.seg_bytes_logical, - get_pending_segment_count(trs, 0)); #ifdef SEG_TEST CheckSegments(trs.tracker); @@ -261,11 +246,6 @@ int TcpReassembler::dup_reassembly_segment( queue_reassembly_segment(trs, left, tsn); - DebugFormat(DEBUG_STREAM_STATE, - "added %hu bytes on segment list @ seq: 0x%X, total %u, %u segments queued\n", - tsn->payload_size, tsn->seq, trs.sos.seg_bytes_logical, - get_pending_segment_count(trs, 0)); - *retSeg = tsn; return STREAM_INSERT_OK; } @@ -290,12 +270,8 @@ int TcpReassembler::purge_to_seq(TcpReassemblerState& trs, uint32_t flush_seq) int purged_bytes = 0; uint32_t last_ts = 0; - DebugFormat(DEBUG_STREAM_STATE, "In purge_to_seq, start seq = 0x%X end seq = 0x%X delta %u\n", - tsn->seq, flush_seq, flush_seq-tsn->seq); - while ( tsn ) { - DebugFormat(DEBUG_STREAM_STATE, "s: %X sz: %d\n", tsn->seq, tsn->payload_size); dump_me = tsn; tsn = tsn->next; @@ -313,7 +289,6 @@ int TcpReassembler::purge_to_seq(TcpReassemblerState& trs, uint32_t flush_seq) if ( SEQ_LT(trs.sos.seglist_base_seq, flush_seq) ) { // FIXIT-M these lines are out of code coverage. Is this even possible? - DebugFormat(DEBUG_STREAM_STATE, "setting seglist_base_seq to 0x%X\n", flush_seq); trs.sos.seglist_base_seq = flush_seq; } @@ -424,7 +399,6 @@ int TcpReassembler::flush_data_segments( uint32_t bytes_flushed = 0; uint32_t segs = 0; uint32_t flags = PKT_PDU_HEAD; - DEBUG_WRAP(uint32_t bytes_queued = trs.sos.seg_bytes_logical; ); assert(trs.sos.seglist.next); Profile profile(s5TcpBuildPacketPerfStats); @@ -439,8 +413,6 @@ int TcpReassembler::flush_data_segments( unsigned bytes_copied = 0; assert(bytes_to_copy); - DebugFormat(DEBUG_STREAM_STATE, "Flushing %u bytes from %X\n", bytes_to_copy, tsn->seq); - if ( !tsn->next or (bytes_to_copy < tsn->payload_size) or SEQ_EQ(tsn->seq + bytes_to_copy, to_seq) or (bytes_flushed + tsn->payload_size + tsn->next->payload_size > @@ -506,11 +478,6 @@ int TcpReassembler::flush_data_segments( break; } - DEBUG_WRAP(bytes_queued -= bytes_flushed; ); - DebugFormat(DEBUG_STREAM_STATE, - "flushed %u bytes / %u segs on stream, %u bytes still queued\n", - bytes_flushed, segs, bytes_queued); - return bytes_flushed; } @@ -599,8 +566,6 @@ int TcpReassembler::_flush_to_seq( p = pdu; } - DebugFormat(DEBUG_STREAM_STATE, "Attempting to flush %u bytes\n", bytes); - uint32_t bytes_processed = 0; uint32_t stop_seq = trs.sos.seglist.next->seq + bytes; @@ -648,9 +613,6 @@ int TcpReassembler::_flush_to_seq( tcpStats.rebuilt_buffers++; // FIXIT-L this is not accurate } - DebugFormat(DEBUG_STREAM_STATE, "setting trs.sos.seglist_base_seq to 0x%X\n", - trs.sos.seglist_base_seq); - // FIXIT-L must check because above may clear trs.sos.session if ( trs.tracker->splitter ) trs.tracker->splitter->update(); @@ -679,15 +641,12 @@ int TcpReassembler::flush_to_seq( { if ( !bytes || !trs.sos.seglist.next ) { - DebugFormat(DEBUG_STREAM_STATE, "bailing: no bytes: %u or empty trs.sos.seglist: %p\n", - bytes, (void*)trs.sos.seglist.next); return 0; } if ( !flush_data_ready(trs) and !(trs.tracker->get_tf_flags() & TF_FORCE_FLUSH) and !trs.tracker->splitter->is_paf() ) { - DebugMessage(DEBUG_STREAM_STATE, "only 1 packet in trs.sos.seglist no need to flush\n"); return 0; } @@ -1072,14 +1031,9 @@ int TcpReassembler::flush_on_data_policy(TcpReassemblerState& trs, Packet* p) { uint32_t flushed = 0; - DebugMessage(DEBUG_STREAM_STATE, "In CheckFlushPolicyOnData\n"); - DebugFormat(DEBUG_STREAM_STATE, "Listener flush policy: %s\n", - flush_policy_names[ trs.tracker->flush_policy ]); - switch ( trs.tracker->flush_policy ) { case STREAM_FLPOLICY_IGNORE: - DebugMessage(DEBUG_STREAM_STATE, "STREAM_FLPOLICY_IGNORE\n"); return 0; case STREAM_FLPOLICY_ON_ACK: @@ -1140,14 +1094,9 @@ int TcpReassembler::flush_on_ack_policy(TcpReassemblerState& trs, Packet* p) { uint32_t flushed = 0; - DebugMessage(DEBUG_STREAM_STATE, "In CheckFlushPolicyOnAck\n"); - DebugFormat(DEBUG_STREAM_STATE, "Talker flush policy: %s\n", - flush_policy_names[ trs.tracker->flush_policy ]); - switch (trs.tracker->flush_policy) { case STREAM_FLPOLICY_IGNORE: - DebugMessage(DEBUG_STREAM_STATE, "STREAM_FLPOLICY_IGNORE\n"); return 0; case STREAM_FLPOLICY_ON_ACK: @@ -1219,12 +1168,10 @@ void TcpReassembler::insert_segment_in_empty_seglist( if ( SEQ_GT(trs.tracker->r_win_base, seq) ) { - DebugMessage(DEBUG_STREAM_STATE, "segment overlaps ack'd data...\n"); overlap = trs.tracker->r_win_base - tsd.get_seg_seq(); if ( overlap >= tsd.get_seg_len() ) { - DebugMessage(DEBUG_STREAM_STATE, "full overlap on ack'd data, dropping segment\n"); return; } } @@ -1233,9 +1180,6 @@ void TcpReassembler::insert_segment_in_empty_seglist( add_reassembly_segment( trs, tsd, tsd.get_seg_len(), overlap, 0, tsd.get_seg_seq() + overlap, nullptr); - DebugFormat(DEBUG_STREAM_STATE, - "Attached new queue to trs.sos.seglist, %u bytes queued, base_seq 0x%X\n", - tsd.get_seg_len() - overlap, trs.sos.seglist_base_seq); } void TcpReassembler::init_overlap_editor( @@ -1248,12 +1192,6 @@ void TcpReassembler::init_overlap_editor( int32_t dist_head; int32_t dist_tail; - DEBUG_WRAP( - TcpSegmentNode *lastptr = nullptr; - uint32_t base_seq = trs.sos.seglist_base_seq; - int last = 0; - ); - if ( trs.sos.seglist.head && trs.sos.seglist.tail ) { if ( SEQ_GT(tsd.get_seg_seq(), trs.sos.seglist.head->seq) ) @@ -1273,17 +1211,6 @@ void TcpReassembler::init_overlap_editor( { for ( tsn = trs.sos.seglist.head; tsn; tsn = tsn->next ) { - DEBUG_WRAP( - DebugFormat(DEBUG_STREAM_STATE, "tsn: %p seq: 0x%X size: %hu delta: %u\n", - (void*) tsn, tsn->seq, tsn->payload_size, ( tsn->seq - base_seq ) - last); - - last = tsn->seq - base_seq; - lastptr = tsn; - - DebugFormat(DEBUG_STREAM_STATE, " lastptr: %p tsn->next: %p tsn->prev: %p\n", - (void*) lastptr, (void*) tsn->next, (void*) tsn->prev); - ); - right = tsn; if ( SEQ_GEQ(right->seq, tsd.get_seg_seq() ) ) @@ -1299,17 +1226,6 @@ void TcpReassembler::init_overlap_editor( { for ( tsn = trs.sos.seglist.tail; tsn; tsn = tsn->prev ) { - DEBUG_WRAP( - DebugFormat(DEBUG_STREAM_STATE, "tsn: %p seq: 0x%X size: %hu delta: %u\n", - (void*) tsn, tsn->seq, tsn->payload_size, ( tsn->seq - base_seq ) - last); - - last = tsn->seq - base_seq; - lastptr = tsn; - - DebugFormat(DEBUG_STREAM_STATE, " lastptr: %p tsn->next: %p tsn->prev: %p\n", - (void*) lastptr, (void*) tsn->next, (void*) tsn->prev); - ); - left = tsn; if ( SEQ_LT(left->seq, tsd.get_seg_seq() ) ) @@ -1322,11 +1238,6 @@ void TcpReassembler::init_overlap_editor( left = nullptr; } - DebugMessage(DEBUG_STREAM_STATE, "!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+\n"); - DebugMessage(DEBUG_STREAM_STATE, "!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+\n"); - - DebugFormat(DEBUG_STREAM_STATE, "left: %p:0x%X right: %p:0x%X\n", - (void*) left, left ? left->seq : 0, (void*) right, right ? right->seq : 0); trs.sos.init_soe(tsd, left, right); } @@ -1336,26 +1247,12 @@ int TcpReassembler::insert_segment_in_seglist( { int rc = STREAM_INSERT_OK; - DebugFormat(DEBUG_STREAM_STATE, - "Queuing %u bytes on stream!\nbase_seq: %X seq: %X seq_end: %X\n", - tsd.get_end_seq() - tsd.get_seg_seq(), trs.sos.seglist_base_seq, tsd.get_seg_seq(), - tsd.get_end_seq()); - - DebugFormat(DEBUG_STREAM_STATE, "%u segments on trs.sos.seglist\n", - get_pending_segment_count(trs, 0)); - - DebugMessage(DEBUG_STREAM_STATE, "!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+\n"); - DebugMessage(DEBUG_STREAM_STATE, "!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+!+\n"); - // NORM fast tracks are in sequence - no norms if ( trs.sos.seglist.tail && is_segment_fasttrack(trs, trs.sos.seglist.tail, tsd) ) { /* segment fit cleanly at the end of the segment list */ TcpSegmentNode* left = trs.sos.seglist.tail; - - DebugFormat(DEBUG_STREAM_STATE, "Fast tracking segment! (tail_seq %X size %d)\n", - trs.sos.seglist.tail->seq, trs.sos.seglist.tail->payload_size); - + // BLOCK add to existing block and/or allocate new block rc = add_reassembly_segment(trs, tsd, tsd.get_seg_len(), 0, 0, tsd.get_seg_seq(), left); return rc; @@ -1381,7 +1278,6 @@ int TcpReassembler::insert_segment_in_seglist( } else { - DebugMessage(DEBUG_STREAM_STATE, "Fully truncated right overlap\n"); rc = STREAM_INSERT_OK; } diff --git a/src/stream/tcp/tcp_session.cc b/src/stream/tcp/tcp_session.cc index 5ed6fa677..47a71b91a 100644 --- a/src/stream/tcp/tcp_session.cc +++ b/src/stream/tcp/tcp_session.cc @@ -64,11 +64,6 @@ using namespace snort; -#ifdef DEBUG_MSGS -static THREAD_LOCAL const char* t_name = nullptr; -static THREAD_LOCAL const char* l_name = nullptr; -#endif - TcpSession::TcpSession(Flow* flow) : TcpStreamSession(flow) { @@ -276,7 +271,6 @@ bool TcpSession::flow_exceeds_config_thresholds(TcpSegmentDescriptor& tsd) { if ( listener->flush_policy == STREAM_FLPOLICY_IGNORE ) { - DebugMessage(DEBUG_STREAM_STATE, "Ignoring segment due to IGNORE flush_policy\n"); return true; } @@ -322,9 +316,6 @@ bool TcpSession::flow_exceeds_config_thresholds(TcpSegmentDescriptor& tsd) void TcpSession::process_tcp_stream(TcpSegmentDescriptor& tsd) { - DebugFormat(DEBUG_STREAM_STATE, "In ProcessTcpStream(), %d bytes to queue\n", - tsd.get_seg_len()); - if (tsd.get_pkt()->packet_flags & PKT_IGNORE) return; @@ -333,7 +324,6 @@ void TcpSession::process_tcp_stream(TcpSegmentDescriptor& tsd) if ( flow_exceeds_config_thresholds(tsd) ) return; - DebugMessage(DEBUG_STREAM_STATE, "queuing segment\n"); listener->reassembler.queue_packet_for_reassembly(tsd); // Alert if overlap limit exceeded @@ -371,7 +361,6 @@ int TcpSession::process_tcp_data(TcpSegmentDescriptor& tsd) else { - DebugMessage(DEBUG_STREAM_STATE, "Bailing, data on SYN, not MAC Policy!\n"); listener->normalizer.trim_syn_payload(tsd); return STREAM_UNALIGNED; } } @@ -383,7 +372,6 @@ int TcpSession::process_tcp_data(TcpSegmentDescriptor& tsd) if (config->policy != StreamPolicy::OS_PROXY and listener->normalizer.get_stream_window(tsd) == 0) { - DebugMessage(DEBUG_STREAM_STATE, "Bailing, we're out of the window!\n"); listener->normalizer.trim_win_payload(tsd); return STREAM_UNALIGNED; } @@ -410,15 +398,11 @@ int TcpSession::process_tcp_data(TcpSegmentDescriptor& tsd) // original data. Let the reassembly policy decide how to handle the overlapping data. // See HP, Solaris, et al. for those that favor duplicate data over the original in // some cases. - DebugFormat(DEBUG_STREAM_STATE, - "out of order segment (tsd.seq: 0x%X l->r_nxt_ack: 0x%X!\n", - tsd.get_seg_seq(), listener->r_nxt_ack); /* check if we're in the window */ if (config->policy != StreamPolicy::OS_PROXY and listener->normalizer.get_stream_window(tsd) == 0) { - DebugMessage(DEBUG_STREAM_STATE, "Bailing, we're out of the window!\n"); listener->normalizer.trim_win_payload(tsd); return STREAM_UNALIGNED; } @@ -534,7 +518,6 @@ bool TcpSession::handle_syn_on_reset_session(TcpSegmentDescriptor& tsd) || ( talker->get_tcp_state() == TcpStreamTracker::TCP_CLOSED ) ) { // Listener previously issued a reset Talker is re-SYN-ing - DebugMessage(DEBUG_STREAM_STATE, "Got SYN pkt on reset ssn, re-SYN-ing\n"); // FIXIT-M this leads to bogus 129:20 clear_session( true, true, true, tsd.get_pkt() ); @@ -621,7 +604,6 @@ void TcpSession::handle_data_on_syn(TcpSegmentDescriptor& tsd) else { listener->normalizer.trim_syn_payload(tsd); - DebugMessage(DEBUG_STREAM_STATE, "Got data on SYN packet, not processing it\n"); tel.set_tcp_event(EVENT_DATA_ON_SYN); pkt_action_mask |= ACTION_BAD_PKT; } @@ -646,8 +628,6 @@ void TcpSession::update_session_on_rst(TcpSegmentDescriptor& tsd, bool flush) void TcpSession::update_paws_timestamps(TcpSegmentDescriptor& tsd) { // update PAWS timestamps - DebugFormat(DEBUG_STREAM_STATE, "PAWS update tsd.seq %u > listener->r_win_base %u\n", - tsd.get_seg_seq(), listener->r_win_base); if ( listener->normalizer.handling_timestamps() && SEQ_EQ(listener->r_win_base, tsd.get_seg_seq() ) ) @@ -657,15 +637,10 @@ void TcpSession::update_paws_timestamps(TcpSegmentDescriptor& tsd) ( ( uint32_t )tsd.get_pkt()->pkth->ts.tv_sec >= talker->get_ts_last_packet() + PAWS_24DAYS ) ) { - DebugMessage(DEBUG_STREAM_STATE, "updating timestamps...\n"); talker->set_ts_last(tsd.get_ts()); talker->set_ts_last_packet(tsd.get_pkt()->pkth->ts.tv_sec); } } - else - { - DebugMessage(DEBUG_STREAM_STATE, "not updating timestamps...\n"); - } } void TcpSession::check_for_session_hijack(TcpSegmentDescriptor& tsd) @@ -714,8 +689,6 @@ bool TcpSession::check_for_window_slam(TcpSegmentDescriptor& tsd) { if ( config->max_window && (tsd.get_seg_wnd() > config->max_window ) ) { - DebugMessage(DEBUG_STREAM_STATE, - "Got window that was beyond the allowed policy value, bailing\n"); /* got a window too large, alert! */ tel.set_tcp_event(EVENT_WINDOW_TOO_LARGE); inc_tcp_discards(); @@ -729,7 +702,6 @@ bool TcpSession::check_for_window_slam(TcpSegmentDescriptor& tsd) && !( tsd.get_tcph()->is_fin() | tsd.get_tcph()->is_rst() ) && !(flow->get_session_flags() & SSNFLAG_MIDSTREAM)) { - DebugMessage(DEBUG_STREAM_STATE, "Window slammed shut!\n"); /* got a window slam alert! */ tel.set_tcp_event(EVENT_WINDOW_SLAM); inc_tcp_discards(); @@ -752,13 +724,6 @@ void TcpSession::mark_packet_for_drop(TcpSegmentDescriptor& tsd) void TcpSession::handle_data_segment(TcpSegmentDescriptor& tsd) { - DebugFormat(DEBUG_STREAM_STATE, " %s state: %s(%d) getting data\n", - l_name, tcp_state_names[listener->get_tcp_state()], listener->get_tcp_state()); - - DebugFormat(DEBUG_STREAM_STATE, "Queuing data on listener, t %s, l %s...\n", - flush_policy_names[talker->flush_policy], - flush_policy_names[listener->flush_policy]); - if ( TcpStreamTracker::TCP_CLOSED != talker->get_tcp_state() ) { uint8_t tcp_options_len = tsd.get_tcph()->options_len(); @@ -891,8 +856,6 @@ void TcpSession::flush_tracker( if ( final_flush && ( !tracker.splitter || !tracker.splitter->finish(flow) ) ) return; - DebugFormat(DEBUG_STREAM_STATE, "Flushing tracker on packet from %s\n", - (dir == PKT_FROM_CLIENT) ? "client" : "server"); tracker.set_tf_flags(TF_FORCE_FLUSH); if ( tracker.reassembler.flush_stream(p, dir) ) tracker.reassembler.purge_flushed_ackd(); @@ -948,10 +911,6 @@ void TcpSession::do_packet_analysis_post_checks(Packet* p) if (pkt_action_mask & ACTION_DISABLE_INSPECTION) { DetectionEngine::disable_all(p); - - DebugFormat(DEBUG_STREAM_STATE, - "Stream Ignoring packet from %s. Session marked as ignore\n", - p->is_from_server() ? "server" : "client"); } } @@ -963,7 +922,6 @@ bool TcpSession::is_flow_handling_packets(Packet* p) // FIXIT-L can't get here without protocol being set to TCP, is this really needed?? if (flow->pkt_type != PktType::TCP) { - DebugMessage(DEBUG_STREAM_STATE, "Lightweight session not TCP on TCP packet\n"); return false; } @@ -1033,23 +991,16 @@ bool TcpSession::do_packet_analysis_pre_checks(Packet* p, TcpSegmentDescriptor& if (p->is_from_client()) { update_session_on_client_packet(tsd); - DEBUG_WRAP(t_name = "Server"; l_name = "Client"); } else { update_session_on_server_packet(tsd); - DEBUG_WRAP(t_name = "Server"; l_name = "Client"); } update_ignored_session(tsd); set_window_scale(*talker, *listener, tsd); check_for_session_hijack(tsd); - DebugFormat(DEBUG_STREAM_STATE, " %s [talker] state: %s\n", t_name, - tcp_state_names[talker->get_tcp_state()]); - DebugFormat(DEBUG_STREAM_STATE, " %s state: %s(%d)\n", l_name, - tcp_state_names[listener->get_tcp_state()], listener->get_tcp_state()); - return true; } @@ -1070,23 +1021,6 @@ int TcpSession::process(Packet* p) { Profile profile(s5TcpPerfStats); - DEBUG_WRAP - ( - char flagbuf[9]; - CreateTCPFlagString(p->ptrs.tcph, flagbuf); - - char src_addr[INET6_ADDRSTRLEN]; - char dst_addr[INET6_ADDRSTRLEN]; - - sfip_ntop(p->ptrs.ip_api.get_src(), src_addr, sizeof(src_addr)); - sfip_ntop(p->ptrs.ip_api.get_dst(), dst_addr, sizeof(dst_addr)); - - DebugFormat((DEBUG_STREAM|DEBUG_STREAM_STATE), - "Got TCP Packet %s:%hu -> %s:%hu %s\nseq: 0x%X ack:0x%X dsize: %hu\n", - src_addr, p->ptrs.sp, dst_addr, p->ptrs.dp, flagbuf, - p->ptrs.tcph->seq(), p->ptrs.tcph->ack(), p->dsize); - ); - assert(flow->ssn_server); // FIXIT-H need to do something here to handle check for need to swap trackers?? @@ -1117,7 +1051,6 @@ int TcpSession::process(Packet* p) { if ( pkt_action_mask & ACTION_BAD_PKT ) { - DebugMessage(DEBUG_STREAM_STATE, "bad packet, bailing\n"); inc_tcp_discards(); do_packet_analysis_post_checks(p); @@ -1128,9 +1061,6 @@ int TcpSession::process(Packet* p) } } - DebugMessage(DEBUG_STREAM_STATE, - "Finished Stream TCP cleanly!\n---------------------------------------------------\n"); - return ACTION_NOTHING; } diff --git a/src/stream/tcp/tcp_state_close_wait.cc b/src/stream/tcp/tcp_state_close_wait.cc index 79b31a5f2..37ea80a92 100644 --- a/src/stream/tcp/tcp_state_close_wait.cc +++ b/src/stream/tcp/tcp_state_close_wait.cc @@ -25,7 +25,6 @@ #include "tcp_state_close_wait.h" -#include "main/snort_debug.h" #include "tcp_normalizers.h" #include "tcp_session.h" @@ -96,7 +95,6 @@ bool TcpStateCloseWait::fin_recv(TcpSegmentDescriptor& tsd, TcpStreamTracker& tr if ( SEQ_GT(tsd.get_seg_seq(), trk.get_fin_final_seq() ) ) { - DebugMessage(DEBUG_STREAM_STATE, "FIN beyond previous, ignoring\n"); trk.session->tel.set_tcp_event(EVENT_BAD_FIN); trk.normalizer.packet_dropper(tsd, NORM_TCP_BLOCK); trk.session->set_pkt_action_flag(ACTION_BAD_PKT); diff --git a/src/stream/tcp/tcp_state_closing.cc b/src/stream/tcp/tcp_state_closing.cc index 46506aefe..4ce384292 100644 --- a/src/stream/tcp/tcp_state_closing.cc +++ b/src/stream/tcp/tcp_state_closing.cc @@ -25,8 +25,6 @@ #include "tcp_state_closing.h" -#include "main/snort_debug.h" - #include "tcp_normalizers.h" #include "tcp_session.h" @@ -96,7 +94,6 @@ bool TcpStateClosing::fin_recv(TcpSegmentDescriptor& tsd, TcpStreamTracker& trk) trk.update_tracker_ack_recv(tsd); if ( SEQ_GT(tsd.get_seg_seq(), trk.get_fin_final_seq() ) ) { - DebugMessage(DEBUG_STREAM_STATE, "FIN beyond previous, ignoring\n"); trk.session->tel.set_tcp_event(EVENT_BAD_FIN); trk.normalizer.packet_dropper(tsd, NORM_TCP_BLOCK); trk.session->set_pkt_action_flag(ACTION_BAD_PKT); diff --git a/src/stream/tcp/tcp_state_fin_wait1.cc b/src/stream/tcp/tcp_state_fin_wait1.cc index bae4b73f6..49c494aaf 100644 --- a/src/stream/tcp/tcp_state_fin_wait1.cc +++ b/src/stream/tcp/tcp_state_fin_wait1.cc @@ -25,8 +25,6 @@ #include "tcp_state_fin_wait1.h" -#include "main/snort_debug.h" - #include "tcp_normalizers.h" #include "tcp_module.h" #include "tcp_session.h" @@ -142,9 +140,6 @@ bool TcpStateFinWait1::rst_recv(TcpSegmentDescriptor& tsd, TcpStreamTracker& trk bool TcpStateFinWait1::check_for_window_slam(TcpSegmentDescriptor& tsd, TcpStreamTracker& trk, bool* is_ack_valid) { - DebugFormat(DEBUG_STREAM_STATE, "tsd.ack %X >= listener->snd_nxt %X\n", - tsd.get_seg_ack(), trk.get_snd_nxt()); - if ( SEQ_EQ(tsd.get_seg_ack(), trk.get_snd_nxt() ) ) { if ( (trk.normalizer.get_os_policy() == StreamPolicy::OS_WINDOWS) diff --git a/src/stream/tcp/tcp_state_syn_recv.cc b/src/stream/tcp/tcp_state_syn_recv.cc index 289d3cdac..2515b4051 100644 --- a/src/stream/tcp/tcp_state_syn_recv.cc +++ b/src/stream/tcp/tcp_state_syn_recv.cc @@ -174,7 +174,6 @@ bool TcpStateSynRecv::rst_recv(TcpSegmentDescriptor& tsd, TcpStreamTracker& trk) } else { - DebugMessage(DEBUG_STREAM_STATE, "Received RST with bad sequence number\n"); inc_tcp_discards(); trk.normalizer.packet_dropper(tsd, NORM_TCP_BLOCK); trk.session->tel.set_tcp_event(EVENT_BAD_RST); diff --git a/src/stream/tcp/tcp_state_time_wait.cc b/src/stream/tcp/tcp_state_time_wait.cc index 1abf966b0..131e75f4b 100644 --- a/src/stream/tcp/tcp_state_time_wait.cc +++ b/src/stream/tcp/tcp_state_time_wait.cc @@ -25,8 +25,6 @@ #include "tcp_state_time_wait.h" -#include "main/snort_debug.h" - #include "tcp_normalizers.h" #include "tcp_session.h" @@ -71,7 +69,6 @@ bool TcpStateTimeWait::fin_recv(TcpSegmentDescriptor& tsd, TcpStreamTracker& trk trk.update_tracker_ack_recv(tsd); if ( SEQ_GT(tsd.get_seg_seq(), trk.get_fin_final_seq() ) ) { - DebugMessage(DEBUG_STREAM_STATE, "FIN beyond previous, ignoring\n"); trk.session->tel.set_tcp_event(EVENT_BAD_FIN); trk.normalizer.packet_dropper(tsd, NORM_TCP_BLOCK); trk.session->set_pkt_action_flag(ACTION_BAD_PKT); diff --git a/src/stream/udp/udp_session.cc b/src/stream/udp/udp_session.cc index 147000dcd..e9dc9337c 100644 --- a/src/stream/udp/udp_session.cc +++ b/src/stream/udp/udp_session.cc @@ -73,15 +73,11 @@ static int ProcessUdp( /* if both seen, mark established */ if (p->is_from_server()) { - DebugMessage(DEBUG_STREAM_STATE, - "Stream: Updating on packet from responder\n"); lwssn->ssn_state.session_flags |= SSNFLAG_SEEN_RESPONDER; lwssn->set_ttl(p, false); } else { - DebugMessage(DEBUG_STREAM_STATE, - "Stream: Updating on packet from client\n"); lwssn->ssn_state.session_flags |= SSNFLAG_SEEN_SENDER; lwssn->set_ttl(p, true); }