Merge pull request #2961 in SNORT/snort3 from ~BSACHDEV/snort3:smb_trace_infra to...

Squashed commit of the following:

commit 7351c4a1f14b9b7b2456064fb054e79082458829
Author: bsachdev <bsachdev@cisco.com>
Date:   Mon Jun 28 04:19:08 2021 -0400

    dce_smb: Added trace messages and multiple level logging for SMB module

    Signed-off-by: bsachdev <bsachdev@cisco.com>

diff --git a/src/service_inspectors/dce_rpc/dce_smb1.cc b/src/service_inspectors/dce_rpc/dce_smb1.cc
index 93af9db84fb37bf22b3870e34df7f03113b071ab..1265cf8f82622c8adf0879b2c7ecb3b56426a628 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb1.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb1.cc
@@ -34,7 +34,6 @@ using namespace snort;
 // debug stuff
 //-------------------------------------------------------------------------
 
-#ifdef DEBUG_MSGS
 static const char* smb_com_strings[SMB_MAX_NUM_COMS] =
 {
     "Create Directory",            // 0x00
@@ -297,7 +296,6 @@ static const char* smb_com_strings[SMB_MAX_NUM_COMS] =
 
 const char* get_smb_com_string(uint8_t b)
 { return smb_com_strings[b]; }
-#endif
 
 Dce2Smb1SessionData::Dce2Smb1SessionData(const Packet* p,
     const dce2SmbProtoConf* proto) : Dce2SmbSessionData(p, proto)
@@ -315,7 +313,7 @@ Dce2Smb1SessionData::Dce2Smb1SessionData(const Packet* p,
     ssd.max_file_depth = max_file_depth;
     ssd.sd = sd;
     ssd.policy = policy;
-    debug_logf(dce_smb_trace, p, "smb1 session created\n");
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, p, "smb1 session created\n");
     memory::MemoryCap::update_allocations(sizeof(*this));
 }
 

diff --git a/src/service_inspectors/dce_rpc/dce_smb2.cc b/src/service_inspectors/dce_rpc/dce_smb2.cc
index 0fba9cc5cc18fe2993bba63368d4383b0f7d5fb3..3b36190383fb995b05e6605c93754896cff0dbc9 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb2.cc
@@ -105,7 +105,7 @@ Dce2Smb2SessionData::Dce2Smb2SessionData(const Packet* p,
 {
     tcp_file_tracker = nullptr;
     flow_key = get_smb2_flow_key(tcp_flow->key);
-    debug_logf(dce_smb_trace, p, "smb2 session created\n");
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, p, "smb2 session created\n");
     memory::MemoryCap::update_allocations(sizeof(*this));
 }
 
@@ -203,7 +203,7 @@ void Dce2Smb2SessionData::process_command(const Smb2Hdr* smb_hdr,
         if (smb_data + SMB2_ ## cmd ## _ ## type ## _STRUC_SIZE - 1 > end) \
         { \
             dce2_smb_stats.v2_ ## counter ## _hdr_err++; \
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET, \
+            SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, GET_CURRENT_PACKET, \
                 "%s : smb data beyond end detected\n", \
                 smb2_command_string[command]); \
             return; \
@@ -215,7 +215,7 @@ void Dce2Smb2SessionData::process_command(const Smb2Hdr* smb_hdr,
         if (SMB2_COMMAND_TYPE(ERROR, RESPONSE) and Smb2Error(smb_hdr)) \
         { \
             dce2_smb_stats.v2_ ## counter ## _err_resp++; \
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_RESP: error\n", \
+            SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, GET_CURRENT_PACKET, "%s_RESP: error\n", \
                 smb2_command_string[command]); \
             return; \
         } \
@@ -224,14 +224,15 @@ void Dce2Smb2SessionData::process_command(const Smb2Hdr* smb_hdr,
 #define SMB2_HANDLE_INVALID_STRUC_SIZE(counter) \
     { \
         dce2_smb_stats.v2_ ## counter ## _inv_str_sz++; \
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s: invalid struct size\n", \
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL \
+           , GET_CURRENT_PACKET, "%s: invalid struct size\n", \
             smb2_command_string[command]); \
         return; \
     }
 
     uint16_t command = alignedNtohs(&(smb_hdr->command));
     uint64_t session_id = Smb2Sid(smb_hdr);
-    debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, GET_CURRENT_PACKET,
         "%s : flow %" PRIu32 " mid %" PRIu64 " sid %" PRIu64 " tid %" PRIu32 "\n",
         (command < SMB2_COM_MAX ? smb2_command_string[command] : "unknown"),
         flow_key, Smb2Mid(smb_hdr), session_id, Smb2Tid(smb_hdr));
@@ -258,7 +259,11 @@ void Dce2Smb2SessionData::process_command(const Smb2Hdr* smb_hdr,
                         p->flow->server_port , snort_protocol_id_smb, fd, false, true);
                 
                     if (result < 0)
+                    {
+                        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_CRITICAL_LEVEL, GET_CURRENT_PACKET,
+                            "Failed to create expected smb flow\n");
                         delete fd;
+                    }
                 }
             }
         }
@@ -460,7 +465,8 @@ void Dce2Smb2SessionData::process()
     // Check header length
     if (data_len < sizeof(NbssHdr) + SMB2_HEADER_LENGTH)
     {
-        debug_logf(dce_smb_trace, p, "Header error with data length %d\n",data_len);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_CRITICAL_LEVEL, 
+           p, "Header error with data length %d\n",data_len);
         dce2_smb_stats.v2_hdr_err++;
         return;
     }
