Merge pull request #1234 in SNORT/snort3 from add_trace to master

Squashed commit of the following:

commit 10d579e68a74a54c9f9ee56c2d772d8360e47e87
Author: mdagon <mdagon@cisco.com>
Date:   Wed May 16 15:49:03 2018 -0400

    trace: add traces for deleted debug messages

diff --git a/doc/module_trace.txt b/doc/module_trace.txt
index 7421bf55249f2e6244fdb1544da7cd530fbcf677..9b86d6ff55ffe2a1b606cda3c9e7cbe2df1c909b 100644 (file)
--- a/doc/module_trace.txt
+++ b/doc/module_trace.txt
@@ -129,6 +129,23 @@ The output:
     var[0]=1 var[1]=10 var[2]=0 
     04/22-20:21:40.905630, 1, TCP, raw, 56, C2S, 127.0.0.1:1234, 127.0.0.1:5678, 1:3:0, allow
 
+==== Protocols decoding trace
+
+Turning on decode trace will print out information about the packets decoded
+protocols. Can be useful in case of tunneling.
+
+Example for a icmpv4-in-ipv6 packet:
+
+In snort.lua, the following line was added:
+
+decode = { trace = 1 }
+
+The output:
+
+    decode: Codec eth (protocol_id: 34525) ip header starts at: 0x7f70800110f0, length is 14
+    decode: Codec ipv6 (protocol_id: 1) ip header starts at: 0x7f70800110f0, length is 40
+    decode: Codec icmp4 (protocol_id: 256) ip header starts at: 0x7f70800110f0, length is 8
+    decode: Codec unknown (protocol_id: 256) ip header starts at: 0x7f70800110f0, length is 0
 
 ==== Other available traces
 

diff --git a/src/codecs/codec_module.cc b/src/codecs/codec_module.cc
index 80d18fa65b74b6b8bc6639c3beac8d871f789ffc..60d51ec75761d6b477a0083f08fb7c31dc845adb 100644 (file)
--- a/src/codecs/codec_module.cc
+++ b/src/codecs/codec_module.cc
@@ -23,14 +23,25 @@
 
 #include "codecs/codec_module.h"
 
+#include "main/snort_debug.h"
+
 using namespace snort;
 
 #define codec_module_help \
     "general decoder rules"
 
-CodecModule::CodecModule() : Module("decode", codec_module_help)
+Trace TRACE_NAME(decode);
+
+static const Parameter s_params[] = {{ nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }};
+
+CodecModule::CodecModule() : Module("decode", codec_module_help, s_params, false, &TRACE_NAME(decode))
 { }
 
+bool CodecModule::set(const char* fqn, Value& v, SnortConfig* sc)
+{
+    return Module::set(fqn, v, sc);
+}
+
 static const RuleMap general_decode_rules[] =
 {
     { DECODE_IP_BAD_PROTO, "bad IP protocol" },

diff --git a/src/codecs/codec_module.h b/src/codecs/codec_module.h
index a49e7b966fa6f454c3291403859a7bbc52cf1ad8..6d7cbb6a3691300b923d969227731c8d381aa7a1 100644 (file)
--- a/src/codecs/codec_module.h
+++ b/src/codecs/codec_module.h
@@ -24,6 +24,7 @@
 #include <cstdint>
 
 #include "framework/module.h"
+#include "main/snort_debug.h"
 #include "main/snort_types.h"
 
 namespace snort
@@ -237,7 +238,12 @@ public:
 
     Usage get_usage() const override
     { return CONTEXT; }
+
+    bool set(const char*, snort::Value&, snort::SnortConfig*) override;
 };
 }
+
+extern Trace TRACE_NAME(decode);
+
 #endif
 

diff --git a/src/framework/module.cc b/src/framework/module.cc
index 0cf75ffaa36b62b9245e404001845faf161acc60..5138007fefccae2584ad29e879952a082a57d34d 100644 (file)
--- a/src/framework/module.cc
+++ b/src/framework/module.cc
@@ -28,7 +28,7 @@ using namespace snort;
 static const Parameter defaults[] =
 {
     { "trace", Parameter::PT_INT, nullptr, nullptr,
-      "mask for enabling debug traces in module"  },
+      "mask for enabling debug traces in module" },
 
     { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }
 };
@@ -202,3 +202,9 @@ const PegInfo simple_pegs[] =
     { CountType::END, nullptr, nullptr }
 };
 
+void Module::enable_trace()
+{
+    if ( trace )
+        *trace = 1;
+}
+

diff --git a/src/framework/module.h b/src/framework/module.h
index 1e65f86e521db1ae6283cf1de9c15ede9f44b8d0..a3a7e8418a386676563518cd8ddc384aca2a3ecb 100644 (file)
--- a/src/framework/module.h
+++ b/src/framework/module.h
@@ -184,6 +184,8 @@ public:
     virtual Usage get_usage() const
     { return CONTEXT; }
 
+    void enable_trace();
+
 protected:
     Module(const char* name, const char* help);
     Module(const char* name, const char* help, const Parameter*,

diff --git a/src/main.cc b/src/main.cc
index aba39f06f8c61bda7f4b8a36b2b576d79f0e6287..8b3cf0e7fae93ae5b9e2cb4e4dc17719768c61dd 100644 (file)
--- a/src/main.cc
+++ b/src/main.cc
@@ -37,6 +37,7 @@
 #include "main/shell.h"
 #include "main/snort.h"
 #include "main/snort_config.h"
+#include "main/snort_debug.h"
 #include "main/snort_module.h"
 #include "main/swapper.h"
 #include "main/thread_config.h"
@@ -189,7 +190,14 @@ bool Pig::queue_command(AnalyzerCommand* ac, bool orphan)
             orphan_commands.push(ac);
         return false;
     }
