]> git.ipfire.org Git - thirdparty/snort3.git/commitdiff
Merge pull request #2561 in SNORT/snort3 from ~OKHOMIAK/snort3:trace_add_timestamps...
authorBhagya Tholpady (bbantwal) <bbantwal@cisco.com>
Tue, 27 Oct 2020 12:41:30 +0000 (12:41 +0000)
committerBhagya Tholpady (bbantwal) <bbantwal@cisco.com>
Tue, 27 Oct 2020 12:41:30 +0000 (12:41 +0000)
Squashed commit of the following:

commit 306574431a9c2ddc00edfa11f37ae29d3bd77222
Author: Oleksii Khomiakovskyi <okhomiak@cisco.com>
Date:   Mon Oct 12 13:18:36 2020 +0300

    trace: add timestamps in trace log messages for stdout logger

doc/user/trace.txt
src/trace/dev_notes.txt
src/trace/trace_api.cc
src/trace/trace_config.cc
src/trace/trace_config.h
src/trace/trace_logger.h
src/trace/trace_loggers.cc
src/trace/trace_module.cc
src/trace/trace_swap.cc

index b2b1de00dc1d92b99f4f45716c1c46a0732bae22..5b335543de951ed885fc0ac904ce073f3cd5751e 100644 (file)
@@ -14,12 +14,13 @@ following parameters:
     output - configure the output method for trace messages
     modules - trace configuration for specific modules
     constraints - filter traces by the packet constraints
-    log_ntuple - on/off packet n-tuple info logging
+    ntuple - on/off packet n-tuple info logging
+    timestamp - on/off message timestamps logging
 
 The following lines, added in snort.lua, will enable trace messages for
 detection and codec modules. The messages will be printed to syslog if
 the packet filtering constraints match. Messages will be in extended format,
-including n-tuple packet info at the beginning of each trace message.
+including timestamp and n-tuple packet info at the beginning of each trace message.
 
     trace =
     {
@@ -36,7 +37,8 @@ including n-tuple packet info at the beginning of each trace message.
             src_port = 100,
             dst_port = 200
         },
-        log_ntuple = true
+        ntuple = true,
+        timestamp = true
     }
 
 The trace module supports config reloading. Also, it's possible to set or clear
@@ -210,7 +212,8 @@ The trace control channel command is a way how to configure module trace
 options and/or packet filter constraints directly during Snort run and
 without reloading the entire config.
 
-Control channel also allow adjusting trace output format by setting log_ntuple switcher.
+Control channel also allow adjusting trace output format by setting ntuple
+and timestamp switchers.
 
 After entering the Snort shell, there are two commands available for
 the trace module:
@@ -219,7 +222,9 @@ the trace module:
 
     trace.set({ modules = { all = N } }) - enable traces for all modules with verbosity level N
 
-    trace.set({ log_ntuple = true/false }) - on/off packet n-tuple info logging
+    trace.set({ ntuple = true/false }) - on/off packet n-tuple info logging
+
+    trace.set({ timestamp = true/false }) - on/off timestamp logging
 
     trace.clear() - clear modules traces and constraints
 
@@ -247,7 +252,7 @@ C – main (control) thread
 P – packet thread
 O – other thread
 
-Setting the option - *log_ntuple* allows you to change the trace message format,
+Setting the option - *ntuple* allows you to change the trace message format,
 expanding it with information about the processed packet.
 
 It will be added at the beginning, right after the thread type and instance ID,
@@ -267,6 +272,20 @@ Where:
 Those info can be displayed only for IP packets.
 Port defaults to zero if a packet doesn't have it.
 
+The *timestamp* option extends output format
+by logging the message time in the next format:
+
+    MM/DD-hh:mm:ss.SSSSSS
+
+Where:
+
+    M – month
+    D – day
+    h – hours
+    m – minutes
+    s – seconds
+    S – milliseconds
+
 ==== Example - Debugging rules using detection trace
 
 The detection engine is responsible for rule evaluation. Turning on the
index afb85b2e35913a104a456abc82cc2c30342ddc36..9e9b1c91de2c856907b525f340422d9d6c3b8568 100644 (file)
@@ -31,7 +31,8 @@ This directory contains the trace logger framework.
         output - create a concrete logger factory based on the output value (stdout/syslog).
         constraints - set packet constraints to use for trace filtering.
         modules - set modules trace level verbosity.