@@ -488,7 +494,8 @@ void Dce2Smb2SessionData::process()
             {
                 dce_alert(GID_DCE2, DCE2_SMB_BAD_NEXT_COMMAND_OFFSET,
                     (dce2CommonStats*)&dce2_smb_stats, sd);
-                debug_logf(dce_smb_trace, p, "bad next command offset\n");
+                       SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, 
+                       TRACE_ERROR_LEVEL, p, "bad next command offset\n");
                 dce2_smb_stats.v2_bad_next_cmd_offset++;
                 return;
             }
@@ -501,7 +508,8 @@ void Dce2Smb2SessionData::process()
             if (compound_request_index > get_smb_max_compound())
             {
                 dce2_smb_stats.v2_cmpnd_req_lt_crossed++;
-                debug_logf(dce_smb_trace, p, "compound request limit"
+                       SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, 
+                           TRACE_INFO_LEVEL, p, "compound request limit"
                     " reached %" PRIu8 "\n",compound_request_index);
                 return;
             }
@@ -513,14 +521,14 @@ void Dce2Smb2SessionData::process()
         tcp_file_tracker_mutex.lock();
         if ( tcp_file_tracker and tcp_file_tracker->accepting_raw_data_from(flow_key))
         {
-            debug_logf(dce_smb_trace, p, "processing raw data for file id %" PRIu64 "\n",
+            SMB_DEBUG(dce_smb_trace,DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, p, "processing raw data for file id %" PRIu64 "\n",
                 tcp_file_tracker->get_file_id());
             tcp_file_tracker->process_data(flow_key, data_ptr, data_len);
             tcp_file_tracker->stop_accepting_raw_data_from(flow_key);
         }
         else
         {
-            debug_logf(dce_smb_trace, p, "not processing raw data\n");
+            SMB_DEBUG(dce_smb_trace,DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, p, "not processing raw data\n");
         }
         tcp_file_tracker_mutex.unlock();
     }

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_file.cc b/src/service_inspectors/dce_rpc/dce_smb2_file.cc
index c4e1e97001b15e85d41f34d321bc5ab724bccf1b..d71fc6e9276c48189711318996081ac85746f5b8 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_file.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb2_file.cc
@@ -84,6 +84,8 @@ std::pair<bool, Dce2Smb2SessionData*> Dce2Smb2FileTracker::update_processing_flo
             processing_flow = (Dce2Smb2SessionData*)current_flow_data->get_smb_session_data();
         }
         file_flow_key = processing_flow->get_flow_key();
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, GET_CURRENT_PACKET, 
+            "updating the processing flow key to %u\n", file_flow_key);
     }
     return std::make_pair(switched, processing_flow);
 }
@@ -101,7 +103,7 @@ void Dce2Smb2FileTracker::set_info(char* file_name_v, uint16_t name_len_v, uint6
     auto updated_flow = update_processing_flow();
     Flow* flow = updated_flow.second->get_tcp_flow();
     FileContext* file = get_smb_file_context(flow, file_name_hash, file_id, true);
-    debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "set file info: file size %"
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, GET_CURRENT_PACKET, "set file info: file size %"
         PRIu64 " fid %" PRIu64 " file_name_hash %" PRIu64 " file context "
         "%sfound\n", size_v, file_id, file_name_hash, (file ? "" : "not "));
     if (file)
@@ -186,11 +188,15 @@ bool Dce2Smb2FileTracker::process_data(const uint32_t current_flow_key, const ui
     }
 
     if (ignore)
+    {
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, p,
+            "file name not set , ignored\n");
         return true;
