From: Lokesh Bevinamarad (lbevinam) Date: Wed, 7 Jul 2021 16:39:03 +0000 (+0000) Subject: Merge pull request #2961 in SNORT/snort3 from ~BSACHDEV/snort3:smb_trace_infra to... X-Git-Tag: 3.1.8.0~9 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=eac351628f6c2d9ea0ecc27f060cc2cf574b2e80;p=thirdparty%2Fsnort3.git Merge pull request #2961 in SNORT/snort3 from ~BSACHDEV/snort3:smb_trace_infra to master Squashed commit of the following: commit 7351c4a1f14b9b7b2456064fb054e79082458829 Author: bsachdev 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 --- diff --git a/src/service_inspectors/dce_rpc/dce_smb1.cc b/src/service_inspectors/dce_rpc/dce_smb1.cc index 93af9db84..1265cf8f8 100644 --- 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 0fba9cc5c..3b3619038 100644 --- 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 c4e1e9700..d71fc6e92 100644 --- 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 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 55baa7375..62ae34936 100644 --- 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 e224fb84d..84db10591 100644 --- 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 d823fe818..19eab6bba 100644 --- 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 a96153c46..ce31f10d1 100644 --- 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 57582e363..d143e0d9f 100644 --- 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 9cc8b46f2..17bebb06e 100644 --- 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 23746949c..de8273fea 100644 --- 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 174b81a86..1ce2430b2 100644 --- 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 881050c2b..33cc952ba 100644 --- 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 7fac8dc58..7b75b438b 100644 --- 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 b73ea9d56..3e363dc77 100644 --- 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 667163713..54046c241 100644 --- 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 ade7611e0..5a0074c7e 100644 --- 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 edc173d74..66a9479bb 100644 --- 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"