-        log_ntuple - on/off packet n-tuple info logging.
+        ntuple - on/off packet n-tuple info logging.
+        timestamp - on/off message time stamps.
 
     This is a built-in module (from coreinit.lua)
 
@@ -46,8 +47,8 @@ This directory contains the trace logger framework.
     for setting/clearing trace configuration from the shell. Commands parameters are encapsulated in
     the TraceSwapParams class.
     Available commands:
-        1) trace.set({ modules = {}, constraints = {}, log_ntuple = true/false })
-           -- set new modules traces, constraints and log_ntuple option;
+        1) trace.set({ modules = {}, constraints = {}, ntuple = true/false, timestamp = true/false })
+           -- set new modules traces, constraints, ntuple and timestamp options;
         2) trace.clear() -- clear modules traces and constraints.
 
 * TraceSwapParams
index 24b81499b79503b3d446143a77e6c8ea72b2903d..48e72ded8d5de0ac991926d7c9064fea597c784b 100644 (file)
@@ -52,10 +52,13 @@ static void update_constraints(PacketConstraints* new_cs)
     g_packet_constraints = new_cs;
 }
 
-static inline void set_ntuple(bool log_ntuple)
+static inline void set_logger_options(const TraceConfig* trace_config)
 {
     if ( g_trace_logger )
-        g_trace_logger->set_ntuple(log_ntuple);
+    {
+        g_trace_logger->set_ntuple(trace_config->ntuple);
+        g_trace_logger->set_timestamp(trace_config->timestamp);
+    }
 }
 
 void TraceApi::thread_init(const TraceConfig* trace_config)
@@ -63,7 +66,7 @@ void TraceApi::thread_init(const TraceConfig* trace_config)
     if ( trace_config->logger_factory )
         g_trace_logger = trace_config->logger_factory->instantiate();
 
-    set_ntuple(trace_config->log_ntuple);
+    set_logger_options(trace_config);
     update_constraints(trace_config->constraints);
     trace_config->setup_module_trace();
 }
@@ -78,7 +81,7 @@ void TraceApi::thread_term()
 
 void TraceApi::thread_reinit(const TraceConfig* trace_config)
 {
-    set_ntuple(trace_config->log_ntuple);
+    set_logger_options(trace_config);
     update_constraints(trace_config->constraints);
     trace_config->setup_module_trace();
 }
index 04078f2fee81fa82c577771c7f16673abaf159e2..f2766d317b6dc77e557fce6ce532498fb0eed1b7 100644 (file)
@@ -47,7 +47,8 @@ TraceConfig::TraceConfig(const TraceConfig& other)
     : TraceConfig()
 {
     traces = other.traces;
-    log_ntuple = other.log_ntuple;
+    ntuple = other.ntuple;
+    timestamp = other.timestamp;
     if ( other.constraints )
         constraints = new PacketConstraints(*other.constraints);
 }
index c20cf61d303cad7d234fd79ba15a731b1a6e3b05..dba31b229344c677880a4293111ce3dce20e87cc 100644 (file)
@@ -45,8 +45,11 @@ public:
 public:
     snort::TraceLoggerFactory* logger_factory = nullptr;
     snort::PacketConstraints* constraints = nullptr;
-    bool log_ntuple = false;
+
+    bool ntuple = false;
+    bool timestamp = false;
     bool initialized = false;
+
 private:
     Traces traces;
 };
index 61aba1f84f1a3c2906a751955a1880c3ed547e7a..0ce74a0bf8ef00788be47e90731f330199902314 100644 (file)
@@ -35,10 +35,14 @@ public:
         uint8_t log_level, const char* trace_option, const Packet* p) = 0;
 
     void set_ntuple(bool flag)
-    { log_ntuple = flag; }
+    { ntuple = flag; }
+
+    void set_timestamp(bool flag)
+    { timestamp = flag; }
 
 protected:
-    bool log_ntuple = false;
+    bool ntuple = false;
+    bool timestamp = false;
 };
 
 class TraceLoggerFactory