+    }
 
     if (file_size and file_offset > file_size)
     {
-        debug_logf(dce_smb_trace, p, "file_process: bad offset\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, p, "file_process: bad offset\n");
         dce_alert(GID_DCE2, DCE2_SMB_INVALID_FILE_OFFSET, (dce2CommonStats*)
             &dce2_smb_stats, *(current_flow->get_dce2_session_data()));
     }
@@ -198,13 +204,16 @@ bool Dce2Smb2FileTracker::process_data(const uint32_t current_flow_key, const ui
     auto updated_flow = update_processing_flow(current_flow);
     Dce2Smb2SessionData* processing_flow = updated_flow.second;
 
-    debug_logf(dce_smb_trace, p, "file_process fid %" PRIu64 " data_size %"
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, p,"file_process fid %" PRIu64 " data_size %"
         PRIu32 " offset %" PRIu64 "\n", file_id, data_size, file_offset);
 
     FileFlows* file_flows = FileFlows::get_file_flows(processing_flow->get_tcp_flow());
 
     if (!file_flows)
+    {
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_CRITICAL_LEVEL, p, "file_flows not found\n");
         return true;
+    }
 
     if (updated_flow.first)
     {
@@ -220,7 +229,7 @@ bool Dce2Smb2FileTracker::process_data(const uint32_t current_flow_key, const ui
     process_file_mutex.unlock();
     if (!continue_processing)
     {
-        debug_logf(dce_smb_trace, p, "file_process completed\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, p, "file_process completed\n");
         return false;
     }
 
@@ -235,7 +244,7 @@ Dce2Smb2FileTracker::~Dce2Smb2FileTracker(void)
 {
     if (smb_module_is_up)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "file tracker %" PRIu64
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET, "file tracker %" PRIu64
             " file name hash %" PRIu64 " terminating\n", file_id, file_name_hash);
     }
 

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_file.h b/src/service_inspectors/dce_rpc/dce_smb2_file.h
index 55baa7375efee181c70bb499ed5318d00676bacf..62ae349366efaab48e40a1367ce0d54a4e27267b 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_file.h
+++ b/src/service_inspectors/dce_rpc/dce_smb2_file.h
@@ -47,7 +47,7 @@ public:
         file_id(file_idv), file_size(0), file_name_hash(0), file_name(nullptr),
         direction(FILE_DOWNLOAD), parent_tree(p_tree)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET,
             "file tracker %" PRIu64 " created\n", file_id);
     }
 

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_request.h b/src/service_inspectors/dce_rpc/dce_smb2_request.h
index e224fb84dbdac1cff357e3d20ca7413b52f9bd13..84db1059124ba345ddbd9d917d8d68b53fb15487 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_request.h
+++ b/src/service_inspectors/dce_rpc/dce_smb2_request.h
@@ -37,20 +37,20 @@ public:
     Dce2Smb2RequestTracker(uint64_t file_id_v, uint64_t offset_v = 0)
         : fname(nullptr), fname_len(0), file_id(file_id_v), offset(offset_v)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "request tracker created\n");
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET, "request tracker created\n");
     }
 
     Dce2Smb2RequestTracker(char* fname_v, uint16_t fname_len_v)
         : fname(fname_v), fname_len(fname_len_v), file_id(0), offset(0)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "request tracker created\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET, "request tracker created\n");
     }
 
     ~Dce2Smb2RequestTracker()
     {
         if (smb_module_is_up)
         {
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "request tracker terminating\n");
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET, "request tracker terminating\n");
         }
         if (fname)
             snort_free(fname);

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_session.cc b/src/service_inspectors/dce_rpc/dce_smb2_session.cc
index d823fe818f122b4a28ef813fc11297ca9d9365ec..19eab6bba47e1e43b20bc41bd6bdb02cf5eaa345 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_session.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb2_session.cc
@@ -98,13 +98,15 @@ void Dce2Smb2SessionTracker::process(const uint16_t command, uint8_t command_typ
     case SMB2_COM_CREATE:
         if (!tree and SMB2_CMD_TYPE_REQUEST == command_type)
         {
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, 
+                   TRACE_INFO_LEVEL, GET_CURRENT_PACKET,
                 "%s_REQ: mid-stream session detected\n",
                 smb2_command_string[command]);
             tree = connect_tree(tree_id, current_flow_key);
             if (!tree)
             {
-                debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+                SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID,
+                    TRACE_INFO_LEVEL, GET_CURRENT_PACKET,
                     "%s_REQ: insert tree tracker failed\n",
                     smb2_command_string[command]);
             }
@@ -115,7 +117,8 @@ void Dce2Smb2SessionTracker::process(const uint16_t command, uint8_t command_typ
             tree->process(command, command_type, smb_header, end, current_flow_key);
         else
         {
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+            SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, 
+                TRACE_ERROR_LEVEL, GET_CURRENT_PACKET,
                 "%s: tree tracker missing\n", smb2_command_string[command]);
             dce2_smb_stats.v2_tree_ignored++;
         }
@@ -131,7 +134,8 @@ Dce2Smb2TreeTracker* Dce2Smb2SessionTracker::connect_tree(const uint32_t tree_id
         (-1 == current_flow->get_max_file_depth()) and
         (-1 == current_flow->get_smb_file_depth()))
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "Not inserting TID (%u) "
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, 
+           TRACE_INFO_LEVEL, GET_CURRENT_PACKET, "Not inserting TID (%u) "
             "because it's not IPC and not inspecting normal file data.\n", tree_id);
         dce2_smb_stats.v2_tree_cnct_ignored++;
         return nullptr;
@@ -189,7 +193,8 @@ Dce2Smb2SessionTracker::~Dce2Smb2SessionTracker(void)
 {
     if (smb_module_is_up)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, 
+               TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET,
             "session tracker %" PRIu64 " terminating\n", session_id);
     }
 

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_session.h b/src/service_inspectors/dce_rpc/dce_smb2_session.h
index a96153c46eb070cec2a7357df0851d3ba41c9fbc..ce31f10d1f311f03e6ce01c6cd232762cb450ada 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_session.h
+++ b/src/service_inspectors/dce_rpc/dce_smb2_session.h
@@ -36,8 +36,8 @@ public:
         session_id = key.sid;
         session_key = key;
         reload_prune = false;
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "session tracker %" PRIu64
-            " created\n", session_id);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, GET_CURRENT_PACKET, 
+            "session tracker %" PRIu64 "created\n", session_id);
     }
 
     ~Dce2Smb2SessionTracker();

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_tree.cc b/src/service_inspectors/dce_rpc/dce_smb2_tree.cc
index 57582e363c41e173dfe70649434b1b0003ccae76..d143e0d9f376729c15ae0c6acbedc4bbfd8cd10b 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_tree.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb2_tree.cc
@@ -113,13 +113,15 @@ void Dce2Smb2TreeTracker::process_set_info_request(const Smb2Hdr* smb_header)
         else
         {
             dce2_smb_stats.v2_stinf_req_ftrkr_misng++;
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_REQ: ftracker missing\n",
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, 
+                GET_CURRENT_PACKET, "%s_REQ: ftracker missing\n",
                 smb2_command_string[SMB2_COM_SET_INFO]);
         }
     }
     else
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_REQ: header error\n",
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL, 
+            GET_CURRENT_PACKET, "%s_REQ: header error\n",
             smb2_command_string[SMB2_COM_SET_INFO]);
         dce2_smb_stats.v2_stinf_req_hdr_err++;
     }