+
+#ifdef DEBUG_MSGS
+    unsigned ac_ref_count = ac->get();
+    trace_logf(snort, "[%u] Queuing command %s for execution (refcount %u)\n",
+            idx, ac->stringify(), ac_ref_count);
+#else
     ac->get();
+#endif
     analyzer->execute(ac);
     return true;
 }
@@ -199,8 +207,15 @@ void Pig::reap_command(AnalyzerCommand* ac)
     unsigned ac_ref_count = ac->put();
     if (ac_ref_count == 0)
     {
+        trace_logf(snort, "[%u] Destroying completed command %s\n",
+                idx, ac->stringify());
         delete ac;
     }
+#ifdef DEBUG_MSGS
+    else
+        trace_logf(snort, "[%u] Reaped ongoing command %s (refcount %u)\n",
+                idx, ac->stringify(), ac_ref_count);
+#endif
 }
 
 void Pig::reap_commands()
@@ -258,6 +273,7 @@ void snort::main_broadcast_command(AnalyzerCommand* ac, bool from_shell)
     unsigned dispatched = 0;
     
     ac = get_command(ac, from_shell);
+    trace_logf(snort, "Broadcasting %s command\n", ac->stringify());
 
     for (unsigned idx = 0; idx < max_pigs; ++idx)
     {
@@ -587,6 +603,7 @@ static void reap_commands()
     {
         AnalyzerCommand* ac = orphan_commands.front();
         orphan_commands.pop();
+        trace_logf(snort, "Destroying orphan command %s\n", ac->stringify());
         delete ac;
     }
 }

diff --git a/src/main/snort_module.cc b/src/main/snort_module.cc
index 490692d5d75293295a74a53ab14e033bff41a7d1..3d277c2be943adfbec1cc68b47ab2c0b593a7105 100644 (file)
--- a/src/main/snort_module.cc
+++ b/src/main/snort_module.cc
@@ -28,6 +28,7 @@
 #include "framework/parameter.h"
 #include "log/messages.h"
 #include "main.h"
+#include "main/snort_debug.h"
 #include "packet_io/sfdaq_config.h"
 #include "packet_io/trough.h"
 #include "parser/config_file.h"
@@ -501,6 +502,9 @@ static const Parameter s_params[] =
 
     { "--x2s", Parameter::PT_STRING, nullptr, nullptr,
       "output ASCII string for given byte code (see also --x2c)" },
+  
+    { "--trace", Parameter::PT_IMPLIED, nullptr, nullptr,
+      "turn on main loop debug trace" },
 
     { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }
 };
@@ -519,10 +523,12 @@ static const Parameter s_params[] =
     "command line configuration"
 #endif
 
+Trace TRACE_NAME(snort);
+
 class SnortModule : public Module
 {
 public:
-    SnortModule() : Module(s_name, s_help, s_params)
+    SnortModule() : Module(s_name, s_help, s_params, false, &TRACE_NAME(snort))
     { }
 
 #ifdef SHELL
@@ -944,6 +950,9 @@ bool SnortModule::set(const char*, Value& v, SnortConfig* sc)
     else if ( v.is("--x2s") )
         x2s(v.get_string());
 
+    else if (v.is("--trace"))
+        Module::enable_trace();
+
     return true;
 }
 

diff --git a/src/main/snort_module.h b/src/main/snort_module.h
index 8db40a4743f673785924b3991edec937ea804fd3..8d4bc7f282d9b3a248a91196b7b171f5ea0478b6 100644 (file)
--- a/src/main/snort_module.h
+++ b/src/main/snort_module.h
@@ -24,11 +24,14 @@
 // the snort module is for handling command line args,
 // shell commands, and basic application stats
 
+#include "main/snort_debug.h"
+
 namespace snort
 {
 class Module;
 }
 
+extern Trace TRACE_NAME(snort);
 snort::Module* get_snort_module();
 
 #endif

diff --git a/src/protocols/packet_manager.cc b/src/protocols/packet_manager.cc
index eac2cc1ed6d79273f63a4eb9cf76fc2799e37592..1a2867c3c7b4dbf6a659be3f54b85fda233ae845 100644 (file)
--- a/src/protocols/packet_manager.cc
+++ b/src/protocols/packet_manager.cc
@@ -160,6 +160,11 @@ void PacketManager::decode(
     // loop until the protocol id is no longer valid
     while (CodecManager::s_protocols[mapped_prot]->decode(raw, codec_data, p->ptrs))
     {
+        trace_logf(decode, "Codec %s (protocol_id: %hu) "
+            "ip header starts at: %p, length is %d\n",
+            CodecManager::s_protocols[mapped_prot]->get_name(),
+            static_cast<uint16_t>(codec_data.next_prot_id), pkt, codec_data.lyr_len);
+
         if ( codec_data.codec_flags & CODEC_ETHER_NEXT )
         {
             if ( codec_data.next_prot_id < ProtocolId::ETHERTYPE_MINIMUM )
@@ -233,6 +238,11 @@ void PacketManager::decode(
         codec_data.proto_bits = 0;
     }
 
+    trace_logf(decode, "Codec %s (protocol_id: %hu) ip header"
+        " starts at: %p, length is %lu\n",
+        CodecManager::s_protocols[mapped_prot]->get_name(),
+        static_cast<uint16_t>(prev_prot_id), pkt, (unsigned long)codec_data.lyr_len);
+
     if ( p->num_layers > 0 )
         s_stats[mapped_prot + stat_offset]++;