index 4c74c36182a15e7bcfe5ce5c03e5154d41d1766a..16d6742f491d5c0cf2aeba3a414a68efc3d80178 100644 (file)
@@ -28,6 +28,7 @@
 
 #include "main/thread.h"
 #include "protocols/packet.h"
+#include "utils/util.h"
 
 using namespace snort;
 
@@ -35,9 +36,9 @@ using namespace snort;
 //  Loggers
 //-----------------------------------------------
 
-static std::string get_ntuple(bool log_ntuple, const Packet* p)
+static std::string get_ntuple(bool ntuple, const Packet* p)
 {
-    if ( !log_ntuple or !p or !p->has_ip() )
+    if ( !ntuple or !p or !p->has_ip() )
         return "";
 
     SfIpString src_addr;
@@ -62,6 +63,17 @@ static std::string get_ntuple(bool log_ntuple, const Packet* p)
     return ss.str();
 }
 
+static std::string get_timestamp(bool timestamp)
+{
+    if ( !timestamp )
+        return "";
+
+    char ts[TIMEBUF_SIZE];
+    ts_print(nullptr, ts);
+
+    return std::string(ts) + ":";
+}
+
 // Stdout
 
 class StdoutTraceLogger : public TraceLogger
@@ -98,8 +110,9 @@ StdoutTraceLogger::StdoutTraceLogger()
 void StdoutTraceLogger::log(const char* log_msg, const char* name,
     uint8_t log_level, const char* trace_option, const Packet* p)
 {
-    fprintf(file, "%c%u:%s%s:%s:%d: %s", thread_type, instance_id,
-        get_ntuple(log_ntuple, p).c_str(), name, trace_option, log_level, log_msg);
+    fprintf(file, "%s%c%u:%s%s:%s:%d: %s", get_timestamp(timestamp).c_str(),
+        thread_type, instance_id, get_ntuple(ntuple, p).c_str(),
+        name, trace_option, log_level, log_msg);
 }
 
 // Syslog
@@ -123,7 +136,7 @@ SyslogTraceLogger::SyslogTraceLogger()
 void SyslogTraceLogger::log(const char* log_msg, const char* name,
     uint8_t log_level, const char* trace_option, const Packet* p)
 {
-    syslog(priority, "%s%s:%s:%d: %s", get_ntuple(log_ntuple, p).c_str(),
+    syslog(priority, "%s%s:%s:%d: %s", get_ntuple(ntuple, p).c_str(),
         name, trace_option, log_level, log_msg);
 }
 
index b0c4b5a00a2e8df415776604f11084af8adc1505..88cf8cf445ab4db2f7dd71126d885554e9e3fd3d 100644 (file)
@@ -147,8 +147,11 @@ void TraceModule::generate_params()
         { "output", Parameter::PT_ENUM, "stdout | syslog", nullptr,
           "output method for trace log messages" },
 
-        { "log_ntuple", Parameter::PT_BOOL, nullptr, "false",
-          "use extended trace output with n-tuple packet info" },
+        { "ntuple", Parameter::PT_BOOL, nullptr, "false",
+          "print packet n-tuple info with trace messages" },
+
+        { "timestamp", Parameter::PT_BOOL, nullptr, "false",
+          "print message timestamps with trace messages" },
 
         { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }
     };
@@ -189,9 +192,14 @@ bool TraceModule::set(const char* fqn, Value& v, SnortConfig*)
         }
         return true;
     }
-    else if ( v.is("log_ntuple") )
+    else if ( v.is("ntuple") )
+    {
+        trace_parser->get_trace_config().ntuple = v.get_bool();
+        return true;
+    }
+    else if ( v.is("timestamp") )
     {
-        trace_parser->get_trace_config().log_ntuple = v.get_bool();
+        trace_parser->get_trace_config().timestamp = v.get_bool();
         return true;
     }
     else if ( strstr(fqn, "trace.modules.") == fqn )