@@ -135,7 +137,8 @@ void Dce2Smb2TreeTracker::process_close_request(const Smb2Hdr* smb_header,
     if (!file_tracker)
     {
         dce2_smb_stats.v2_cls_req_ftrkr_misng++;
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_REQ: ftracker missing %" PRIu64 "\n",
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, 
+               GET_CURRENT_PACKET, "%s_REQ: ftracker missing %" PRIu64 "\n",
             smb2_command_string[SMB2_COM_CLOSE], file_id);
         return;
     }
@@ -201,8 +204,9 @@ void Dce2Smb2TreeTracker::process_create_response(const uint64_t message_id,
         file_size = alignedNtohq((const uint64_t*)(&(create_res_hdr->end_of_file)));
     if (create_res_hdr->file_attributes & SMB2_CREATE_RESPONSE_DIRECTORY)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_RESP: not processing for directory\n",
-            smb2_command_string[SMB2_COM_CREATE]);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, 
+            GET_CURRENT_PACKET, "%s_RESP: not processing for directory\n",
+        smb2_command_string[SMB2_COM_CREATE]);
         close_file(file_id);
     }
     else
@@ -222,7 +226,7 @@ void Dce2Smb2TreeTracker::process_create_response(const uint64_t message_id,
         }
         else
         {
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_RESP: req tracker missing\n",
+            SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, GET_CURRENT_PACKET, "%s_RESP: req tracker missing\n",
                 smb2_command_string[SMB2_COM_CREATE]);
             dce2_smb_stats.v2_crt_rtrkr_misng++;
         }
@@ -236,8 +240,9 @@ void Dce2Smb2TreeTracker::process_create_request(const uint64_t message_id,
     const Smb2CreateRequestHdr* create_req_hdr = (const Smb2CreateRequestHdr*)smb_data;
     if (alignedNtohs(&(create_req_hdr->name_offset)) <= SMB2_HEADER_LENGTH)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_REQ: name_offset %" PRIu16 "\n",
-            smb2_command_string[SMB2_COM_CREATE], create_req_hdr->name_offset);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            GET_CURRENT_PACKET, "%s_REQ: name_offset %" PRIu16 "\n",
+        smb2_command_string[SMB2_COM_CREATE], create_req_hdr->name_offset);
         dce2_smb_stats.v2_crt_req_hdr_err++;
         return;
     }
@@ -247,7 +252,7 @@ void Dce2Smb2TreeTracker::process_create_request(const uint64_t message_id,
     if (!file_name_size or (file_name_offset >= end) or
         (file_name_offset + file_name_size > end))
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL, GET_CURRENT_PACKET,
             "%s_REQ: invalid file name data seen with size %" PRIu16 "\n",
             smb2_command_string[SMB2_COM_CREATE], file_name_size);
         dce2_smb_stats.v2_crt_inv_file_data++;
@@ -260,7 +265,8 @@ void Dce2Smb2TreeTracker::process_create_request(const uint64_t message_id,
     Dce2Smb2RequestTracker* create_request = new Dce2Smb2RequestTracker(file_name, name_len);
     if (!store_request(message_id, current_flow_key, create_request))
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "SMB2_COM_CREATE_REQ: store failed\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_CRITICAL_LEVEL,
+            GET_CURRENT_PACKET, "SMB2_COM_CREATE_REQ: store failed\n");
         delete create_request;
     }
     //check if file_id is available form a durable reconnect request.
@@ -269,6 +275,8 @@ void Dce2Smb2TreeTracker::process_create_request(const uint64_t message_id,
     uint64_t file_id = get_durable_file_id(create_req_hdr, end);
     if (file_id)
     {
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+            GET_CURRENT_PACKET, "requested file_id %lu\n", file_id);
         Dce2Smb2FileTracker* file_tracker = find_file(file_id);
         if (!file_tracker)
         {
@@ -290,16 +298,18 @@ void Dce2Smb2TreeTracker::process_read_response(const uint64_t message_id,
     Dce2Smb2RequestTracker* read_request = find_request(message_id, current_flow_key);
     if (!read_request)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "SMB2_COM_READ_RESP: request tracker missing\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            GET_CURRENT_PACKET, "SMB2_COM_READ_RESP: request tracker missing\n");
         dce2_smb_stats.v2_read_rtrkr_misng++;
         return;
     }
+
     uint16_t data_offset = alignedNtohs((const uint16_t*)(&(read_resp_hdr->data_offset)));
     Dce2Smb2SessionData* current_flow = parent_session->get_flow(current_flow_key);
     if (data_offset + (const uint8_t*)smb_header > end)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "SMB2_COM_READ_RESP: bad offset\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            GET_CURRENT_PACKET, "SMB2_COM_READ_RESP: bad offset\n");
         if (current_flow)
             dce_alert(GID_DCE2, DCE2_SMB_BAD_OFF, (dce2CommonStats*)&dce2_smb_stats,
                 *current_flow->get_dce2_session_data());
@@ -324,8 +334,8 @@ void Dce2Smb2TreeTracker::process_read_response(const uint64_t message_id,
     }
     else
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "SMB2_COM_READ_RESP: file tracker missing\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+               GET_CURRENT_PACKET, "SMB2_COM_READ_RESP: file tracker missing\n");
     }
 }
 
@@ -339,21 +349,22 @@ void Dce2Smb2TreeTracker::process_read_request(const uint64_t message_id,
     Dce2Smb2RequestTracker* read_request = new Dce2Smb2RequestTracker(file_id, offset);
     if (!store_request(message_id, current_flow_key, read_request))
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "SMB2_COM_READ_REQ: store failed\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_CRITICAL_LEVEL,
+               GET_CURRENT_PACKET, "SMB2_COM_READ_REQ: store failed\n");
         delete read_request;
     }
     Dce2Smb2FileTracker* file_tracker = find_file(file_id);
     Dce2Smb2SessionData* current_flow = parent_session->get_flow(current_flow_key);
     if (file_tracker)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "SMB2_COM_READ_REQ: start accepting Raw Data\n");
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+            GET_CURRENT_PACKET, "SMB2_COM_READ_REQ: start accepting Raw Data\n");
         file_tracker->accept_raw_data_from(current_flow,offset);
     }
     else
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "SMB2_COM_READ_REQ: file tracker missing\n");
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            GET_CURRENT_PACKET, "SMB2_COM_READ_REQ: file tracker missing\n");
     }
 }
 
@@ -367,6 +378,8 @@ void Dce2Smb2TreeTracker::process_write_request(const uint64_t message_id,
     if ((alignedNtohs((const uint16_t*)(&(write_req_hdr->data_offset))) +
         (const uint8_t*)smb_header > end) and current_flow)
     {
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            GET_CURRENT_PACKET, "SMB2_COM_WRITE_REQ: bad offset\n");
         dce_alert(GID_DCE2, DCE2_SMB_BAD_OFF, (dce2CommonStats*)&dce2_smb_stats,
             *current_flow->get_dce2_session_data());
     }
@@ -374,7 +387,8 @@ void Dce2Smb2TreeTracker::process_write_request(const uint64_t message_id,
     Dce2Smb2RequestTracker* write_request = new Dce2Smb2RequestTracker(file_id);
     if (!store_request(message_id, current_flow_key, write_request))
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "SMB2_COM_WRITE_REQ: store failed\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+               GET_CURRENT_PACKET, "SMB2_COM_WRITE_REQ: store failed\n");
         delete write_request;
     }
     const uint8_t* file_data = (const uint8_t*)write_req_hdr + SMB2_WRITE_REQUEST_STRUC_SIZE - 1;
@@ -398,8 +412,8 @@ void Dce2Smb2TreeTracker::process_write_request(const uint64_t message_id,
     }
     else
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "SMB2_COM_WRITE_REQ: file tracker missing\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+               GET_CURRENT_PACKET,"SMB2_COM_WRITE_REQ: file tracker missing\n");
     }
 }
 
@@ -431,8 +445,8 @@ void Dce2Smb2TreeTracker::process(uint16_t command, uint8_t command_type,
     if (SMB2_CMD_TYPE_REQUEST == command_type and current_flow and
         pending_requests >= current_flow->get_max_outstanding_requests())
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "%s_REQ: max req exceeded\n", smb2_command_string[command]);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+               GET_CURRENT_PACKET, "%s_REQ: max req exceeded\n", smb2_command_string[command])
         dce_alert(GID_DCE2, DCE2_SMB_MAX_REQS_EXCEEDED, (dce2CommonStats*)&dce2_smb_stats,
             *current_flow->get_dce2_session_data());
         return;
@@ -446,15 +460,15 @@ void Dce2Smb2TreeTracker::process(uint16_t command, uint8_t command_type,
         if (SMB2_CMD_TYPE_ERROR_RESPONSE == command_type)
         {
             dce2_smb_stats.v2_crt_err_resp++;
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-                "%s_RESP: error\n", smb2_command_string[command]);
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                   GET_CURRENT_PACKET, "%s_RESP: error\n", smb2_command_string[command]);
         }
         else if (SMB2_CMD_TYPE_REQUEST == command_type)
         {
             if (SMB2_SHARE_TYPE_DISK != share_type)
             {
-                debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "%s_REQ:"
-                    "processed for ipc share\n", smb2_command_string[command]);
+                       SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+                           GET_CURRENT_PACKET, "%s_REQ: processed for ipc share\n", smb2_command_string[command]);
                 dce2_smb_stats.v2_crt_req_ipc++;
             }
             process_create_request(message_id, current_flow_key, smb_header, end);
@@ -472,8 +486,8 @@ void Dce2Smb2TreeTracker::process(uint16_t command, uint8_t command_type,
         if (SMB2_CMD_TYPE_ERROR_RESPONSE == command_type)
         {
             dce2_smb_stats.v2_read_err_resp++;
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-                "%s_RESP: error\n", smb2_command_string[command]);
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                   GET_CURRENT_PACKET, "%s_RESP: error\n", smb2_command_string[command]);
             Dce2Smb2RequestTracker* request = find_request(message_id, current_flow_key);
             if (request)
                 close_file(request->get_file_id());
@@ -487,8 +501,8 @@ void Dce2Smb2TreeTracker::process(uint16_t command, uint8_t command_type,
         if (SMB2_CMD_TYPE_ERROR_RESPONSE == command_type)
         {
             dce2_smb_stats.v2_wrt_err_resp++;
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-                "%s_RESP: error\n", smb2_command_string[command]);
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                GET_CURRENT_PACKET, "%s_RESP: error\n", smb2_command_string[command]);
             Dce2Smb2RequestTracker* request = find_request(message_id, current_flow_key);
             if (request)
                 close_file(request->get_file_id());