index d9a9715b6beacaf368b45f887367afe47ae2ede2..a57c5830e0225e1e6a27286a3c4c67ed1f413921 100644 (file)
@@ -45,11 +45,13 @@ static int clear(lua_State*);
 
 void TraceSwapParams::set_params(const Parameter* params)
 {
-    const Parameter* ntuple_params = Parameter::find(params, "log_ntuple");
+    const Parameter* ntuple_params = Parameter::find(params, "ntuple");
+    const Parameter* timestamp_params = Parameter::find(params, "timestamp");
     const Parameter* modules_params = Parameter::find(params, "modules");
     const Parameter* constraints_params = Parameter::find(params, "constraints");
 
     assert(ntuple_params);
+    assert(timestamp_params);
     assert(modules_params);
     assert(constraints_params);
 
@@ -61,12 +63,15 @@ void TraceSwapParams::set_params(const Parameter* params)
 
         *ntuple_params,
 
+        *timestamp_params,
+
         { nullptr, Parameter::PT_MAX, nullptr, nullptr, nullptr }
     };
 
     static const Command commands[] =
     {
-        { "set", set, trace_params, "set modules traces, constraints and log_ntuple option" },
+        { "set", set, trace_params,
+          "set modules traces, constraints, ntuple and timestamp options" },
 
         { "clear", clear, nullptr, "clear modules traces and constraints" },
 
@@ -83,15 +88,41 @@ const Command* TraceSwapParams::get_commands()
 const Parameter* TraceSwapParams::get_params()
 { return s_params; }
 
+struct LogParams
+{
+    bool set_traces;
+    bool set_constraints;
+    bool set_ntuple;
+    bool set_timestamp;
+
+    bool is_set() const
+    { return set_traces or set_constraints or set_ntuple or set_timestamp; }
+
+    void print_msg() const
+    {
+        if ( set_traces and set_constraints )
+            LogMessage("== set modules traces and constraints\n");
+        else if ( !is_set() )
+            LogMessage("== clear modules traces and constraints\n");
+        else if ( set_traces )
+            LogMessage("== set modules traces\n");
+        else if ( set_constraints )
+            LogMessage("== set constraints\n");
+
+        if ( set_ntuple )
+            LogMessage("== set ntuple option\n");
+
+        if ( set_timestamp )
+            LogMessage("== set timestamp option\n");
+    }
+};
+
 class TraceSwap : public AnalyzerCommand
 {
 public:
-    TraceSwap(TraceConfig* tc, bool set_traces = false, bool set_constraints = false,
-        bool set_ntuple = false)
+    TraceSwap(TraceConfig* tc, const LogParams& lp)
         : trace_config(tc),
-          is_set_ntuple(set_ntuple),
-          is_set_traces(set_traces),
-          is_set_constraints(set_constraints)
+          log_params(lp)
     { assert(trace_config); }
     ~TraceSwap() override;
 
@@ -99,14 +130,9 @@ public:
     const char* stringify() override
     { return "TRACE_SWAP"; }
 
-private:
-    void print_msg() const;
-
 private:
     TraceConfig* trace_config = nullptr;
-    bool is_set_ntuple;
-    bool is_set_traces;
-    bool is_set_constraints;
+    LogParams log_params;
 };
 
 TraceSwap::~TraceSwap()
@@ -116,7 +142,7 @@ TraceSwap::~TraceSwap()
     TraceApi::thread_reinit(trace_config);
     SnortConfig::get_main_conf()->set_overlay_trace_config(trace_config);
 
-    print_msg();
+    log_params.print_msg();
 }
 
 bool TraceSwap::execute(Analyzer&, void**)
@@ -124,25 +150,10 @@ bool TraceSwap::execute(Analyzer&, void**)
     // Update configuration for packet threads
     TraceApi::thread_reinit(trace_config);
 
-    print_msg();
+    log_params.print_msg();
     return true;
 }
 