@@ -499,8 +513,8 @@ void Dce2Smb2TreeTracker::process(uint16_t command, uint8_t command_type,
     case SMB2_COM_IOCTL:
         if (SMB2_CMD_TYPE_ERROR_RESPONSE == command_type)
         {
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-                "%s_RESP: error\n", smb2_command_string[command]);
+               SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                GET_CURRENT_PACKET, "%s_RESP: error\n", smb2_command_string[command]);
         }
         else if (SMB2_SHARE_TYPE_DISK != share_type)
         {
@@ -516,8 +530,8 @@ Dce2Smb2TreeTracker::~Dce2Smb2TreeTracker(void)
 {
     if (smb_module_is_up)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "tree tracker %" PRIu32 " terminating\n",
-            tree_id);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+               GET_CURRENT_PACKET, "tree tracker %" PRIu32 " terminating\n", tree_id);
     }
 
     if (co_tracker != nullptr)
@@ -533,15 +547,15 @@ Dce2Smb2TreeTracker::~Dce2Smb2TreeTracker(void)
     {
         if (smb_module_is_up)
         {
-            debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-                "cleanup pending requests for below MIDs:\n");
+            SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+                   GET_CURRENT_PACKET, "cleanup pending requests for below MIDs:\n");
         }
         for (auto it_request : active_requests)
         {
             if (smb_module_is_up)
             {
-                debug_logf(dce_smb_trace, GET_CURRENT_PACKET, "mid %" PRIu64 "\n",
-                    it_request.first.mid);
+                       SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+                           GET_CURRENT_PACKET, "mid %" PRIu64 "\n", it_request.first.mid);
             }
             delete it_request.second;
         }

diff --git a/src/service_inspectors/dce_rpc/dce_smb2_tree.h b/src/service_inspectors/dce_rpc/dce_smb2_tree.h
index 9cc8b46f2b91e349eb813cf5b7ac0ab043414d2b..17bebb06e70a423025731df3eca3023e2a71ef6b 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb2_tree.h
+++ b/src/service_inspectors/dce_rpc/dce_smb2_tree.h
@@ -43,8 +43,8 @@ public:
     Dce2Smb2TreeTracker(uint32_t tree_id_v, Dce2Smb2SessionTracker* p_session, uint8_t sharetype)
         : tree_id(tree_id_v), share_type(sharetype), parent_session(p_session)
     {
-        debug_logf(dce_smb_trace, GET_CURRENT_PACKET,
-            "tree tracker %" PRIu32 " created\n", tree_id);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+               GET_CURRENT_PACKET, "tree tracker %" PRIu32 " created\n", tree_id);
         if (share_type != SMB2_SHARE_TYPE_DISK)
         {
             co_tracker = (DCE2_CoTracker*)snort_calloc(sizeof(DCE2_CoTracker));

diff --git a/src/service_inspectors/dce_rpc/dce_smb_common.h b/src/service_inspectors/dce_rpc/dce_smb_common.h
index 23746949c864ec268af94e138697b573e4a79884..de8273fea1163e4ef8ead70c4e03054697f322c2 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb_common.h
+++ b/src/service_inspectors/dce_rpc/dce_smb_common.h
@@ -36,6 +36,9 @@
 #define DCE2_SMB_NAME "dce_smb"
 #define DCE2_SMB_HELP "dce over smb inspection"
 
+#define SMB_DEBUG(module_name, module_id, log_level, p, ...) \
+    trace_logf(log_level, module_name , module_id, p, __VA_ARGS__);
+
 #define DCE2_SMB_ID   0xff534d42  /* \xffSMB */
 #define DCE2_SMB2_ID  0xfe534d42  /* \xfeSMB */
 #define DCE2_SMB_ID_SIZE 4

diff --git a/src/service_inspectors/dce_rpc/dce_smb_inspector.cc b/src/service_inspectors/dce_rpc/dce_smb_inspector.cc
index 174b81a867b8f5e2e0d212900cc6027f5dd1e88e..1ce2430b23caf72dc7aabf98a4a7115280502160 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb_inspector.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb_inspector.cc
@@ -89,7 +89,8 @@ void Dce2Smb::eval(Packet* p)
     }
     else
     {
-        debug_logf(dce_smb_trace, p, "non-smb packet detected\n");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+               p, "non-smb packet detected with dsize as %u\n", p->dsize);
     }
 }
 

diff --git a/src/service_inspectors/dce_rpc/dce_smb_module.cc b/src/service_inspectors/dce_rpc/dce_smb_module.cc
index 881050c2bbb095f8cc250d85cccb4ce54c59f3bd..33cc952ba362a5be67b140a227680de55720ef19 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb_module.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb_module.cc
@@ -335,12 +335,8 @@ void Dce2SmbModule::set_trace(const Trace* trace) const
 
 const TraceOption* Dce2SmbModule::get_trace_options() const
 {
-#ifndef DEBUG_MSGS
-    return nullptr;
-#else
     static const TraceOption dce_smb_trace_options(nullptr, 0, nullptr);
     return &dce_smb_trace_options;
-#endif
 }
 
 const RuleMap* Dce2SmbModule::get_rules() const

diff --git a/src/service_inspectors/dce_rpc/dce_smb_paf.cc b/src/service_inspectors/dce_rpc/dce_smb_paf.cc
index 7fac8dc58cbd8bc542868b01610749425a09a5ca..7b75b438b909712007595d9ee4a8b8d9f76b04d8 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb_paf.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb_paf.cc
@@ -190,6 +190,9 @@ StreamSplitter::Status Dce2SmbSplitter::scan(
     uint32_t flags, uint32_t* fp)
 {
     DCE2_PafSmbData* pfdata = &state;
-    return dce2_smb_paf(pfdata, pkt->flow, data, len, flags, fp);
+    StreamSplitter::Status ps =  dce2_smb_paf(pfdata, pkt->flow, data, len, flags, fp);
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL, pkt,
+        "Dce2SmbSplitter scan with length %u and status %d\n", len, ps);
+    return ps;
 }
 

diff --git a/src/service_inspectors/dce_rpc/dce_smb_transaction.cc b/src/service_inspectors/dce_rpc/dce_smb_transaction.cc
index b73ea9d569b161d070a6815d270e72a478f2e73b..3e363dc77dc2b80f92646f0e665c3498395a0d32 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb_transaction.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb_transaction.cc
@@ -528,7 +528,8 @@ static DCE2_Ret DCE2_SmbUpdateTransRequest(DCE2_SmbSsnData* ssd,
             if (DCE2_SsnIsWindowsPolicy(&ssd->sd)
                 && ssd->cur_rtracker->ftracker->fp_byte_mode)
             {
-                debug_log(dce_smb_trace, DetectionEngine::get_current_packet(),
+                SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+                    DetectionEngine::get_current_packet(),
                     "Pipe is in byte mode - TRANS_TRANSACT_NMPIPE won't work\n");
                 return DCE2_RET__ERROR;
             }
@@ -589,7 +590,8 @@ static DCE2_Ret DCE2_SmbUpdateTransRequest(DCE2_SmbSsnData* ssd,
             && (DCE2_SmbTransactionGetName(nb_ptr, nb_len,
             byte_count, SmbUnicode(smb_hdr)) != DCE2_RET__SUCCESS))
         {
-            debug_log(dce_smb_trace, DetectionEngine::get_current_packet(),
+            SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+                DetectionEngine::get_current_packet(),
                 "Failed to validate pipe name for Samba.\n");
             return DCE2_RET__ERROR;
         }
@@ -1073,8 +1075,8 @@ DCE2_Ret DCE2_SmbTransaction(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr,
     if (DCE2_ComInfoIsRequest(com_info)
         && !DCE2_SmbIsTransactionComplete(ttracker))
     {
-        debug_log(dce_smb_trace, DetectionEngine::get_current_packet(),
-            "Got new transaction request "
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            DetectionEngine::get_current_packet(), "Got new transaction request "
             "that matches an in progress transaction - not inspecting.\n");
         return DCE2_RET__ERROR;
     }
@@ -1083,7 +1085,8 @@ DCE2_Ret DCE2_SmbTransaction(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr,
     if (DCE2_ComInfoIsRequest(com_info)
         && (DCE2_ComInfoWordCount(com_info) != 16))
     {
-        debug_log(dce_smb_trace, DetectionEngine::get_current_packet(),
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            DetectionEngine::get_current_packet(),
             "\\PIPE\\LANMAN request - not inspecting\n");
         return DCE2_RET__IGNORE;
     }
@@ -1196,9 +1199,9 @@ DCE2_Ret DCE2_SmbTransaction2(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr,
     if (DCE2_ComInfoIsRequest(com_info)
         && !DCE2_SmbIsTransactionComplete(ttracker))
     {
-        debug_log(dce_smb_trace, DetectionEngine::get_current_packet(),
-            "Got new transaction request "
-            "that matches an in progress transaction - not inspecting.\n");
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+             DetectionEngine::get_current_packet(), "Got new transaction request "
+             "that matches an in progress transaction - not inspecting.\n");
         return DCE2_RET__ERROR;
     }
 
@@ -1455,8 +1458,8 @@ DCE2_Ret DCE2_SmbNtTransact(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr,
     if (DCE2_ComInfoIsRequest(com_info)
         && !DCE2_SmbIsTransactionComplete(ttracker))
     {
-        debug_log(dce_smb_trace, DetectionEngine::get_current_packet(),
-            "Got new transaction request "
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+            DetectionEngine::get_current_packet(), "Got new transaction request "
             "that matches an in progress transaction - not inspecting.\n");
         return DCE2_RET__ERROR;
     }

diff --git a/src/service_inspectors/dce_rpc/dce_smb_utils.cc b/src/service_inspectors/dce_rpc/dce_smb_utils.cc
index 6671637130d3feb7e557c89a9a0e82183b8c515c..54046c2410765efa68603f53c09cee2f6d992e35 100644 (file)
--- a/src/service_inspectors/dce_rpc/dce_smb_utils.cc
+++ b/src/service_inspectors/dce_rpc/dce_smb_utils.cc
@@ -794,8 +794,8 @@ void DCE2_SmbInsertTid(DCE2_SmbSsnData* ssd,
     if ( !is_ipc and
         ssd->max_file_depth == -1 and DCE2_ScSmbFileDepth((dce2SmbProtoConf*)ssd->sd.config) == -1 )
     {
-        debug_logf(dce_smb_trace, DetectionEngine::get_current_packet(),
-            "Not inserting TID (%hu) "
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+               DetectionEngine::get_current_packet(), "Not inserting TID (%hu) "
             "because it's not IPC and not inspecting normal file data.\n", tid);
         return;
     }
@@ -1504,8 +1504,9 @@ static DCE2_Ret DCE2_SmbFileAPIProcess(DCE2_SmbSsnData* ssd,
     if (!file_flows->file_process(p, data_ptr, (int)data_len, position, upload,
         ftracker->file_name_hash))
     {
-        debug_logf(dce_smb_trace, p, "File API returned FAILURE for (0x%02X) %s\n",
-            ftracker->fid_v1, upload ? "UPLOAD" : "DOWNLOAD");
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_ERROR_LEVEL,
+               p, "File API returned FAILURE for (0x%02X) %s\n",
+               ftracker->fid_v1, upload ? "UPLOAD" : "DOWNLOAD");
 
         // Failure.  Abort tracking this file under file API
         return DCE2_RET__ERROR;
@@ -1756,10 +1757,10 @@ void DCE2_SmbProcessFileData(DCE2_SmbSsnData* ssd,
             }
             else if (ftracker->ff_file_offset < ftracker->ff_bytes_processed)
             {
-                debug_logf(dce_smb_trace, DetectionEngine::get_current_packet(),
-                    "File offset %" PRIu64 " is less than bytes processed %"
-                    PRIu64 " - aborting.\n", ftracker->ff_file_offset,
-                    ftracker->ff_bytes_processed);
+                       SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                       DetectionEngine::get_current_packet(), "File offset %" PRIu64 " is less than bytes processed %"
+                           PRIu64 " - aborting.\n", ftracker->ff_file_offset,
+                           ftracker->ff_bytes_processed);
 
                 DCE2_SmbAbortFileAPI(ssd);
                 DCE2_SmbSetNewFileAPIFileTracker(ssd);

diff --git a/src/service_inspectors/dce_rpc/smb_message.cc b/src/service_inspectors/dce_rpc/smb_message.cc
index ade7611e01935b71dd10ad10a6501bcc2e69b743..5a0074c7e1d93449e828a3229973f0556dd7624b 100644 (file)
--- a/src/service_inspectors/dce_rpc/smb_message.cc
+++ b/src/service_inspectors/dce_rpc/smb_message.cc
@@ -804,8 +804,9 @@ static void DCE2_SmbProcessCommand(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr
         com_info.cmd_size = 0;
         com_info.byte_count = 0;
         DCE2_SmbCheckCommand(ssd, smb_hdr, smb_com, nb_ptr, nb_len, com_info);
-        debug_logf(dce_smb_trace, DetectionEngine::get_current_packet(),
-            "Processing command: %s (0x%02X)\n", get_smb_com_string(smb_com), smb_com);
+           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+               DetectionEngine::get_current_packet(),
+               "Processing command: %s (0x%02X)\n", get_smb_com_string(smb_com), smb_com);
 
         // Note that even if the command shouldn't be processed, some of
         // the command functions need to know and do cleanup or some other
@@ -829,8 +830,9 @@ static void DCE2_SmbProcessCommand(DCE2_SmbSsnData* ssd, const SmbNtHdr* smb_hdr
         if (smb_com2 == SMB_COM_NO_ANDX_COMMAND)
             break;
 
-        debug_logf(dce_smb_trace, DetectionEngine::get_current_packet(),
-            "Chained SMB command: %s\n", get_smb_com_string(smb_com2));
+        SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_DEBUG_LEVEL,
+           DetectionEngine::get_current_packet(),
+           "Chained SMB command: %s\n", get_smb_com_string(smb_com2));
 
         num_chained++;
         if (DCE2_ScSmbMaxChain((dce2SmbProtoConf*)ssd->sd.config) &&
@@ -1033,8 +1035,9 @@ static DCE2_SmbRequestTracker* DCE2_SmbInspect(DCE2_SmbSsnData* ssd, const SmbNt
 
     if (smb_com < 0 or smb_com > 255) return nullptr;
 
-    debug_logf(dce_smb_trace, DetectionEngine::get_current_packet(),
-        "SMB command: %s (0x%02X)\n", get_smb_com_string(smb_com), smb_com);
+    SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+        DetectionEngine::get_current_packet(),
+       "SMB command: %s (0x%02X)\n", get_smb_com_string(smb_com), smb_com);
 
     if (smb_com_funcs[smb_com] == nullptr)
     {
@@ -1554,7 +1557,8 @@ void DCE2_Smb1Process(DCE2_SmbSsnData* ssd)
                 if (!DCE2_GcIsLegacyMode((dce2SmbProtoConf*)ssd->sd.config))
                 {
                     // Upgrade connection to SMBv2
-                    debug_log(dce_smb_trace, p, "upgrading to smb2 session\n");
+                           SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                               p, "upgrading to smb2 session\n");
                     Dce2SmbFlowData* fd = (Dce2SmbFlowData*)p->flow->get_flow_data(
                         Dce2SmbFlowData::inspector_id);
                     if (fd)
@@ -1572,7 +1576,8 @@ void DCE2_Smb1Process(DCE2_SmbSsnData* ssd)
             rtracker = DCE2_SmbInspect(ssd, smb_hdr);
             if (rtracker == nullptr)
             {
-                debug_log(dce_smb_trace, p, "Not inspecting SMB packet.\n");
+                       SMB_DEBUG(dce_smb_trace, DEFAULT_TRACE_OPTION_ID, TRACE_INFO_LEVEL,
+                           p, "Not inspecting SMB packet.\n");
 
                 if (DCE2_BufferIsEmpty(*seg_buf))
                 {

diff --git a/src/trace/trace.h b/src/trace/trace.h
index edc173d74dd28eab61428cfde2c7563945928223..66a9479bb6fa67f293e183a762d52403f9db3f97 100644 (file)
--- a/src/trace/trace.h
+++ b/src/trace/trace.h
@@ -27,6 +27,10 @@
 #include "main/thread.h"
 
 #define DEFAULT_TRACE_LOG_LEVEL 1
+#define TRACE_CRITICAL_LEVEL 2
+#define TRACE_ERROR_LEVEL 3
+#define TRACE_INFO_LEVEL 6
+#define TRACE_DEBUG_LEVEL 7
 #define DEFAULT_TRACE_OPTION_ID 0
 #define DEFAULT_TRACE_OPTION_NAME "all"