-void TraceSwap::print_msg() const
-{
-    if ( is_set_traces and is_set_constraints )
-        LogMessage("== set modules traces and constraints\n");
-    else if ( !is_set_traces and !is_set_constraints and !is_set_ntuple )
-        LogMessage("== clear modules traces and constraints\n");
-    else if ( is_set_traces )
-        LogMessage("== set modules traces\n");
-    else if ( is_set_constraints )
-        LogMessage("== set constraints\n");
-
-    if ( is_set_ntuple )
-        LogMessage("== set log_ntuple option\n");
-}
-
 static int set(lua_State* L)
 {
     const SnortConfig* sc = SnortConfig::get_conf();
@@ -159,14 +170,6 @@ static int set(lua_State* L)
     TraceConfig* trace_config = new TraceConfig(sc->overlay_trace_config
         ? *sc->overlay_trace_config : *sc->trace_config);
 
-    TraceParser trace_parser(*trace_config);
-
-    const Parameter* params_tree = TraceSwapParams::get_params();
-    bool parse_err = false;
-    bool set_traces = false;
-    bool set_constraints = false;
-    bool set_ntuple = false;
-
     // Passed Lua entry check
     if ( lua_gettop(L) != 1 or !lua_istable(L, 1) )
     {
@@ -178,6 +181,11 @@ static int set(lua_State* L)
         return 0;
     }
 
+    TraceParser trace_parser(*trace_config);
+    const Parameter* params_tree = TraceSwapParams::get_params();
+    LogParams log_params{};
+    bool parse_err = false;
+
     // Outer table traversal
     lua_pushnil(L);
     while ( lua_next(L, 1) )
@@ -185,17 +193,35 @@ static int set(lua_State* L)
         const char* root_element_key = luaL_checkstring(L, -2);
         const Parameter* root_parameter = Parameter::find(params_tree, root_element_key);
 
-        // extended output switcher
+        // log n-tuple
         if ( !strcmp(root_element_key, params_tree[2].name) )
         {
             if ( lua_isboolean(L, -1) and root_parameter )
             {
-                set_ntuple = true;
-                trace_parser.get_trace_config().log_ntuple = bool(lua_toboolean(L, -1));
+                log_params.set_ntuple = true;
+                trace_parser.get_trace_config().ntuple = bool(lua_toboolean(L, -1));
+            }
+            else
+            {
+                LogMessage("== invalid value for option: %s\n", root_element_key);
+                parse_err = true;
+            }
+
+            lua_pop(L, 1);
+            continue;
+        }
+
+        // log time stamp
+        if ( !strcmp(root_element_key, params_tree[3].name) )
+        {
+            if ( lua_isboolean(L, -1) and root_parameter )
+            {
+                log_params.set_timestamp = true;
+                trace_parser.get_trace_config().timestamp = bool(lua_toboolean(L, -1));
             }
             else
             {
-                LogMessage("== invalid value is provided: %s\n", root_element_key);
+                LogMessage("== invalid value for option: %s\n", root_element_key);
                 parse_err = true;
             }
 
@@ -214,7 +240,7 @@ static int set(lua_State* L)
         // "modules" table traversal
         else if ( !strcmp(root_element_key, params_tree[0].name) )
         {
-            set_traces = true;
+            log_params.set_traces = true;
             trace_parser.clear_traces();
 
             const Parameter* modules_param = (const Parameter*)root_parameter->range;
@@ -288,7 +314,7 @@ static int set(lua_State* L)
         // "constraints" table traversal
         else if ( !strcmp(root_element_key, params_tree[1].name) )
         {
-            set_constraints = true;
+            log_params.set_constraints = true;
             trace_parser.clear_constraints();
 
             const Parameter* constraints_param = (const Parameter*)root_parameter->range;
@@ -327,18 +353,17 @@ static int set(lua_State* L)
 
     if ( !parse_err )
     {
-        if ( !set_traces and !set_constraints and !set_ntuple )
+        if ( !log_params.is_set() )
         {
             trace_parser.clear_traces();
             trace_parser.clear_constraints();
         }
 
-        if ( set_constraints )
+        if ( log_params.set_constraints )
             trace_parser.finalize_constraints();
 
         main_broadcast_command(new TraceSwap(
-            &trace_parser.get_trace_config(), set_traces, set_constraints, set_ntuple),
-            true);
+            &trace_parser.get_trace_config(), log_params), true);
     }
     else
         delete trace_config;
@@ -350,7 +375,7 @@ static int clear(lua_State*)
 {
     // Create an empty overlay TraceConfig
     // It will be set in a SnortConfig during TraceSwap execution and owned by it after
-    main_broadcast_command(new TraceSwap(new TraceConfig), true);
+    main_broadcast_command(new TraceSwap(new TraceConfig, {}), true);
     return 0;
 }