From: Sreeja Athirkandathil Narayanan (sathirka) Date: Mon, 16 Oct 2023 18:19:27 +0000 (+0000) Subject: Pull request #4001: appid: Added support for appid trace logs with multiple logging... X-Git-Tag: 3.1.73.0~7 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=a67daa26b03929dce89b663318d746c265d8b012;p=thirdparty%2Fsnort3.git Pull request #4001: appid: Added support for appid trace logs with multiple logging levels Merge in SNORT/snort3 from ~SATHIRKA/snort3:appid_cbd_logging to master Squashed commit of the following: commit 03b7c38fb7fb796f0e7983c3f8fa6686c19a1561 Author: Sreeja Athirkandathil Narayanan Date: Tue Sep 12 11:45:40 2023 -0400 appid: Added support for appid trace logs with multiple logging levels --- diff --git a/src/log/messages.cc b/src/log/messages.cc index ae81c821c..a46fdcc5c 100644 --- a/src/log/messages.cc +++ b/src/log/messages.cc @@ -222,12 +222,8 @@ void LogMessage(FILE* fh, const char* format,...) } // print a warning message to stderr or syslog -void WarningMessage(const char* format,...) +void WarningMessage(const char* format, va_list& ap) { - va_list ap; - - va_start(ap, format); - if ( SnortConfig::log_syslog() ) { char buf[STD_BUF+1]; @@ -239,17 +235,21 @@ void WarningMessage(const char* format,...) { vfprintf(stderr, format, ap); } - - va_end(ap); } -// print a warning message to stderr or syslog -void ErrorMessage(const char* format,...) +void WarningMessage(const char* format, ...) { va_list ap; - va_start(ap, format); + WarningMessage(format, ap); + + va_end(ap); +} + +// print an error message to stderr or syslog +void ErrorMessage(const char* format, va_list& ap) +{ if ( SnortConfig::log_syslog() ) { char buf[STD_BUF+1]; @@ -261,6 +261,16 @@ void ErrorMessage(const char* format,...) { vfprintf(stderr, format, ap); } +} + +void ErrorMessage(const char* format,...) +{ + va_list ap; + + va_start(ap, format); + + ErrorMessage(format, ap); + va_end(ap); } diff --git a/src/log/messages.h b/src/log/messages.h index af5f39236..03e9927b5 100644 --- a/src/log/messages.h +++ b/src/log/messages.h @@ -63,7 +63,9 @@ SO_PUBLIC void LogMessage(const char*, va_list& ap); SO_PUBLIC void LogMessage(const char*, ...) __attribute__((format (printf, 1, 2))); SO_PUBLIC void LogMessage(FILE*, const char*, ...) __attribute__((format (printf, 2, 3))); SO_PUBLIC void WarningMessage(const char*, ...) __attribute__((format (printf, 1, 2))); +SO_PUBLIC void WarningMessage(const char*, va_list& ap); SO_PUBLIC void ErrorMessage(const char*, ...) __attribute__((format (printf, 1, 2))); +SO_PUBLIC void ErrorMessage(const char*, va_list& ap); class SO_PUBLIC ConfigLogger final { diff --git a/src/network_inspectors/appid/app_info_table.cc b/src/network_inspectors/appid/app_info_table.cc index a0f807a34..9e294b9b1 100644 --- a/src/network_inspectors/appid/app_info_table.cc +++ b/src/network_inspectors/appid/app_info_table.cc @@ -36,6 +36,7 @@ #include "utils/util_cstring.h" #include "appid_api.h" #include "appid_config.h" +#include "appid_debug.h" #include "appid_inspector.h" #include "appid_peg_counts.h" @@ -104,8 +105,8 @@ bool AppInfoManager::add_entry_to_app_info_name_table(const char* app_name, app_info_name_table[app_name] = entry; else { - WarningMessage("App name, \"%s\" is a duplicate entry will be shared by each detector.\n", - app_name); + appid_log(nullptr, TRACE_WARNING_LEVEL, "App name, \"%s\" is a duplicate entry will be shared by " + "each detector.\n", app_name); added = false; } return added; @@ -170,7 +171,7 @@ AppInfoTableEntry* AppInfoManager::add_dynamic_app_entry(const char* app_name) { if (!app_name || strlen(app_name) >= MAX_EVENT_APPNAME_LEN) { - ErrorMessage("Appname invalid or too long: %s\n", app_name); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Appname invalid or too long: %s\n", app_name); return nullptr; } @@ -204,14 +205,14 @@ void AppInfoManager::cleanup_appid_info_table() void AppInfoManager::dump_app_info_table() { - LogMessage("Cisco provided detectors:\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "Cisco provided detectors:\n"); for (auto& kv: app_info_table) - LogMessage("%s\t%d\t%s\n", kv.second->app_name, kv.second->appId, + appid_log(nullptr, TRACE_INFO_LEVEL, "%s\t%d\t%s\n", kv.second->app_name, kv.second->appId, (kv.second->flags & APPINFO_FLAG_ACTIVE) ? "active" : "inactive"); - LogMessage("User provided detectors:\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "User provided detectors:\n"); for (auto& kv: custom_app_info_table) - LogMessage("%s\t%d\t%s\n", kv.second->app_name, kv.second->appId, + appid_log(nullptr, TRACE_INFO_LEVEL, "%s\t%d\t%s\n", kv.second->app_name, kv.second->appId, (kv.second->flags & APPINFO_FLAG_ACTIVE) ? "active" : "inactive"); } @@ -395,7 +396,7 @@ void AppInfoManager::load_odp_config(OdpContext& odp_ctxt, const char* path) else if (!(strcasecmp(conf_key, "bittorrent_aggressiveness"))) { int aggressiveness = atoi(conf_val); - LogMessage("AppId: bittorrent_aggressiveness %d\n", aggressiveness); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: bittorrent_aggressiveness %d\n", aggressiveness); if (aggressiveness >= 50) { odp_ctxt.host_port_app_cache_lookup_interval = 5; @@ -403,59 +404,59 @@ void AppInfoManager::load_odp_config(OdpContext& odp_ctxt, const char* path) set_app_info_flags(APP_ID_BITTORRENT, APPINFO_FLAG_DEFER); set_app_info_flags(APP_ID_BITTORRENT, APPINFO_FLAG_DEFER_PAYLOAD); odp_ctxt.max_tp_flow_depth = 25; - LogMessage("AppId: host_port_app_cache_lookup_interval %d\n", + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: host_port_app_cache_lookup_interval %d\n", odp_ctxt.host_port_app_cache_lookup_interval); - LogMessage("AppId: recheck_for_portservice_appid enabled\n"); - LogMessage("AppId: defer_to_thirdparty %d\n", APP_ID_BITTORRENT); - LogMessage("AppId: defer_payload_to_thirdparty %d\n", APP_ID_BITTORRENT); - LogMessage("AppId: max_tp_flow_depth %d\n", odp_ctxt.max_tp_flow_depth); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: recheck_for_portservice_appid enabled\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: defer_to_thirdparty %d\n", APP_ID_BITTORRENT); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: defer_payload_to_thirdparty %d\n", APP_ID_BITTORRENT); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: max_tp_flow_depth %d\n", odp_ctxt.max_tp_flow_depth); } if (aggressiveness >= 80) { odp_ctxt.allow_port_wildcard_host_cache = true; - LogMessage("AppId: allow_port_wildcard_host_cache enabled\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: allow_port_wildcard_host_cache enabled\n"); } } else if (!(strcasecmp(conf_key, "ultrasurf_aggressiveness"))) { int aggressiveness = atoi(conf_val); - LogMessage("AppId: ultrasurf_aggressiveness %d\n", aggressiveness); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: ultrasurf_aggressiveness %d\n", aggressiveness); if (aggressiveness >= 50) { odp_ctxt.check_host_cache_unknown_ssl = true; set_app_info_flags(APP_ID_ULTRASURF, APPINFO_FLAG_DEFER); set_app_info_flags(APP_ID_ULTRASURF, APPINFO_FLAG_DEFER_PAYLOAD); odp_ctxt.max_tp_flow_depth = 25; - LogMessage("AppId: check_host_cache_unknown_ssl enabled\n"); - LogMessage("AppId: defer_to_thirdparty %d\n", APP_ID_ULTRASURF); - LogMessage("AppId: defer_payload_to_thirdparty %d\n", APP_ID_ULTRASURF); - LogMessage("AppId: max_tp_flow_depth %d\n", odp_ctxt.max_tp_flow_depth); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: check_host_cache_unknown_ssl enabled\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: defer_to_thirdparty %d\n", APP_ID_ULTRASURF); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: defer_payload_to_thirdparty %d\n", APP_ID_ULTRASURF); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: max_tp_flow_depth %d\n", odp_ctxt.max_tp_flow_depth); } if (aggressiveness >= 80) { odp_ctxt.allow_port_wildcard_host_cache = true; - LogMessage("AppId: allow_port_wildcard_host_cache enabled\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: allow_port_wildcard_host_cache enabled\n"); } } else if (!(strcasecmp(conf_key, "psiphon_aggressiveness"))) { int aggressiveness = atoi(conf_val); - LogMessage("AppId: psiphon_aggressiveness %d\n", aggressiveness); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: psiphon_aggressiveness %d\n", aggressiveness); if (aggressiveness >= 50) { odp_ctxt.check_host_cache_unknown_ssl = true; set_app_info_flags(APP_ID_PSIPHON, APPINFO_FLAG_DEFER); set_app_info_flags(APP_ID_PSIPHON, APPINFO_FLAG_DEFER_PAYLOAD); odp_ctxt.max_tp_flow_depth = 25; - LogMessage("AppId: check_host_cache_unknown_ssl enabled\n"); - LogMessage("AppId: defer_to_thirdparty %d\n", APP_ID_PSIPHON); - LogMessage("AppId: defer_payload_to_thirdparty %d\n", APP_ID_PSIPHON); - LogMessage("AppId: max_tp_flow_depth %d\n", odp_ctxt.max_tp_flow_depth); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: check_host_cache_unknown_ssl enabled\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: defer_to_thirdparty %d\n", APP_ID_PSIPHON); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: defer_payload_to_thirdparty %d\n", APP_ID_PSIPHON); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: max_tp_flow_depth %d\n", odp_ctxt.max_tp_flow_depth); } if (aggressiveness >= 80) { odp_ctxt.allow_port_wildcard_host_cache = true; - LogMessage("AppId: allow_port_wildcard_host_cache enabled\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: allow_port_wildcard_host_cache enabled\n"); } } else if (!(strcasecmp(conf_key, "tp_allow_probes"))) @@ -627,10 +628,10 @@ void AppInfoManager::dump_appid_configurations(const std::string& file_path) con if (!conf_file.is_open()) return; - LogMessage("AppId: Configuration file %s\n", file_path.c_str()); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId: Configuration file %s\n", file_path.c_str()); std::string line; while (getline(conf_file, line)) - LogMessage("%s\n", line.c_str()); + appid_log(nullptr, TRACE_INFO_LEVEL, "%s\n", line.c_str()); conf_file.close(); } @@ -674,7 +675,7 @@ void AppInfoManager::init_appid_info_table(const AppIdConfig& config, const char* token = strtok_r(buf, CONF_SEPARATORS, &context); if (!token) { - ErrorMessage("Could not read id for AppId\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not read id for AppId\n"); continue; } app_id = strtol(token, nullptr, 10); @@ -682,7 +683,7 @@ void AppInfoManager::init_appid_info_table(const AppIdConfig& config, token = strtok_r(nullptr, CONF_SEPARATORS, &context); if (!token) { - ErrorMessage("Could not read app_name. Line %s\n", buf); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not read app_name. Line %s\n", buf); continue; } app_name = snort_strdup(token); @@ -690,7 +691,7 @@ void AppInfoManager::init_appid_info_table(const AppIdConfig& config, token = strtok_r(nullptr, CONF_SEPARATORS, &context); if (!token) { - ErrorMessage("Could not read service id for AppId\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not read service id for AppId\n"); snort_free(app_name); continue; } @@ -699,7 +700,7 @@ void AppInfoManager::init_appid_info_table(const AppIdConfig& config, token = strtok_r(nullptr, CONF_SEPARATORS, &context); if (!token) { - ErrorMessage("Could not read client id for AppId\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not read client id for AppId\n"); snort_free(app_name); continue; } @@ -708,7 +709,7 @@ void AppInfoManager::init_appid_info_table(const AppIdConfig& config, token = strtok_r(nullptr, CONF_SEPARATORS, &context); if (!token) { - ErrorMessage("Could not read payload id for AppId\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not read payload id for AppId\n"); snort_free(app_name); continue; } diff --git a/src/network_inspectors/appid/appid_cip_event_handler.cc b/src/network_inspectors/appid/appid_cip_event_handler.cc index 446bd5561..1341af21f 100644 --- a/src/network_inspectors/appid/appid_cip_event_handler.cc +++ b/src/network_inspectors/appid/appid_cip_event_handler.cc @@ -91,16 +91,15 @@ void CipEventHandler::handle(DataEvent& event, Flow* flow) asd->set_payload_id(payload_id); asd->set_ss_application_ids(APP_ID_CIP, APP_ID_CIP, payload_id, APP_ID_NONE, APP_ID_NONE, change_bits); - if (change_bits[APPID_PAYLOAD_BIT] and appidDebug->is_enabled()) + if (change_bits[APPID_PAYLOAD_BIT]) { - appidDebug->activate(flow, asd, inspector.get_ctxt().config.log_all_sessions); - if (appidDebug->is_active()) - { - const char* app_name_service = asd->get_odp_ctxt().get_app_info_mgr().get_app_name(APP_ID_CIP); - const char* app_name_payload = asd->get_odp_ctxt().get_app_info_mgr().get_app_name(payload_id); - LogMessage("AppIdDbg %s CIP event handler service %s (%d) and payload %s (%d) are detected\n", - appidDebug->get_debug_session(), app_name_service, APP_ID_CIP, app_name_payload, payload_id); - } + if (appidDebug->is_enabled()) + appidDebug->activate(flow, asd, inspector.get_ctxt().config.log_all_sessions); + + const char* app_name_service = asd->get_odp_ctxt().get_app_info_mgr().get_app_name(APP_ID_CIP); + const char* app_name_payload = asd->get_odp_ctxt().get_app_info_mgr().get_app_name(payload_id); + appid_log(p, TRACE_DEBUG_LEVEL, "CIP event handler service %s (%d) and payload %s (%d) are detected\n", + app_name_service, APP_ID_CIP, app_name_payload, payload_id); } asd->publish_appid_event(change_bits, *p); diff --git a/src/network_inspectors/appid/appid_config.cc b/src/network_inspectors/appid/appid_config.cc index 14dcdf1fb..f34d30789 100644 --- a/src/network_inspectors/appid/appid_config.cc +++ b/src/network_inspectors/appid/appid_config.cc @@ -29,6 +29,7 @@ #include #include "app_info_table.h" +#include "appid_debug.h" #include "appid_discovery.h" #include "appid_http_session.h" #include "appid_inspector.h" @@ -40,7 +41,6 @@ #include "detector_plugins/detector_smtp.h" #include "host_port_app_cache.h" #include "main/snort_config.h" -#include "log/messages.h" #include "utils/util.h" #include "service_plugins/service_ssl.h" #include "detector_plugins/detector_dns.h" @@ -224,7 +224,7 @@ void OdpContext::set_client_and_service_detectors() Pop3ClientDetector* c_pop = (Pop3ClientDetector*) client_disco_mgr.get_client_detector("pop3"); if (!s_pop or !c_pop) { - ErrorMessage("appid: failed to initialize pop3 detector\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: failed to initialize pop3 detector\n"); return; } s_pop->set_client_detector(c_pop); @@ -234,7 +234,7 @@ void OdpContext::set_client_and_service_detectors() KerberosClientDetector* c_krb = (KerberosClientDetector*) client_disco_mgr.get_client_detector("kerberos"); if (!s_krb or !c_krb) { - ErrorMessage("appid: failed to initialize kerberos detector\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: failed to initialize kerberos detector\n"); return; } s_krb->set_client_detector(c_krb); @@ -244,7 +244,7 @@ void OdpContext::set_client_and_service_detectors() SmtpClientDetector* c_smtp = (SmtpClientDetector*) client_disco_mgr.get_client_detector("SMTP"); if (!s_smtp or !c_smtp) { - ErrorMessage("appid: failed to initialize smtp detector\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: failed to initialize smtp detector\n"); return; } s_smtp->set_client_detector(c_smtp); @@ -253,7 +253,7 @@ void OdpContext::set_client_and_service_detectors() ImapClientDetector* c_imap = (ImapClientDetector*) client_disco_mgr.get_client_detector("IMAP"); if (!s_imap or !c_imap) { - ErrorMessage("appid: failed to initialize imap detector\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: failed to initialize imap detector\n"); return; } s_imap->set_client_detector(c_imap); @@ -263,7 +263,7 @@ SipServiceDetector* OdpContext::get_sip_service_detector() { SipServiceDetector* s_sip = (SipServiceDetector*) service_disco_mgr.get_service_detector("sip"); if (!s_sip) - ErrorMessage("appid: failed to initialize sip service detector\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: failed to initialize sip service detector\n"); return s_sip; } @@ -271,7 +271,7 @@ SipUdpClientDetector* OdpContext::get_sip_client_detector() { SipUdpClientDetector* c_sip = (SipUdpClientDetector*) client_disco_mgr.get_client_detector("SIP"); if (!c_sip) - ErrorMessage("appid: failed to initialize sip client detector\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: failed to initialize sip client detector\n"); return c_sip; } @@ -282,7 +282,7 @@ void OdpContext::add_port_service_id(IpProtocol proto, uint16_t port, AppId appi else if (proto == IpProtocol::UDP) udp_port_only[port] = appid; else - ErrorMessage("appid: invalid port service for proto %d port %d app %d\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: invalid port service for proto %d port %d app %d\n", static_cast(proto), port, appid); } diff --git a/src/network_inspectors/appid/appid_debug.cc b/src/network_inspectors/appid/appid_debug.cc index 0995de1ea..e6d452939 100644 --- a/src/network_inspectors/appid/appid_debug.cc +++ b/src/network_inspectors/appid/appid_debug.cc @@ -27,13 +27,73 @@ #include "flow/flow_key.h" #include "log/messages.h" +#include "trace/trace_api.h" #include "appid_config.h" +#include "appid_module.h" #include "appid_session.h" using namespace snort; THREAD_LOCAL AppIdDebug* appidDebug = nullptr; +void appid_log(const Packet* p, const uint8_t log_level, const char* format, ...) +{ + va_list args; + va_start(args, format); + + va_list dup_args; + va_copy(dup_args, args); + + switch(log_level) + { + case TRACE_CRITICAL_LEVEL: + FatalError(format, args); + break; + + case TRACE_ERROR_LEVEL: + ErrorMessage(format, args); + + if (p) + trace_logf(TRACE_ERROR_LEVEL, appid_trace, DEFAULT_TRACE_OPTION_ID, p, format, dup_args); + break; + + case TRACE_WARNING_LEVEL: + WarningMessage(format, args); + + if (p) + trace_logf(TRACE_WARNING_LEVEL, appid_trace, DEFAULT_TRACE_OPTION_ID, p, format, dup_args); + break; + + case TRACE_INFO_LEVEL: + LogMessage(format, args); + + if (p) + trace_logf(TRACE_INFO_LEVEL, appid_trace, DEFAULT_TRACE_OPTION_ID, p, format, dup_args); + break; + + case TRACE_DEBUG_LEVEL: + if (p) //called from packet threads + { + if (appidDebug and appidDebug->is_active()) + { + string msg = string("AppIdDbg ") + appidDebug->get_debug_session() + " " + format; + LogMessage(msg.c_str(), args); + } + + trace_logf(TRACE_DEBUG_LEVEL, appid_trace, DEFAULT_TRACE_OPTION_ID, p, format, dup_args); + } + else //called from control thread + LogMessage(format, args); + break; + + default: + break; + } + + va_end(args); + va_end(dup_args); +} + void AppIdDebug::activate(const uint32_t* ip1, const uint32_t* ip2, uint16_t port1, uint16_t port2, IpProtocol protocol, const int version, uint32_t address_space_id, const AppIdSession* session, bool log_all_sessions, int16_t group1, int16_t group2, @@ -148,14 +208,14 @@ void AppIdDebug::set_constraints(const char *desc, info = *constraints; info.sip.ntop(sipstr, sizeof(sipstr)); info.dip.ntop(dipstr, sizeof(dipstr)); - LogMessage("Debugging %s with %s-%hu and %s-%hu %hhu\n", desc, + appid_log(nullptr, TRACE_INFO_LEVEL, "Debugging %s with %s-%hu and %s-%hu %hhu\n", desc, sipstr, info.sport, dipstr, info.dport, static_cast(info.protocol)); enabled = true; } else { - LogMessage("Debugging %s disabled\n", desc); + appid_log(nullptr, TRACE_INFO_LEVEL, "Debugging %s disabled\n", desc); enabled = false; active = false; } diff --git a/src/network_inspectors/appid/appid_debug.h b/src/network_inspectors/appid/appid_debug.h index 696d241cd..6211aaef7 100644 --- a/src/network_inspectors/appid/appid_debug.h +++ b/src/network_inspectors/appid/appid_debug.h @@ -26,6 +26,7 @@ #include +#include "detection/detection_engine.h" #include "protocols/ipv6.h" #include "protocols/protocol_ids.h" #include "main/thread.h" @@ -35,12 +36,17 @@ class AppIdSession; namespace snort { class Flow; + struct Packet; } // %s %u -> %s %u %u AS=%u ID=%u [GR=%hd-%hd] // IPv6 Port -> IPv6 Port Proto AS=ASNum ID=InstanceNum [GR=SrcGroupNum-DstGroupNum] #define APPID_DEBUG_SESSION_ID_SIZE ((39+1+5+1+2+1+39+1+5+1+3+1+2+1+10+1+2+1+10+32)+1) +#define CURRENT_PACKET snort::DetectionEngine::get_current_packet() + +void appid_log(const snort::Packet*, const uint8_t log_level, const char*, ...); + struct AppIdDebugSessionConstraints { snort::SfIp sip; diff --git a/src/network_inspectors/appid/appid_discovery.cc b/src/network_inspectors/appid/appid_discovery.cc index 453d92ec2..d985009a2 100644 --- a/src/network_inspectors/appid/appid_discovery.cc +++ b/src/network_inspectors/appid/appid_discovery.cc @@ -27,7 +27,6 @@ #include "host_tracker/host_cache.h" #include "host_tracker/host_cache_segmented.h" -#include "log/messages.h" #include "packet_tracer/packet_tracer.h" #include "profiler/profiler.h" #include "protocols/packet.h" @@ -100,7 +99,7 @@ void AppIdDiscovery::register_detector(const std::string& name, AppIdDetector* c else if (proto == IpProtocol::UDP) udp_detectors[name] = cd; else - ErrorMessage("Detector %s has unsupported protocol %u", name.c_str(), (unsigned)proto); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Detector %s has unsupported protocol %u\n", name.c_str(), (unsigned)proto); } void AppIdDiscovery::add_pattern_data(AppIdDetector* detector, SearchTool& st, int position, const @@ -242,19 +241,16 @@ bool AppIdDiscovery::do_pre_discovery(Packet* p, AppIdSession*& asd, AppIdInspec if (p->flow->get_session_flags() & SSNFLAG_MIDSTREAM) { asd->flags |= APPID_SESSION_MID; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s New AppId mid-stream session\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "New AppId mid-stream session\n"); } - else if (appidDebug->is_active()) - LogMessage("AppIdDbg %s New AppId session\n", appidDebug->get_debug_session()); + else + appid_log(p, TRACE_DEBUG_LEVEL, "New AppId session\n"); } else if (!asd->get_session_flags(APPID_SESSION_MID) and (p->flow->get_session_flags() & SSNFLAG_MIDSTREAM)) { asd->flags |= APPID_SESSION_MID; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s AppId mid-stream session\n", appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "AppId mid-stream session\n"); } if (!asd->get_session_flags(APPID_SESSION_DISCOVER_APP | APPID_SESSION_SPECIAL_MONITORED)) @@ -300,14 +296,10 @@ bool AppIdDiscovery::do_pre_discovery(Packet* p, AppIdSession*& asd, AppIdInspec asd->publish_appid_event(change_bits, *p); asd->set_session_flags(APPID_SESSION_FUTURE_FLOW_IDED); - if (appidDebug->is_active()) - { - const char *app_name = - asd->get_odp_ctxt().get_app_info_mgr().get_app_name(asd->get_service_id()); - LogMessage("AppIdDbg %s Ignoring connection with service %s (%d)\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", - asd->get_service_id()); - } + const char *app_name = + asd->get_odp_ctxt().get_app_info_mgr().get_app_name(asd->get_service_id()); + appid_log(p, TRACE_DEBUG_LEVEL, "Ignoring connection with service %s (%d)\n", + app_name ? app_name : "unknown", asd->get_service_id()); return false; } @@ -332,11 +324,9 @@ bool AppIdDiscovery::do_pre_discovery(Packet* p, AppIdSession*& asd, AppIdInspec (p->dsize and !(p->packet_flags & (PKT_STREAM_ORDER_OK | PKT_REBUILT_STREAM)))) { asd->set_session_flags(APPID_SESSION_OOO | APPID_SESSION_OOO_CHECK_TP); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Packet out-of-order, %s%sflow\n", - appidDebug->get_debug_session(), - (p->packet_flags & PKT_STREAM_ORDER_BAD) ? "bad " : "not-ok ", - asd->get_session_flags(APPID_SESSION_MID) ? "mid-stream " : ""); + appid_log(p, TRACE_DEBUG_LEVEL, "Packet out-of-order, %s%sflow\n", + (p->packet_flags & PKT_STREAM_ORDER_BAD) ? "bad " : "not-ok ", + asd->get_session_flags(APPID_SESSION_MID) ? "mid-stream " : ""); // Shut off service/client discoveries, since they skip not-ok data packets and // may keep failing on subsequent data packets causing performance degradation @@ -350,9 +340,7 @@ bool AppIdDiscovery::do_pre_discovery(Packet* p, AppIdSession*& asd, AppIdInspec asd->client_disco_state = APPID_DISCO_STATE_FINISHED; asd->set_session_flags(APPID_SESSION_SERVICE_DETECTED | APPID_SESSION_CLIENT_DETECTED); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s stopped service/client discovery\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "stopped service/client discovery\n"); } } else @@ -387,9 +375,7 @@ bool AppIdDiscovery::do_pre_discovery(Packet* p, AppIdSession*& asd, AppIdInspec if (fdpd and (fdpd == asd->session_packet_count)) { p->flow->set_proxied(); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Marked the flow as decrypted at packet number %lu\n", - appidDebug->get_debug_session(), (long unsigned)fdpd); + appid_log(p, TRACE_DEBUG_LEVEL, "Marked the flow as decrypted at packet number %lu\n", (long unsigned)fdpd); } #endif @@ -421,14 +407,10 @@ void AppIdDiscovery::do_port_based_discovery(Packet* p, AppIdSession& asd, IpPro if (id > APP_ID_NONE) { asd.set_port_service_id(id); - if (appidDebug->is_active()) - { - AppId ps_id = asd.get_port_service_id(); - const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(ps_id); - LogMessage("AppIdDbg %s Port service %s (%d) from port\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", - asd.get_port_service_id()); - } + AppId ps_id = asd.get_port_service_id(); + const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(ps_id); + appid_log(p, TRACE_DEBUG_LEVEL, "Port service %s (%d) from port\n", + app_name ? app_name : "unknown", asd.get_port_service_id()); } asd.set_session_flags(APPID_SESSION_PORT_SERVICE_DONE); } @@ -658,14 +640,11 @@ bool AppIdDiscovery::detect_on_first_pkt(Packet* p, AppIdSession& asd, break; } asd.set_session_flags(APPID_SESSION_FIRST_PKT_CACHE_MATCHED); - if (appidDebug->is_active()) - { - LogMessage("AppIdDbg %s Host cache match found on first packet, service: %s(%d), " - "client: %s(%d), payload: %s(%d), reinspect: %s \n", appidDebug->get_debug_session(), - (service_app_name ? service_app_name : ""), service_id, - (client_app_name ? client_app_name : ""), client_id, - (payload_app_name ? payload_app_name : ""), payload_id, (hv->reinspect ? "True" : "False")); - } + appid_log(p, TRACE_DEBUG_LEVEL, "Host cache match found on first packet, service: %s(%d), " + "client: %s(%d), payload: %s(%d), reinspect: %s \n", + (service_app_name ? service_app_name : ""), service_id, + (client_app_name ? client_app_name : ""), client_id, + (payload_app_name ? payload_app_name : ""), payload_id, (hv->reinspect ? "True" : "False")); return true; } return false; @@ -704,14 +683,9 @@ bool AppIdDiscovery::do_discovery(Packet* p, AppIdSession& asd, IpProtocol proto if (id > APP_ID_NONE) { asd.misc_app_id = misc_id = id; - if (appidDebug->is_active()) - { - const char *app_name = - asd.get_odp_ctxt().get_app_info_mgr().get_app_name(asd.misc_app_id); - LogMessage("AppIdDbg %s Outer protocol service %s (%d)\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", - asd.misc_app_id); - } + const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(asd.misc_app_id); + appid_log(p, TRACE_DEBUG_LEVEL, "Outer protocol service %s (%d)\n", + app_name ? app_name : "unknown", asd.misc_app_id); } } @@ -725,14 +699,10 @@ bool AppIdDiscovery::do_discovery(Packet* p, AppIdSession& asd, IpProtocol proto asd.set_port_service_id(id); service_id = id; asd.service_disco_state = APPID_DISCO_STATE_FINISHED; - if (appidDebug->is_active()) - { - AppId ps_id = asd.get_port_service_id(); - const char *app_name = - asd.get_odp_ctxt().get_app_info_mgr().get_app_name(ps_id); - LogMessage("AppIdDbg %s Protocol service %s (%d) from protocol\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", ps_id); - } + AppId ps_id = asd.get_port_service_id(); + const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(ps_id); + appid_log(p, TRACE_DEBUG_LEVEL, "Protocol service %s (%d) from protocol\n", + app_name ? app_name : "unknown", ps_id); } asd.set_session_flags(APPID_SESSION_PORT_SERVICE_DONE); } @@ -813,12 +783,9 @@ bool AppIdDiscovery::do_discovery(Packet* p, AppIdSession& asd, IpProtocol proto { service_id = id; asd.set_port_service_id(id); - if (appidDebug->is_active()) - { - const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(id); - LogMessage("AppIdDbg %s Port service %s (%d) from length\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", id); - } + const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(id); + appid_log(p, TRACE_DEBUG_LEVEL, "Port service %s (%d) from length\n", + app_name ? app_name : "unknown", id); asd.set_session_flags(APPID_SESSION_PORT_SERVICE_DONE); } } @@ -882,9 +849,7 @@ void AppIdDiscovery::do_post_discovery(Packet* p, AppIdSession& asd, if (!asd.is_tp_appid_done()) { asd.tpsession->set_state(TP_STATE_TERMINATED); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Stopped 3rd party detection\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "Stopped 3rd party detection\n"); } } diff --git a/src/network_inspectors/appid/appid_eve_process_event_handler.cc b/src/network_inspectors/appid/appid_eve_process_event_handler.cc index 415d40dfe..dedb8e29d 100644 --- a/src/network_inspectors/appid/appid_eve_process_event_handler.cc +++ b/src/network_inspectors/appid/appid_eve_process_event_handler.cc @@ -51,12 +51,9 @@ void AppIdEveProcessEventHandler::handle(DataEvent& event, Flow* flow) asd = AppIdSession::allocate_session(p, p->get_ip_proto_next(), dir, inspector, *pkt_thread_odp_ctxt); if (appidDebug->is_enabled()) - { appidDebug->activate(flow, asd, inspector.get_ctxt().config.log_all_sessions); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s New AppId session at mercury event\n", - appidDebug->get_debug_session()); - } + + appid_log(p, TRACE_DEBUG_LEVEL, "New AppId session at mercury event\n"); } if (!asd->get_session_flags(APPID_SESSION_DISCOVER_APP | APPID_SESSION_SPECIAL_MONITORED)) @@ -130,29 +127,25 @@ void AppIdEveProcessEventHandler::handle(DataEvent& event, Flow* flow) asd->set_payload_id(payload_id); } - if (appidDebug->is_active()) - { - std::string debug_str; - - debug_str += "encrypted client app: " + std::to_string(client_id); - if (!name.empty()) - debug_str += ", process name: " + name + ", confidence: " + std::to_string(conf); + std::string debug_str; - if (!server_name.empty()) - debug_str += ", server name: " + server_name; + debug_str += "encrypted client app: " + std::to_string(client_id); + if (!name.empty()) + debug_str += ", process name: " + name + ", confidence: " + std::to_string(conf); - if (!user_agent.empty()) - debug_str += ", user agent: " + user_agent; + if (!server_name.empty()) + debug_str += ", server name: " + server_name; - if (is_quic && alpn_vec.size()) - { - debug_str += ", alpn: [ "; - for(unsigned int i = 0; i < alpn_vec.size(); i++) - debug_str += alpn_vec[i] + " "; - debug_str += "]"; - } + if (!user_agent.empty()) + debug_str += ", user agent: " + user_agent; - LogMessage("AppIdDbg %s %s\n", - appidDebug->get_debug_session(), debug_str.c_str()); + if (is_quic && alpn_vec.size()) + { + debug_str += ", alpn: [ "; + for(unsigned int i = 0; i < alpn_vec.size(); i++) + debug_str += alpn_vec[i] + " "; + debug_str += "]"; } + + appid_log(p, TRACE_DEBUG_LEVEL, "%s\n", debug_str.c_str()); } diff --git a/src/network_inspectors/appid/appid_ha.cc b/src/network_inspectors/appid/appid_ha.cc index 6e7759c20..4880bdfe1 100644 --- a/src/network_inspectors/appid/appid_ha.cc +++ b/src/network_inspectors/appid/appid_ha.cc @@ -50,9 +50,7 @@ static AppIdSession* create_appid_session(Flow& flow, const FlowKey* key, flow.flags.client_initiated ? &flow.client_ip : &flow.server_ip, flow.flags.client_initiated ? flow.client_port : flow.server_port, inspector, *pkt_thread_odp_ctxt, key->addressSpaceId); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s high-avail - New AppId session created in consume\n", - appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "high-avail - New AppId session created in consume\n"); flow.set_flow_data(asd); asd->flow = &flow; @@ -77,18 +75,18 @@ bool AppIdHAAppsClient::consume(Flow*& flow, const FlowKey* key, HAMessage& msg, const AppIdSessionHAApps* appHA = (const AppIdSessionHAApps*)msg.cursor; if (appidDebug->is_enabled()) - { appidDebug->activate(flow, asd, inspector->get_ctxt().config.log_all_sessions); - LogMessage("AppIdDbg %s high-avail - Consuming app data - flags 0x%x, service %d, " - "client %d, payload %d, misc %d, referred %d, client_inferred_service %d, " - "port_service %d, tp_app %d, tp_payload %d\n", - appidDebug->get_debug_session(), appHA->flags, appHA->appId[APPID_HA_APP_SERVICE], - appHA->appId[APPID_HA_APP_CLIENT], appHA->appId[APPID_HA_APP_PAYLOAD], - appHA->appId[APPID_HA_APP_MISC], appHA->appId[APPID_HA_APP_REFERRED], - appHA->appId[APPID_HA_APP_CLIENT_INFERRED_SERVICE], - appHA->appId[APPID_HA_APP_PORT_SERVICE], appHA->appId[APPID_HA_APP_TP], - appHA->appId[APPID_HA_APP_TP_PAYLOAD]); - } + + Packet* p = CURRENT_PACKET; + appid_log(p, TRACE_DEBUG_LEVEL, "high-avail - Consuming app data - flags 0x%x, service %d, " + "client %d, payload %d, misc %d, referred %d, client_inferred_service %d, " + "port_service %d, tp_app %d, tp_payload %d\n", + appHA->flags, appHA->appId[APPID_HA_APP_SERVICE], + appHA->appId[APPID_HA_APP_CLIENT], appHA->appId[APPID_HA_APP_PAYLOAD], + appHA->appId[APPID_HA_APP_MISC], appHA->appId[APPID_HA_APP_REFERRED], + appHA->appId[APPID_HA_APP_CLIENT_INFERRED_SERVICE], + appHA->appId[APPID_HA_APP_PORT_SERVICE], appHA->appId[APPID_HA_APP_TP], + appHA->appId[APPID_HA_APP_TP_PAYLOAD]); if (!asd) { @@ -112,7 +110,7 @@ bool AppIdHAAppsClient::consume(Flow*& flow, const FlowKey* key, HAMessage& msg, const TPLibHandler* tph = TPLibHandler::get(); TpAppIdCreateSession tpsf = tph->tpsession_factory(); if ( !(asd->tpsession = tpsf(*asd->get_tp_appid_ctxt())) ) - ErrorMessage("appid: Could not allocate asd.tpsession data in consume"); + appid_log(p, TRACE_ERROR_LEVEL, "appid: Could not allocate asd.tpsession data in consume"); else { asd->tpsession->set_state(TP_STATE_HA); @@ -206,16 +204,15 @@ bool AppIdHAAppsClient::produce(Flow& flow, HAMessage& msg) appHA->appId[APPID_HA_APP_TP] = asd->get_tp_app_id(); appHA->appId[APPID_HA_APP_TP_PAYLOAD] = asd->get_tp_payload_app_id(); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s high-avail - Producing app data - flags 0x%x, service %d, client %d, " - "payload %d, misc %d, referred %d, client_inferred_service %d, port_service %d, " - "tp_app %d, tp_payload %d\n", - appidDebug->get_debug_session(), appHA->flags, appHA->appId[APPID_HA_APP_SERVICE], - appHA->appId[APPID_HA_APP_CLIENT], appHA->appId[APPID_HA_APP_PAYLOAD], - appHA->appId[APPID_HA_APP_MISC], appHA->appId[APPID_HA_APP_REFERRED], - appHA->appId[APPID_HA_APP_CLIENT_INFERRED_SERVICE], - appHA->appId[APPID_HA_APP_PORT_SERVICE], appHA->appId[APPID_HA_APP_TP], - appHA->appId[APPID_HA_APP_TP_PAYLOAD]); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "high-avail - Producing app data - flags 0x%x, service %d, client %d, " + "payload %d, misc %d, referred %d, client_inferred_service %d, port_service %d, " + "tp_app %d, tp_payload %d\n", + appHA->flags, appHA->appId[APPID_HA_APP_SERVICE], + appHA->appId[APPID_HA_APP_CLIENT], appHA->appId[APPID_HA_APP_PAYLOAD], + appHA->appId[APPID_HA_APP_MISC], appHA->appId[APPID_HA_APP_REFERRED], + appHA->appId[APPID_HA_APP_CLIENT_INFERRED_SERVICE], + appHA->appId[APPID_HA_APP_PORT_SERVICE], appHA->appId[APPID_HA_APP_TP], + appHA->appId[APPID_HA_APP_TP_PAYLOAD]); msg.advance_cursor(sizeof(AppIdSessionHAApps)); return true; @@ -238,11 +235,10 @@ bool AppIdHAHttpClient::consume(Flow*& flow, const FlowKey* key, HAMessage& msg, AppIdSession* asd = appid_api.get_appid_session(*flow); AppIdSessionHAHttp* appHA = (AppIdSessionHAHttp*)msg.cursor; if (appidDebug->is_enabled()) - { appidDebug->activate(flow, asd, inspector->get_ctxt().config.log_all_sessions); - LogMessage("AppIdDbg %s high-avail - Consuming HTTP data - URL %s, host %s\n", - appidDebug->get_debug_session(), appHA->url, appHA->host); - } + + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "high-avail - Consuming HTTP data - URL %s, host %s\n", + appHA->url, appHA->host); if (!asd) asd = create_appid_session(*flow, key, *inspector); @@ -304,9 +300,8 @@ bool AppIdHAHttpClient::produce(Flow& flow, HAMessage& msg) else appHA->host[0] = '\0'; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s high-avail - Producing HTTP data - URL %s, host %s\n", - appidDebug->get_debug_session(), appHA->url, appHA->host); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "high-avail - Producing HTTP data - URL %s, host %s\n", + appHA->url, appHA->host); msg.advance_cursor(sizeof(AppIdSessionHAHttp)); return true; @@ -328,11 +323,9 @@ bool AppIdHATlsHostClient::consume(Flow*& flow, const FlowKey* key, HAMessage& m AppIdSession* asd = appid_api.get_appid_session(*flow); AppIdSessionHATlsHost* appHA = (AppIdSessionHATlsHost*)msg.cursor; if (appidDebug->is_enabled()) - { appidDebug->activate(flow, asd, inspector->get_ctxt().config.log_all_sessions); - LogMessage("AppIdDbg %s high-avail - Consuming TLS host - %s\n", - appidDebug->get_debug_session(), appHA->tls_host); - } + + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "high-avail - Consuming TLS host - %s\n", appHA->tls_host); if (!asd) asd = create_appid_session(*flow, key, *inspector); @@ -363,9 +356,7 @@ bool AppIdHATlsHostClient::produce(Flow& flow, HAMessage& msg) memcpy(appHA->tls_host, tls_host, length); appHA->tls_host[length] = '\0'; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s high-avail - Producing TLS host - %s\n", - appidDebug->get_debug_session(), appHA->tls_host); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "high-avail - Producing TLS host - %s\n", appHA->tls_host); msg.advance_cursor(sizeof(AppIdSessionHATlsHost)); return true; diff --git a/src/network_inspectors/appid/appid_http_event_handler.cc b/src/network_inspectors/appid/appid_http_event_handler.cc index fe62128c4..328e4abfd 100644 --- a/src/network_inspectors/appid/appid_http_event_handler.cc +++ b/src/network_inspectors/appid/appid_http_event_handler.cc @@ -59,11 +59,9 @@ void HttpEventHandler::handle(DataEvent& event, Flow* flow) if ( appidDebug->is_enabled() ) { appidDebug->activate(flow, asd, inspector.get_ctxt().config.log_all_sessions); - if ( appidDebug->is_active() ) - LogMessage("AppIdDbg %s New AppId session at HTTP event\n", - appidDebug->get_debug_session()); is_debug_active = true; } + appid_log(p, TRACE_DEBUG_LEVEL, "New AppId session at HTTP event\n"); } else if ( asd->get_odp_ctxt_version() != pkt_thread_odp_ctxt->get_version() ) return; // Skip detection for sessions using old odp context after odp reload @@ -85,9 +83,8 @@ void HttpEventHandler::handle(DataEvent& event, Flow* flow) if (appidDebug->is_enabled() and !is_debug_active) appidDebug->activate(flow, asd, inspector.get_ctxt().config.log_all_sessions); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Processing HTTP metadata from HTTP Inspector for stream %" PRId64 "\n", - appidDebug->get_debug_session(), http_event->get_httpx_stream_id()); + appid_log(p, TRACE_DEBUG_LEVEL, "Processing HTTP metadata from HTTP Inspector for stream %" PRId64 "\n", + http_event->get_httpx_stream_id()); asd->set_session_flags(APPID_SESSION_HTTP_SESSION); diff --git a/src/network_inspectors/appid/appid_http_session.cc b/src/network_inspectors/appid/appid_http_session.cc index 4c798e2b5..9a76f1e93 100644 --- a/src/network_inspectors/appid/appid_http_session.cc +++ b/src/network_inspectors/appid/appid_http_session.cc @@ -450,12 +450,9 @@ void AppIdHttpSession::set_client(AppId app_id, AppidChangeBits& change_bits, change_bits.set(APPID_CLIENT_INFO_BIT); } - if (appidDebug->is_active()) - { - const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); - LogMessage("AppIdDbg %s %s is client %s (%d)\n", appidDebug->get_debug_session(), - type, app_name ? app_name : "unknown", app_id); - } + const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "%s is client %s (%d)\n", + type, app_name ? app_name : "unknown", app_id); } void AppIdHttpSession::set_payload(AppId app_id, AppidChangeBits& change_bits, @@ -473,16 +470,12 @@ void AppIdHttpSession::set_payload(AppId app_id, AppidChangeBits& change_bits, AppIdPegCounts::inc_payload_count(app_id); payload.set_version(version); - if (appidDebug->is_active()) - { - const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); - if (app_id == APP_ID_UNKNOWN) - LogMessage("AppIdDbg %s Payload is Unknown (%d)\n", appidDebug->get_debug_session(), - app_id); - else - LogMessage("AppIdDbg %s %s is payload %s (%d)\n", appidDebug->get_debug_session(), - type, app_name ? app_name : "unknown", app_id); - } + const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); + if (app_id == APP_ID_UNKNOWN) + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Payload is Unknown (%d)\n", app_id); + else + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "%s is payload %s (%d)\n", type, + app_name ? app_name : "unknown", app_id); } void AppIdHttpSession::set_referred_payload(AppId app_id, AppidChangeBits& change_bits) @@ -495,12 +488,8 @@ void AppIdHttpSession::set_referred_payload(AppId app_id, AppidChangeBits& chang AppIdPegCounts::inc_referred_count(app_id); change_bits.set(APPID_REFERRED_BIT); - if (appidDebug->is_active()) - { - const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); - LogMessage("AppIdDbg %s URL is referred %s (%d)\n", appidDebug->get_debug_session(), - app_name ? app_name : "unknown", app_id); - } + const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "URL is referred %s (%d)\n", app_name ? app_name : "unknown", app_id); } int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, @@ -520,6 +509,8 @@ int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, return 0; } + Packet* p = CURRENT_PACKET; + if ( direction == APP_ID_FROM_RESPONDER and !asd.get_session_flags(APPID_SESSION_RESPONSE_CODE_CHECKED) ) { @@ -530,9 +521,7 @@ int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, constexpr auto RESPONSE_CODE_LENGTH = 3; if (response_code->size() != RESPONSE_CODE_LENGTH) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Bad http response code.\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "Bad http response code.\n"); asd.reset_session_data(change_bits); return 0; } @@ -543,9 +532,7 @@ int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, set_session_flags(APPID_SESSION_RESPONSE_CODE_CHECKED); /* didn't receive response code in first X packets. Stop processing this session */ asd.reset_session_data(change_bits); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s No response code received\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "No response code received\n"); return 0; } #endif @@ -618,15 +605,11 @@ int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, http_matchers.identify_user_agent(useragent->c_str(), useragent->size(), service_id, client_id, &version); - if (appidDebug->is_active()) + if (service_id > APP_ID_NONE and service_id != APP_ID_HTTP and asd.get_service_id() != service_id) { - if (service_id > APP_ID_NONE and service_id != APP_ID_HTTP and - asd.get_service_id() != service_id) - { - const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(service_id); - LogMessage("AppIdDbg %s User Agent is service %s (%d)\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", service_id); - } + const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(service_id); + appid_log(p, TRACE_DEBUG_LEVEL, "User Agent is service %s (%d)\n", + app_name ? app_name : "unknown", service_id); } asd.set_service_appid_data(service_id, change_bits); if (client_id != APP_ID_HTTP) @@ -665,12 +648,8 @@ int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, if (app_id and asd.get_service_id() != app_id) { asd.set_service_appid_data(app_id, change_bits, version); - if (appidDebug->is_active()) - { - const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); - LogMessage("AppIdDbg %s X service %s (%d)\n", appidDebug->get_debug_session(), - app_name ? app_name : "unknown", app_id); - } + const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(app_id); + appid_log(p, TRACE_DEBUG_LEVEL, "X service %s (%d)\n", app_name ? app_name : "unknown", app_id); } } asd.scan_flags &= ~SCAN_HTTP_XWORKINGWITH_FLAG; @@ -712,14 +691,11 @@ int AppIdHttpSession::process_http_packet(AppidSessionDirection direction, if (asd.get_service_id() <= APP_ID_NONE) { - if (appidDebug->is_active() and service_id > APP_ID_NONE and service_id != - APP_ID_HTTP and asd.get_service_id() != service_id) + if (service_id > APP_ID_NONE and service_id != APP_ID_HTTP and asd.get_service_id() != service_id) { const char* app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(service_id); - LogMessage("AppIdDbg %s URL is service %s (%d)\n", - appidDebug->get_debug_session(), - app_name ? app_name : "unknown", - service_id); + appid_log(p, TRACE_DEBUG_LEVEL, "URL is service %s (%d)\n", + app_name ? app_name : "unknown", service_id); } asd.set_service_appid_data(service_id, change_bits); } @@ -814,8 +790,7 @@ void AppIdHttpSession::set_field(HttpFieldIds id, const std::string* str, set_http_change_bits(change_bits, id); set_scan_flags(id); - if (appidDebug->is_active()) - print_field(id, str); + print_field(id, str); } else if (str) delete str; @@ -831,8 +806,7 @@ void AppIdHttpSession::set_field(HttpFieldIds id, const uint8_t* str, int32_t le set_http_change_bits(change_bits, id); set_scan_flags(id); - if (appidDebug->is_active()) - print_field(id, meta_data[id]); + print_field(id, meta_data[id]); } } @@ -860,8 +834,7 @@ void AppIdHttpSession::set_req_body_field(HttpFieldIds id, const uint8_t* str, i set_http_change_bits(change_bits, id); set_scan_flags(id); - if (appidDebug->is_active()) - print_field(id, meta_data[id]); + print_field(id, meta_data[id]); } } @@ -935,10 +908,9 @@ void AppIdHttpSession::print_field(HttpFieldIds id, const std::string* field) } if (httpx_stream_id >= 0) - LogMessage("AppIdDbg %s stream %" PRId64 ": %s is %s\n", appidDebug->get_debug_session(), + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "stream %" PRId64 ": %s is %s\n", httpx_stream_id, field_name.c_str(), field->c_str()); else - LogMessage("AppIdDbg %s %s is %s\n", appidDebug->get_debug_session(), - field_name.c_str(), field->c_str()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "%s is %s\n", field_name.c_str(), field->c_str()); } diff --git a/src/network_inspectors/appid/appid_inspector.cc b/src/network_inspectors/appid/appid_inspector.cc index c29fd75be..59b0fb156 100644 --- a/src/network_inspectors/appid/appid_inspector.cc +++ b/src/network_inspectors/appid/appid_inspector.cc @@ -29,7 +29,6 @@ #include #include "flow/flow.h" -#include "log/messages.h" #include "main/analyzer_command.h" #include "managers/inspector_manager.h" #include "managers/module_manager.h" @@ -138,11 +137,10 @@ bool AppIdInspector::configure(SnortConfig* sc) { #endif if ( prev_maxrss == -1 or getrusage(RUSAGE_SELF, &ru) == -1 ) - ErrorMessage("appid: fetching memory usage failed\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: fetching memory usage failed\n"); else - LogMessage("appid: MaxRss diff: %li\n", ru.ru_maxrss - prev_maxrss); - - LogMessage("appid: patterns loaded: %u\n", ctxt->get_odp_ctxt().get_pattern_count()); + appid_log(nullptr, TRACE_INFO_LEVEL, "appid: MaxRss diff: %li\n", ru.ru_maxrss - prev_maxrss); + appid_log(nullptr, TRACE_INFO_LEVEL, "appid: patterns loaded: %u\n", ctxt->get_odp_ctxt().get_pattern_count()); #ifdef REG_TEST } #endif diff --git a/src/network_inspectors/appid/appid_module.cc b/src/network_inspectors/appid/appid_module.cc index 55d654f77..6b49ff5c2 100644 --- a/src/network_inspectors/appid/appid_module.cc +++ b/src/network_inspectors/appid/appid_module.cc @@ -32,7 +32,6 @@ #include "control/control.h" #include "host_tracker/host_cache.h" #include "host_tracker/host_cache_segmented.h" -#include "log/messages.h" #include "main/analyzer.h" #include "main/analyzer_command.h" #include "main/reload_tracker.h" @@ -161,7 +160,7 @@ public: ACThirdPartyAppIdContextSwap(const AppIdInspector& inspector, ControlConn* conn) : AnalyzerCommand(conn), inspector(inspector) { - LogMessage("== swapping third-party configuration\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "== swapping third-party configuration\n"); } ~ACThirdPartyAppIdContextSwap() override; @@ -186,7 +185,7 @@ ACThirdPartyAppIdContextSwap::~ACThirdPartyAppIdContextSwap() std::string file_path = ctxt.get_tp_appid_ctxt()->get_user_config(); ctxt.get_odp_ctxt().get_app_info_mgr().dump_appid_configurations(file_path); log_message("== reload third-party complete\n"); - LogMessage("== third-party configuration swap complete\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "== third-party configuration swap complete\n"); ReloadTracker::end(ctrlcon, true); } @@ -294,7 +293,7 @@ static int enable_debug(lua_State* L) if (sipstr) { if (constraints.sip.set(sipstr) != SFIP_SUCCESS) - LogMessage("Invalid source IP address provided: %s\n", sipstr); + appid_log(nullptr, TRACE_INFO_LEVEL, "Invalid source IP address provided: %s\n", sipstr); else if (constraints.sip.is_set()) constraints.sip_flag = true; } @@ -302,7 +301,7 @@ static int enable_debug(lua_State* L) if (dipstr) { if (constraints.dip.set(dipstr) != SFIP_SUCCESS) - LogMessage("Invalid destination IP address provided: %s\n", dipstr); + appid_log(nullptr, TRACE_INFO_LEVEL, "Invalid destination IP address provided: %s\n", dipstr); else if (constraints.dip.is_set()) constraints.dip_flag = true; } @@ -427,8 +426,8 @@ static int reload_detectors(lua_State* L) { #endif getrusage(RUSAGE_SELF, &ru); - LogMessage("appid: MaxRss diff: %li\n", ru.ru_maxrss - prev_maxrss); - LogMessage("appid: patterns loaded: %u\n", odp_ctxt.get_pattern_count()); + appid_log(nullptr, TRACE_INFO_LEVEL, "appid: MaxRss diff: %li\n", ru.ru_maxrss - prev_maxrss); + appid_log(nullptr, TRACE_INFO_LEVEL, "appid: patterns loaded: %u\n", odp_ctxt.get_pattern_count()); #ifdef REG_TEST } #endif @@ -488,12 +487,8 @@ void AppIdModule::set_trace(const Trace* trace) const const TraceOption* AppIdModule::get_trace_options() const { -#ifndef DEBUG_MSGS - return nullptr; -#else static const TraceOption appid_trace_options(nullptr, 0, nullptr); return &appid_trace_options; -#endif } ProfileStats* AppIdModule::get_profile() const diff --git a/src/network_inspectors/appid/appid_module.h b/src/network_inspectors/appid/appid_module.h index b86307b25..1e1b60615 100644 --- a/src/network_inspectors/appid/appid_module.h +++ b/src/network_inspectors/appid/appid_module.h @@ -46,7 +46,6 @@ extern THREAD_LOCAL const snort::Trace* appid_trace; #define MOD_HELP "application and service identification" #define MOD_USAGE snort::Module::GLOBAL - class AppIdReloadTuner : public snort::ReloadResourceTuner { public: diff --git a/src/network_inspectors/appid/appid_service_event_handler.cc b/src/network_inspectors/appid/appid_service_event_handler.cc index e85f81183..c7d5a5481 100644 --- a/src/network_inspectors/appid/appid_service_event_handler.cc +++ b/src/network_inspectors/appid/appid_service_event_handler.cc @@ -60,12 +60,8 @@ void AppIdServiceEventHandler::handle(DataEvent&, Flow* flow) asd = AppIdSession::allocate_session(p, p->get_ip_proto_next(), dir, inspector, *pkt_thread_odp_ctxt); if (appidDebug->is_enabled()) - { appidDebug->activate(flow, asd, inspector.get_ctxt().config.log_all_sessions); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s New AppId session at service event\n", - appidDebug->get_debug_session()); - } + appid_log(p, TRACE_DEBUG_LEVEL, "New AppId session at service event\n"); } else if (asd->get_odp_ctxt_version() != pkt_thread_odp_ctxt->get_version()) return; // Skip detection for sessions using old odp context after odp reload @@ -76,14 +72,11 @@ void AppIdServiceEventHandler::handle(DataEvent&, Flow* flow) if (!asd->has_no_service_candidate()) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s No service inspector\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "No service inspector\n"); return; } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s No service candidate and no inspector\n", appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "No service candidate and no inspector\n"); const SfIp* service_ip; uint16_t port; diff --git a/src/network_inspectors/appid/appid_session.cc b/src/network_inspectors/appid/appid_session.cc index f3f31c446..d8162ab7a 100644 --- a/src/network_inspectors/appid/appid_session.cc +++ b/src/network_inspectors/appid/appid_session.cc @@ -28,7 +28,6 @@ #include #include "flow/flow_stash.h" -#include "log/messages.h" #include "main/snort_config.h" #include "managers/inspector_manager.h" #include "profiler/profiler.h" @@ -38,6 +37,7 @@ #include "stream/stream.h" #include "target_based/snort_protocols.h" #include "time/packet_time.h" +#include "trace/trace.h" #include "app_info_table.h" #include "appid_config.h" @@ -214,9 +214,8 @@ AppIdSession* AppIdSession::create_future_session(const Packet* ctrlPkt, const S if (type == PktType::NONE) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Failed to create a related flow - invalid protocol %u\n", - appidDebug->get_debug_session(), (unsigned)proto); + appid_log(ctrlPkt, TRACE_DEBUG_LEVEL, "Failed to create a related flow - invalid protocol %u\n", + (unsigned)proto); return nullptr; } @@ -237,27 +236,19 @@ AppIdSession* AppIdSession::create_future_session(const Packet* ctrlPkt, const S cliPort, srvIp, srvPort, snort_protocol_id, asd, swap_app_direction, false, bidirectional, expect_persist)) { - if (appidDebug->is_active()) - { - sfip_ntop(cliIp, src_ip, sizeof(src_ip)); - sfip_ntop(srvIp, dst_ip, sizeof(dst_ip)); - LogMessage("AppIdDbg %s Failed to create a related flow for %s-%u -> %s-%u %u\n", - appidDebug->get_debug_session(), src_ip, (unsigned)cliPort, dst_ip, - (unsigned)srvPort, (unsigned)proto); - } + sfip_ntop(cliIp, src_ip, sizeof(src_ip)); + sfip_ntop(srvIp, dst_ip, sizeof(dst_ip)); + appid_log(ctrlPkt, TRACE_DEBUG_LEVEL, "Failed to create a related flow for %s-%u -> %s-%u %u\n", + src_ip, (unsigned)cliPort, dst_ip, (unsigned)srvPort, (unsigned)proto); delete asd; asd = nullptr; } else { - if (appidDebug->is_active()) - { - sfip_ntop(cliIp, src_ip, sizeof(src_ip)); - sfip_ntop(srvIp, dst_ip, sizeof(dst_ip)); - LogMessage("AppIdDbg %s Related flow created for %s-%u -> %s-%u %u\n", - appidDebug->get_debug_session(), - src_ip, (unsigned)cliPort, dst_ip, (unsigned)srvPort, (unsigned)proto); - } + sfip_ntop(cliIp, src_ip, sizeof(src_ip)); + sfip_ntop(srvIp, dst_ip, sizeof(dst_ip)); + appid_log(ctrlPkt, TRACE_DEBUG_LEVEL, "Related flow created for %s-%u -> %s-%u %u\n", + src_ip, (unsigned)cliPort, dst_ip, (unsigned)srvPort, (unsigned)proto); asd->in_expected_cache = true; } @@ -394,9 +385,7 @@ void AppIdSession::check_ssl_detection_restart(AppidChangeBits& change_bits, encrypted.referred_id = pick_ss_referred_payload_app_id(); reinit_session_data(change_bits, curr_tp_appid_ctxt); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSL decryption is available, restarting app detection\n", - appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "SSL decryption is available, restarting app detection\n"); // APPID_SESSION_ENCRYPTED is set upon receiving a command which upgrades the session to // SSL. Next packet after the command will have encrypted traffic. In the case of a @@ -416,9 +405,7 @@ void AppIdSession::check_tunnel_detection_restart() if (!hsession or !hsession->get_tunnel()) return; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Found HTTP Tunnel, restarting app Detection\n", - appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Found HTTP Tunnel, restarting app Detection\n"); // service if (api.service.get_id() == api.service.get_port_service_id()) @@ -552,9 +539,8 @@ void AppIdSession::examine_ssl_metadata(AppidChangeBits& change_bits) if (tsession->get_tls_handshake_done() and api.payload.get_id() == APP_ID_NONE) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s End of SSL/TLS handshake detected with no payloadAppId, " - "so setting to unknown\n", appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "End of SSL/TLS handshake detected with no payloadAppId, " + "so setting to unknown\n"); api.payload.set_id(APP_ID_UNKNOWN); } } @@ -1221,16 +1207,12 @@ void AppIdSession::publish_appid_event(AppidChangeBits& change_bits, const Packe AppidEvent app_event(change_bits, is_httpx, httpx_stream_index, api, p); DataBus::publish(AppIdInspector::get_pub_id(), AppIdEventIds::ANY_CHANGE, app_event, p.flow); - if (appidDebug->is_active()) - { - std::string str; - change_bits_to_string(change_bits, str); - if (is_httpx) - LogMessage("AppIdDbg %s Published event for changes: %s for HTTPX stream index %u\n", - appidDebug->get_debug_session(), str.c_str(), httpx_stream_index); - else - LogMessage("AppIdDbg %s Published event for changes: %s\n", - appidDebug->get_debug_session(), str.c_str()); - } + std::string str; + change_bits_to_string(change_bits, str); + if (is_httpx) + appid_log(&p, TRACE_DEBUG_LEVEL, "Published event for changes: %s for HTTPX stream index %u\n", + str.c_str(), httpx_stream_index); + else + appid_log(&p, TRACE_DEBUG_LEVEL, "Published event for changes: %s\n", str.c_str()); } diff --git a/src/network_inspectors/appid/appid_ssh_event_handler.cc b/src/network_inspectors/appid/appid_ssh_event_handler.cc index efd3e840b..c70b70c1c 100644 --- a/src/network_inspectors/appid/appid_ssh_event_handler.cc +++ b/src/network_inspectors/appid/appid_ssh_event_handler.cc @@ -62,9 +62,8 @@ static bool handle_protocol(SshEvent& event, SshAppIdInfo* fd) size_t version_len = (size_t)(version_end - version_begin); fd->version.assign(version_begin, version_len); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler read SSH version string with vendor %s and version %s\n", - appidDebug->get_debug_session(), fd->vendor.c_str(), fd->version.c_str()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "SSH event handler read SSH version string with vendor %s and version %s\n", + fd->vendor.c_str(), fd->version.c_str()); return true; } @@ -89,16 +88,12 @@ static void client_success(const SshAppIdInfo& fd, AppIdSession& asd, AppidChang if (table.has_pattern(fd.vendor)) { client_id = table.get_appid(fd.vendor); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler identified client with AppId %u\n", - appidDebug->get_debug_session(), client_id); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "SSH event handler identified client with AppId %u\n", client_id); } else { client_id = APP_ID_SSH; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler client detected, but vendor not recognized\n", - appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "SSH event handler client detected, but vendor not recognized\n"); } asd.set_client_id(client_id); @@ -142,9 +137,7 @@ static void handle_success(SshEventFlowData& data, const SshEvent& event, service_success(data.service_info, *event.get_packet(), asd, change_bits); client_success(data.client_info, asd, change_bits); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler service detected\n", - appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "SSH event handler service detected\n"); } @@ -170,14 +163,11 @@ void SshEventHandler::handle(DataEvent& event, Flow* flow) return; SshEventFlowData* data = (SshEventFlowData* )asd->get_flow_data(id); + Packet* p = DetectionEngine::get_current_packet(); if (data and data->failed) { - if (appidDebug->is_active()) - { - LogMessage("AppIdDbg %s SSH detection failed, ignoring event\n", - appidDebug->get_debug_session()); - } + appid_log(p, TRACE_DEBUG_LEVEL, "SSH detection failed, ignoring event\n"); return; } @@ -206,16 +196,15 @@ void SshEventHandler::handle(DataEvent& event, Flow* flow) { if (asd->get_session_flags(APPID_SESSION_EARLY_SSH_DETECTED)) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Early detection of SSH\n", appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "Early detection of SSH\n"); handle_success(*data, ssh_event, *asd, change_bits); asd->publish_appid_event(change_bits, *ssh_event.get_packet()); asd->clear_session_flags(APPID_SESSION_EARLY_SSH_DETECTED); } } - else if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler received unsupported protocol %s\n", - appidDebug->get_debug_session(), ssh_event.get_version_str().c_str()); + else + appid_log(p, TRACE_DEBUG_LEVEL, "SSH event handler received unsupported protocol %s\n", + ssh_event.get_version_str().c_str()); break; @@ -223,23 +212,17 @@ void SshEventHandler::handle(DataEvent& event, Flow* flow) switch (ssh_event.get_validation_result()) { case SSH_VALID_KEXINIT: - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler received valid key exchange\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "SSH event handler received valid key exchange\n"); fd->finished = true; break; case SSH_INVALID_KEXINIT: - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler received invalid key exchange\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "SSH event handler received invalid key exchange\n"); handle_failure(*asd, *data); break; case SSH_INVALID_VERSION: - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SSH event handler received invalid version\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "SSH event handler received invalid version\n"); handle_failure(*asd, *data); break; diff --git a/src/network_inspectors/appid/client_plugins/client_discovery.cc b/src/network_inspectors/appid/client_plugins/client_discovery.cc index a69b8cb18..da661210d 100644 --- a/src/network_inspectors/appid/client_plugins/client_discovery.cc +++ b/src/network_inspectors/appid/client_plugins/client_discovery.cc @@ -268,10 +268,9 @@ void ClientDiscovery::exec_client_detectors(AppIdSession& asd, Packet* p, { AppIdDiscoveryArgs disco_args(p->data, p->dsize, direction, asd, p, change_bits); ret = asd.client_detector->validate(disco_args); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s %s client detector returned %s (%d)\n", - appidDebug->get_debug_session(), asd.client_detector->get_log_name().c_str(), - asd.client_detector->get_code_string((APPID_STATUS_CODE)ret), ret); + appid_log(p, TRACE_DEBUG_LEVEL, "%s client detector returned %s (%d)\n", + asd.client_detector->get_log_name().c_str(), + asd.client_detector->get_code_string((APPID_STATUS_CODE)ret), ret); } else { @@ -279,10 +278,9 @@ void ClientDiscovery::exec_client_detectors(AppIdSession& asd, Packet* p, { AppIdDiscoveryArgs disco_args(p->data, p->dsize, direction, asd, p, change_bits); int result = kv->second->validate(disco_args); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s %s client candidate returned %s (%d)\n", - appidDebug->get_debug_session(), kv->second->get_log_name().c_str(), - kv->second->get_code_string((APPID_STATUS_CODE)result), result); + appid_log(p, TRACE_DEBUG_LEVEL, "%s client candidate returned %s (%d)\n", + kv->second->get_log_name().c_str(), + kv->second->get_code_string((APPID_STATUS_CODE)result), result); if (result == APPID_SUCCESS) { diff --git a/src/network_inspectors/appid/client_plugins/client_discovery.h b/src/network_inspectors/appid/client_plugins/client_discovery.h index e92dc2b91..b9c1a6063 100644 --- a/src/network_inspectors/appid/client_plugins/client_discovery.h +++ b/src/network_inspectors/appid/client_plugins/client_discovery.h @@ -23,7 +23,6 @@ #define CLIENT_DISCOVERY_H #include "flow/flow.h" -#include "log/messages.h" #include "appid_discovery.h" #include "appid_types.h" diff --git a/src/network_inspectors/appid/client_plugins/eve_ca_patterns.cc b/src/network_inspectors/appid/client_plugins/eve_ca_patterns.cc index 86e0dab88..5f0bb9bf3 100644 --- a/src/network_inspectors/appid/client_plugins/eve_ca_patterns.cc +++ b/src/network_inspectors/appid/client_plugins/eve_ca_patterns.cc @@ -26,7 +26,6 @@ #include -#include "log/messages.h" #include "managers/inspector_manager.h" #include "utils/util.h" #include "appid_debug.h" @@ -43,7 +42,7 @@ void EveCaPatternMatchers::add_eve_ca_pattern(AppId app_id, const string& patter if (match != eve_ca_load_list.end()) { if ((*match)->app_id != app_id) - WarningMessage("appid: detector %s - process name '%s' for client app %d is already " + appid_log(nullptr, TRACE_WARNING_LEVEL, "appid: detector %s - process name '%s' for client app %d is already " "mapped to client app %d\n", detector.c_str(), (*match)->pattern.c_str(), app_id, (*match)->app_id); } @@ -113,7 +112,7 @@ void EveCaPatternMatchers::finalize_patterns() AppIdInspector* inspector = (AppIdInspector*) InspectorManager::get_inspector(MOD_NAME, true); if (inspector and inspector->get_ctxt().config.log_eve_process_client_mappings) - LogMessage("Adding EVE Client App pattern %d %s %d\n", + appid_log(nullptr, TRACE_INFO_LEVEL, "Adding EVE Client App pattern %d %s %d\n", p->app_id, p->pattern.c_str(), p->confidence); #endif } diff --git a/src/network_inspectors/appid/client_plugins/test/eve_ca_patterns_test.cc b/src/network_inspectors/appid/client_plugins/test/eve_ca_patterns_test.cc index 03f2509c2..a2a1f65f2 100644 --- a/src/network_inspectors/appid/client_plugins/test/eve_ca_patterns_test.cc +++ b/src/network_inspectors/appid/client_plugins/test/eve_ca_patterns_test.cc @@ -50,6 +50,7 @@ Inspector* InspectorManager::get_inspector(char const*, bool, const snort::Snort AppIdContext* ctxt; AppIdContext& AppIdInspector::get_ctxt() const { return *ctxt; } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } TEST_GROUP(eve_ca_patterns_tests) { diff --git a/src/network_inspectors/appid/detector_plugins/detector_sip.cc b/src/network_inspectors/appid/detector_plugins/detector_sip.cc index c2c1c259a..30a8ee431 100644 --- a/src/network_inspectors/appid/detector_plugins/detector_sip.cc +++ b/src/network_inspectors/appid/detector_plugins/detector_sip.cc @@ -447,9 +447,7 @@ void SipEventHandler::service_handler(SipEvent& sip_event, AppIdSession& asd, asd.set_session_flags(APPID_SESSION_CONTINUE); service->add_service(change_bits, asd, sip_event.get_packet(), direction, APP_ID_SIP, ss->vendor[0] ? ss->vendor : nullptr); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Sip service detected. Setting APPID_SESSION_CONTINUE flag\n", - appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Sip service detected. Setting APPID_SESSION_CONTINUE flag\n"); } } } diff --git a/src/network_inspectors/appid/detector_plugins/http_url_patterns.cc b/src/network_inspectors/appid/detector_plugins/http_url_patterns.cc index a21fe421d..864ea2c8e 100644 --- a/src/network_inspectors/appid/detector_plugins/http_url_patterns.cc +++ b/src/network_inspectors/appid/detector_plugins/http_url_patterns.cc @@ -28,11 +28,11 @@ #include "http_url_patterns.h" #include "app_info_table.h" +#include "appid_debug.h" #include "appid_module.h" #include "appid_http_session.h" #include "appid_session.h" #include "appid_utils/sf_mlmp.h" -#include "log/messages.h" #include "protocols/packet.h" using namespace snort; @@ -1684,7 +1684,7 @@ uint32_t HttpPatternMatchers::parse_multiple_http_patterns(const char* pattern, for (unsigned i = 0; i <= partNum; i++) snort_free((void*)parts[i].pattern); - ErrorMessage("Failed to allocate memory"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Failed to allocate memory"); return 0; } partNum++; diff --git a/src/network_inspectors/appid/detector_plugins/http_url_patterns.h b/src/network_inspectors/appid/detector_plugins/http_url_patterns.h index 55e60a813..5f75fc57c 100644 --- a/src/network_inspectors/appid/detector_plugins/http_url_patterns.h +++ b/src/network_inspectors/appid/detector_plugins/http_url_patterns.h @@ -26,10 +26,11 @@ #include #include "flow/flow.h" -#include "log/messages.h" #include "search_engines/search_tool.h" +#include "trace/trace.h" #include "utils/util.h" +#include "appid_debug.h" #include "appid_types.h" #include "appid_utils/sf_mlmp.h" #include "application_ids.h" @@ -101,13 +102,13 @@ struct DetectorHTTPPattern { if( !pat ) { - snort::ErrorMessage("HTTP pattern string is null."); + appid_log(nullptr, TRACE_ERROR_LEVEL, "HTTP pattern string is null."); return false; } if (seq < SINGLE || seq > USER_AGENT_HEADER) { - snort::ErrorMessage("Invalid HTTP DHP Sequence."); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Invalid HTTP DHP Sequence."); return false; } diff --git a/src/network_inspectors/appid/detector_plugins/test/detector_plugins_mock.h b/src/network_inspectors/appid/detector_plugins/test/detector_plugins_mock.h index 40863e12c..0cd5c8c6f 100644 --- a/src/network_inspectors/appid/detector_plugins/test/detector_plugins_mock.h +++ b/src/network_inspectors/appid/detector_plugins/test/detector_plugins_mock.h @@ -27,10 +27,7 @@ namespace snort { // Stubs for messages -void ErrorMessage(const char*,...) { } // LCOV_EXCL_START -void WarningMessage(const char*,...) { } -void LogMessage(const char*,...) { } void ParseWarning(WarningGroup, const char*, ...) { } // LCOV_EXCL_STOP diff --git a/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc b/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc index 5929a5bed..cd0f38c25 100644 --- a/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc +++ b/src/network_inspectors/appid/detector_plugins/test/http_url_patterns_test.cc @@ -91,6 +91,7 @@ AlpnPatternMatchers::~AlpnPatternMatchers() = default; CipPatternMatchers::~CipPatternMatchers() = default; void AppIdModule::reset_stats() {} bool AppIdInspector::configure(snort::SnortConfig*) { return true; } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } TEST_GROUP(http_url_patterns_tests) { diff --git a/src/network_inspectors/appid/host_port_app_cache.cc b/src/network_inspectors/appid/host_port_app_cache.cc index b1cc7eaa9..abb7788e9 100644 --- a/src/network_inspectors/appid/host_port_app_cache.cc +++ b/src/network_inspectors/appid/host_port_app_cache.cc @@ -26,10 +26,10 @@ #include #include "host_port_app_cache.h" -#include "log/messages.h" #include "main/thread.h" #include "managers/inspector_manager.h" #include "appid_config.h" +#include "appid_debug.h" #include "appid_inspector.h" using namespace snort; @@ -233,7 +233,7 @@ void HostPortCache::dump() HostPortVal hv = kv.second; inet_ntop(AF_INET6, &hk.ip, inet_buffer, sizeof(inet_buffer)); - LogMessage("\tip=%s, \tport %d, \tip_proto %u, \ttype=%u, \tappId=%d\n", + appid_log(nullptr, TRACE_INFO_LEVEL, "\tip=%s, \tport %d, \tip_proto %u, \ttype=%u, \tappId=%d\n", inet_buffer, hk.port, (unsigned)hk.proto, hv.type, hv.appId); } } diff --git a/src/network_inspectors/appid/lua_detector_api.cc b/src/network_inspectors/appid/lua_detector_api.cc index 318b3dfed..355bad87a 100644 --- a/src/network_inspectors/appid/lua_detector_api.cc +++ b/src/network_inspectors/appid/lua_detector_api.cc @@ -32,7 +32,6 @@ #include "framework/mpse.h" #include "host_tracker/cache_allocator.cc" #include "host_tracker/host_cache.h" -#include "log/messages.h" #include "main/snort_config.h" #include "main/snort_types.h" #include "managers/mpse_manager.h" @@ -157,7 +156,7 @@ static inline int toipprotocol(lua_State *L, int index, if (tmp_proto > (unsigned)IpProtocol::RESERVED) { if (print_err) - ErrorMessage("Invalid protocol value %u\n", tmp_proto); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Invalid protocol value %u\n", tmp_proto); return -1; } @@ -211,7 +210,7 @@ static int service_init(lua_State* L) } } - ErrorMessage("%s: attempted setting validator/fini to non-function\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "%s: attempted setting validator/fini to non-function\n", ud->sd->get_name().c_str()); lua_pop(L, 1); return 0; @@ -322,20 +321,20 @@ static int detector_log_message(lua_State* L) switch (level) { case LUA_LOG_CRITICAL: - FatalError("%s:%s\n", name.c_str(), message); + appid_log(nullptr, TRACE_CRITICAL_LEVEL, "%s:%s\n", name.c_str(), message); break; case LUA_LOG_ERR: - ErrorMessage("%s:%s\n", name.c_str(), message); + appid_log(nullptr, TRACE_ERROR_LEVEL, "%s:%s\n", name.c_str(), message); break; case LUA_LOG_WARN: - WarningMessage("%s:%s\n", name.c_str(), message); + appid_log(nullptr, TRACE_WARNING_LEVEL, "%s:%s\n", name.c_str(), message); break; case LUA_LOG_NOTICE: case LUA_LOG_INFO: - LogMessage("%s:%s\n", name.c_str(), message); + appid_log(nullptr, TRACE_INFO_LEVEL, "%s:%s\n", name.c_str(), message); break; case LUA_LOG_TRACE: @@ -519,7 +518,7 @@ static int service_set_validator(lua_State* L) lua_getfield(L, -1, pValidator); if (!lua_isfunction(L, -1)) { - ErrorMessage("%s: attempted setting validator to non-function\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "%s: attempted setting validator to non-function\n", ud->sd->get_name().c_str()); lua_pop(L, 1); @@ -709,7 +708,7 @@ static int detector_get_pcre_groups(lua_State* L) if (re == nullptr) { - ErrorMessage("PCRE compilation failed at offset %d: %s\n", erroffset, error); + appid_log(lsd->ldp.pkt, TRACE_ERROR_LEVEL, "PCRE compilation failed at offset %d: %s\n", erroffset, error); return 0; } @@ -729,12 +728,13 @@ static int detector_get_pcre_groups(lua_State* L) { /*overflow of matches */ rc = OVECCOUNT / 3; - WarningMessage("ovector only has room for %d captured substrings\n", rc - 1); + appid_log(lsd->ldp.pkt, TRACE_WARNING_LEVEL, "ovector only has room for %d captured substrings\n", rc - 1); } if (!lua_checkstack(L, rc)) { - WarningMessage("Cannot grow Lua stack by %d slots to hold PCRE matches\n", rc); + appid_log(lsd->ldp.pkt, TRACE_WARNING_LEVEL, "Cannot grow Lua stack by %d slots to hold " + "PCRE matches\n", rc); return 0; } @@ -748,7 +748,7 @@ static int detector_get_pcre_groups(lua_State* L) { // log errors except no matches if (rc != PCRE_ERROR_NOMATCH) - WarningMessage("PCRE regular expression group match failed. rc: %d\n", rc); + appid_log(lsd->ldp.pkt, TRACE_WARNING_LEVEL, "PCRE regular expression group match failed. rc: %d\n", rc); rc = 0; } @@ -774,7 +774,7 @@ static int detector_get_substr(lua_State* L) unsigned int substr_len = lua_tonumber(L, 3); if (offset + substr_len > lsd->ldp.size) { - WarningMessage("Requested substr end offset %d is greater than data size %d\n", + appid_log(lsd->ldp.pkt, TRACE_WARNING_LEVEL, "Requested substr end offset %d is greater than data size %d\n", offset + substr_len, lsd->ldp.size); return 0; } @@ -1106,7 +1106,7 @@ static int add_alpn_to_service_mapping(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid alpn service string: appid %u.\n", appid); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid alpn service string: appid %u.\n", appid); return 0; } const std::string service_name(tmp_string); @@ -1142,7 +1142,7 @@ static int add_process_to_client_mapping(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid eve process_name string: appid %u.\n", appid); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid eve process_name string: appid %u.\n", appid); return 0; } const std::string process_name(tmp_string); @@ -1198,7 +1198,8 @@ static int detector_add_http_pattern(lua_State* L) enum httpPatternType pat_type = (enum httpPatternType)lua_tointeger(L, ++index); if (pat_type < HTTP_PAYLOAD or pat_type > HTTP_URL) { - ErrorMessage("appid: Invalid HTTP pattern type in %s.\n", ud->get_detector()->get_name().c_str()); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid HTTP pattern type in %s.\n", + ud->get_detector()->get_name().c_str()); return 0; } @@ -1214,7 +1215,8 @@ static int detector_add_http_pattern(lua_State* L) const uint8_t* pattern_str = (const uint8_t*)lua_tolstring(L, ++index, &pattern_size); if (!pattern_str or !pattern_size) { - ErrorMessage("appid: Invalid HTTP pattern string in %s.\n", ud->get_detector()->get_name().c_str()); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid HTTP pattern string in %s.\n", + ud->get_detector()->get_name().c_str()); return 0; } @@ -1250,7 +1252,7 @@ static int detector_add_ssl_cert_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid SSL Host pattern string in %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid SSL Host pattern string in %s.\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -1273,8 +1275,8 @@ static int detector_add_ssl_cert_regex_pattern(lua_State* L) const FastPatternConfig* const fp = SnortConfig::get_conf()->fast_pattern_config; if (!MpseManager::is_regex_capable(fp->get_search_api())){ - WarningMessage("WARNING: appid: Regex patterns require usage of regex capable search engine like hyperscan in %s\n", - ud->get_detector()->get_name().c_str()); + appid_log(nullptr, TRACE_WARNING_LEVEL, "WARNING: appid: Regex patterns require usage of " + "regex capable search engine like hyperscan in %s\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -1286,7 +1288,7 @@ static int detector_add_ssl_cert_regex_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid SSL Host regex pattern string in %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid SSL Host regex pattern string in %s.\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -1316,7 +1318,7 @@ static int detector_add_ssl_cname_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid SSL CN pattern string in %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid SSL CN pattern string in %s.\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -1339,8 +1341,8 @@ static int detector_add_ssl_cname_regex_pattern(lua_State* L) const FastPatternConfig* const fp = SnortConfig::get_conf()->fast_pattern_config; if (!MpseManager::is_regex_capable(fp->get_search_api())){ - WarningMessage("WARNING: appid: Regex patterns require usage of regex capable search engine like hyperscan in %s\n", - ud->get_detector()->get_name().c_str()); + appid_log(nullptr, TRACE_WARNING_LEVEL, "WARNING: appid: Regex patterns require usage of " + "regex capable search engine like hyperscan in %s\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -1353,7 +1355,7 @@ static int detector_add_ssl_cname_regex_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid SSL CN regex pattern string in %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid SSL CN regex pattern string in %s.\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -1384,7 +1386,7 @@ static int detector_add_dns_host_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &pattern_size); if (!tmp_string or !pattern_size) { - ErrorMessage("appid: Invalid DNS Host pattern string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid DNS Host pattern string.\n"); return 0; } @@ -1420,7 +1422,7 @@ static int detector_add_host_first_pkt_application(lua_State* L) if (!cidr_str or !ipaddr_size) { - ErrorMessage("%s: No IP address provided\n", "First packet API"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "First packet API: No IP address provided\n"); return 0; } @@ -1428,7 +1430,7 @@ static int detector_add_host_first_pkt_application(lua_State* L) { if (!convert_string_to_address(cidr_str, &ip_address)) { - ErrorMessage("%s: Invalid IP address: %s\n", "First packet API", cidr_str); + appid_log(nullptr, TRACE_ERROR_LEVEL, "First packet API: Invalid IP address: %s\n", cidr_str); return 0; } } @@ -1446,7 +1448,7 @@ static int detector_add_host_first_pkt_application(lua_State* L) if (!netip_str or !convert_string_to_address(netip_str, &ip_address)) { - ErrorMessage("%s: Invalid IP address: %s\n", "First packet API", netip_str); + appid_log(nullptr, TRACE_ERROR_LEVEL, "First packet API: Invalid IP address: %s\n", netip_str); return 0; } @@ -1457,14 +1459,14 @@ static int detector_add_host_first_pkt_application(lua_State* L) { if (bits < 0 or bits > 32) { - ErrorMessage("%s: Invalid IPv4 prefix range: %d\n","First packet API", bits); + appid_log(nullptr, TRACE_ERROR_LEVEL, "First packet API: Invalid IPv4 prefix range: %d\n", bits); return 0; } } else if (strchr(netip_str, ':')) { if (bits < 0 or bits > 128) { - ErrorMessage("%s: Invalid IPv6 prefix range: %d\n","First packet API", bits); + appid_log(nullptr, TRACE_ERROR_LEVEL, "First packet API: Invalid IPv6 prefix range: %d\n", bits); return 0; } } @@ -1491,7 +1493,7 @@ static int detector_add_host_first_pkt_application(lua_State* L) } else { - ErrorMessage("%s: Invalid prefix bit: %s\n", "First packet API", tokens[1].c_str()); + appid_log(nullptr, TRACE_ERROR_LEVEL, "First packet API: Invalid prefix bit: %s\n", tokens[1].c_str()); return 0; } } @@ -1507,7 +1509,7 @@ static int detector_add_host_first_pkt_application(lua_State* L) if (!ud->get_odp_ctxt().host_first_pkt_add( sc, &ip_address, netmask_parsed ? netmask32 : nullptr, (uint16_t)port, proto, protocol_appid, client_appid, web_appid, reinspect)) - ErrorMessage("%s:Failed to backend call first pkt add\n",__func__); + appid_log(nullptr, TRACE_ERROR_LEVEL, "%s:Failed to backend call first pkt add\n", __func__); return 0; } @@ -1529,7 +1531,7 @@ static int detector_add_host_port_application(lua_State* L) const char* ip_str= lua_tolstring(L, ++index, &ipaddr_size); if (!ip_str or !ipaddr_size or !convert_string_to_address(ip_str, &ip_address)) { - ErrorMessage("%s: Invalid IP address: %s\n",__func__, ip_str); + appid_log(nullptr, TRACE_ERROR_LEVEL, "%s: Invalid IP address: %s\n", __func__, ip_str); return 0; } @@ -1543,7 +1545,7 @@ static int detector_add_host_port_application(lua_State* L) lua_pop(L, 1); if (!ud->get_odp_ctxt().host_port_cache_add( sc, &ip_address, (uint16_t)port, proto, type, app_id)) - ErrorMessage("%s:Failed to backend call\n",__func__); + appid_log(nullptr, TRACE_ERROR_LEVEL, "%s:Failed to backend call\n", __func__); return 0; } @@ -1583,10 +1585,8 @@ static int detector_add_host_port_dynamic(lua_State* L) if (added) { AppIdSession::incr_inferred_svcs_ver(); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s " - "Added hostPortCache entry ip=%s, port %d, ip_proto %u, type=%u, appId=%d\n", - appidDebug->get_debug_session(), ip_str, port, (unsigned)proto, type, appid); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Added hostPortCache entry ip=%s, port %d, ip_proto %u, " + "type=%u, appId=%d\n", ip_str, port, (unsigned)proto, type, appid); } return 0; @@ -1606,7 +1606,7 @@ static int detector_add_content_type_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &stringSize); if (!tmp_string or !stringSize) { - ErrorMessage("appid: Invalid HTTP Header string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid HTTP Header string.\n"); return 0; } uint8_t* pattern = (uint8_t*)snort_strdup(tmp_string); @@ -1636,7 +1636,7 @@ static int detector_add_ssh_client_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &string_size); if (!tmp_string || !string_size) { - ErrorMessage("appid: Invalid SSH Client string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid SSH Client string.\n"); return 0; } std::string pattern(tmp_string); @@ -1669,14 +1669,15 @@ static int register_callback(lua_State* L, LuaObject& ud, AppInfoFlags flag) { if (entry->flags & flag) { - ErrorMessage("AppId: detector callback already registered for app %d\n", app_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "AppId: detector callback already registered for app %d\n", + app_id); return 1; } entry->flags |= flag; } else { - ErrorMessage("AppId: detector callback cannot be registered for invalid app %d\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "AppId: detector callback cannot be registered for invalid app %d\n", app_id); return 1; } @@ -1689,7 +1690,7 @@ static int register_callback(lua_State* L, LuaObject& ud, AppInfoFlags flag) if (!odp_thread_local_ctxt->get_lua_detector_mgr().insert_cb_detector(app_id, &ud)) { - ErrorMessage("AppId: detector callback already registered for app %d\n", app_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "AppId: detector callback already registered for app %d\n", app_id); return 1; } } @@ -1726,7 +1727,7 @@ static int detector_callback(const uint8_t* data, uint16_t size, AppidSessionDir // when an ODP detector triggers the detector callback to be called, there are some elements // in the stack. Checking here to make sure the number of elements is not too many if (lua_gettop(my_lua_state) > 20) - WarningMessage("appid: leak of %d lua stack elements before detector callback\n", + appid_log(&p, TRACE_WARNING_LEVEL, "appid: leak of %d lua stack elements before detector callback\n", lua_gettop(my_lua_state)); const string& cb_fn_name = ud.get_cb_fn_name(); @@ -1744,7 +1745,8 @@ static int detector_callback(const uint8_t* data, uint16_t size, AppidSessionDir lua_getfield(my_lua_state, -1, cb_fn_name.c_str()); if (lua_pcall(my_lua_state, 0, 1, 0)) { - ErrorMessage("Detector %s: Error validating %s\n", detector_name, lua_tostring(my_lua_state, -1)); + appid_log(&p, TRACE_ERROR_LEVEL, "Detector %s: Error validating %s\n", detector_name, + lua_tostring(my_lua_state, -1)); ud.lsd.ldp.pkt = nullptr; lua_settop(my_lua_state, 0); return -10; @@ -1757,7 +1759,7 @@ static int detector_callback(const uint8_t* data, uint16_t size, AppidSessionDir // retrieve result if (!lua_isnumber(my_lua_state, -1)) { - ErrorMessage("Detector %s: Validator returned non-numeric value\n", detector_name); + appid_log(&p, TRACE_ERROR_LEVEL, "Detector %s: Validator returned non-numeric value\n", detector_name); ud.lsd.ldp.pkt = nullptr; lua_settop(my_lua_state, 0); return -10; @@ -1791,9 +1793,8 @@ void check_detector_callback(const Packet& p, AppIdSession& asd, AppidSessionDir ud->set_running(true); int ret = detector_callback(p.data, p.dsize, dir, asd, p, *ud, change_bits); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s %s detector callback returned %d\n", appidDebug->get_debug_session(), - ud->get_detector()->get_name().empty() ? "UKNOWN" : ud->get_detector()->get_name().c_str(), ret); + appid_log(&p, TRACE_DEBUG_LEVEL, "%s detector callback returned %d\n", + ud->get_detector()->get_name().empty() ? "UKNOWN" : ud->get_detector()->get_name().c_str(), ret); ud->set_running(false); } } @@ -1807,7 +1808,7 @@ static int create_chp_application(AppId appIdInstance, unsigned app_type_flags, if (CHP_glossary->emplace(appIdInstance, new_app).second == false) { - ErrorMessage("LuaDetectorApi:Failed to add CHP for appId %d, instance %d", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Failed to add CHP for appId %d, instance %d", CHP_APPIDINSTANCE_TO_ID(appIdInstance), CHP_APPIDINSTANCE_TO_INSTANCE(appIdInstance)); snort_free(new_app); return -1; @@ -1834,7 +1835,8 @@ static int detector_chp_create_application(lua_State* L) // We only want one of these for each appId. if (CHP_glossary->find(appIdInstance) != CHP_glossary->end()) { - ErrorMessage("appid: Attempt to add more than one CHP for appId %d - use CHPMultiCreateApp.\n", appId); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Attempt to add more than one CHP for appId %d - " + "use CHPMultiCreateApp.\n", appId); return 0; } @@ -1852,7 +1854,7 @@ static inline int get_chp_pattern_type(lua_State* L, int index, HttpFieldIds* pa *pattern_type = (HttpFieldIds)lua_tointeger(L, index); if (*pattern_type >= NUM_HTTP_FIELDS) { - ErrorMessage("appid: Invalid CHP Action pattern type.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid CHP Action pattern type.\n"); return -1; } return 0; @@ -1868,7 +1870,7 @@ static inline int get_chp_pattern_data_and_size(lua_State* L, int index, char** // non-empty pattern required if (!tmp_string or !*pattern_size) { - ErrorMessage("appid: Invalid CHP Action PATTERN string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid CHP Action PATTERN string.\n"); return -1; } *pattern_data = snort_strdup(tmp_string); @@ -1880,7 +1882,8 @@ static inline int get_chp_action_type(lua_State* L, int index, ActionType& actio action_type = (ActionType)lua_tointeger(L, index); if (action_type < NO_ACTION or action_type > MAX_ACTION_TYPE) { - WarningMessage("appid: Unsupported CHP Action type: %d, possible version mismatch.\n", action_type); + appid_log(nullptr, TRACE_WARNING_LEVEL, "appid: Unsupported CHP Action type: %d, " + "possible version mismatch.\n", action_type); return -1; } @@ -1920,10 +1923,9 @@ static int add_chp_pattern_action(AppId appIdInstance, int isKeyPattern, HttpFie auto chp_entry = CHP_glossary->find(appIdInstance); if (chp_entry == CHP_glossary->end() or !chp_entry->second) { - ErrorMessage("appid: Invalid attempt to add a CHP action for unknown appId %d, instance %d. " - "- pattern:\"%s\" - action \"%s\"\n", CHP_APPIDINSTANCE_TO_ID(appIdInstance), - CHP_APPIDINSTANCE_TO_INSTANCE(appIdInstance), patternData, - optionalActionData ? optionalActionData : ""); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid attempt to add a CHP action for " + "unknown appId %d, instance %d. - pattern:\"%s\" - action \"%s\"\n", CHP_APPIDINSTANCE_TO_ID(appIdInstance), + CHP_APPIDINSTANCE_TO_INSTANCE(appIdInstance), patternData, optionalActionData ? optionalActionData : ""); snort_free(patternData); if (optionalActionData) snort_free(optionalActionData); @@ -2044,7 +2046,7 @@ static int detector_create_chp_multi_application(lua_State* L) // We only want a maximum of these for each appId. if (instance == CHP_APPID_INSTANCE_MAX) { - ErrorMessage("LuaDetectorApi:Attempt to create more than %d CHP for appId %d", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Attempt to create more than %d CHP for appId %d", CHP_APPID_INSTANCE_MAX, appId); return 0; } @@ -2171,7 +2173,7 @@ static int detector_add_length_app_cache(lua_State* L) or ((sequence_cnt == 0) or (sequence_cnt > LENGTH_SEQUENCE_CNT_MAX)) or ((sequence_str == nullptr) or (strlen(sequence_str) == 0))) { - ErrorMessage("LuaDetectorApi:Invalid input (%d,%u,%u,\"%s\")!", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Invalid input (%d,%u,%u,\"%s\")!", appId, (unsigned)proto, (unsigned)sequence_cnt, sequence_str ? sequence_str : ""); lua_pushnumber(L, -1); return 1; @@ -2195,7 +2197,7 @@ static int detector_add_length_app_cache(lua_State* L) length_sequence.sequence[i].direction = APP_ID_FROM_RESPONDER; break; default: - ErrorMessage("LuaDetectorApi:Invalid sequence string (\"%s\")!", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Invalid sequence string (\"%s\")!", sequence_str); lua_pushnumber(L, -1); return 1; @@ -2204,7 +2206,7 @@ static int detector_add_length_app_cache(lua_State* L) if (*str_ptr != '/') { - ErrorMessage("LuaDetectorApi:Invalid sequence string (\"%s\")!", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Invalid sequence string (\"%s\")!", sequence_str); lua_pushnumber(L, -1); return 1; @@ -2215,7 +2217,7 @@ static int detector_add_length_app_cache(lua_State* L) if (length == 0) { - ErrorMessage("LuaDetectorApi:Invalid sequence string (\"%s\")!", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Invalid sequence string (\"%s\")!", sequence_str); lua_pushnumber(L, -1); return 1; @@ -2231,7 +2233,7 @@ static int detector_add_length_app_cache(lua_State* L) if ((!last_one and (*str_ptr != ',')) or (last_one and (*str_ptr != 0))) { - ErrorMessage("LuaDetectorApi:Invalid sequence string (\"%s\")!", + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Invalid sequence string (\"%s\")!", sequence_str); lua_pushnumber(L, -1); return 1; @@ -2241,7 +2243,7 @@ static int detector_add_length_app_cache(lua_State* L) if (!ud->get_odp_ctxt().length_cache_add(length_sequence, appId)) { - ErrorMessage("LuaDetectorApi:Could not add entry to cache!"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "LuaDetectorApi:Could not add entry to cache!"); lua_pushnumber(L, -1); return 1; } @@ -2272,9 +2274,8 @@ static int detector_add_url_application(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &host_pattern_size); if (!tmp_string or !host_pattern_size) { - ErrorMessage( - "appid: Invalid host pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid host pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); return 0; } else @@ -2286,9 +2287,8 @@ static int detector_add_url_application(lua_State* L) tmp_string = lua_tolstring(L, ++index, &path_pattern_size); if (!tmp_string or !path_pattern_size) { - ErrorMessage( - "appid: Invalid path pattern string: service_id %u; client_id %u; payload %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid path pattern string: service_id %u; " + "client_id %u; payload %u.\n", service_id, client_id, payload_id); snort_free(host_pattern); return 0; } @@ -2301,9 +2301,8 @@ static int detector_add_url_application(lua_State* L) tmp_string = lua_tolstring(L, ++index, &schemePatternSize); if (!tmp_string or !schemePatternSize) { - ErrorMessage( - "appid: Invalid scheme pattern string: service_id %u; client_id %u; payload %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid scheme pattern string: service_id %u; " + "client_id %u; payload %u.\n", service_id, client_id, payload_id); snort_free(path_pattern); snort_free(host_pattern); return 0; @@ -2365,9 +2364,8 @@ static int detector_add_rtmp_url(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &host_pattern_size); if (!tmp_string or !host_pattern_size) { - ErrorMessage( - "appid: Invalid RTMP host pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid RTMP host pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); return 0; } uint8_t* host_pattern = (uint8_t*)snort_strdup(tmp_string); @@ -2377,9 +2375,8 @@ static int detector_add_rtmp_url(lua_State* L) tmp_string = lua_tolstring(L, ++index, &path_pattern_size); if (!tmp_string or !path_pattern_size) { - ErrorMessage( - "appid: Invalid RTMP path pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid RTMP path pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); snort_free(host_pattern); return 0; } @@ -2390,9 +2387,8 @@ static int detector_add_rtmp_url(lua_State* L) tmp_string = lua_tolstring(L, ++index, &schemePatternSize); if (!tmp_string or !schemePatternSize) { - ErrorMessage( - "appid: Invalid RTMP scheme pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid RTMP scheme pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); snort_free(path_pattern); snort_free(host_pattern); return 0; @@ -2452,7 +2448,7 @@ static int detector_add_sip_user_agent(lua_State* L) const char* client_version = lua_tostring(L, ++index); if (!client_version) { - ErrorMessage("appid: Invalid sip client version string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid sip client version string.\n"); return 0; } @@ -2461,7 +2457,7 @@ static int detector_add_sip_user_agent(lua_State* L) const char* ua_pattern = lua_tolstring(L, ++index, &ua_len); if (!ua_pattern or !ua_len) { - ErrorMessage("appid: Invalid sip ua pattern string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid sip ua pattern string.\n"); return 0; } @@ -2487,7 +2483,7 @@ static int create_custom_application(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &appNameLen); if (!tmp_string or !appNameLen) { - ErrorMessage("Invalid appName string."); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Invalid appName string.\n"); lua_pushnumber(L, APP_ID_NONE); return 1; /*number of results */ } @@ -2573,7 +2569,8 @@ static int add_http_pattern(lua_State* L) enum httpPatternType pat_type = (enum httpPatternType)lua_tointeger(L, ++index); if (pat_type < HTTP_PAYLOAD or pat_type > HTTP_URL) { - ErrorMessage("appid: Invalid HTTP pattern type in %s.\n", ud->get_detector()->get_name().c_str()); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid HTTP pattern type in %s.\n", + ud->get_detector()->get_name().c_str()); return 0; } @@ -2587,7 +2584,8 @@ static int add_http_pattern(lua_State* L) const uint8_t* pattern_str = (const uint8_t*)lua_tolstring(L, ++index, &pattern_size); if (!pattern_str or !pattern_size) { - ErrorMessage("appid: Invalid HTTP pattern string in %s.\n", ud->get_detector()->get_name().c_str()); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid HTTP pattern string in %s.\n", + ud->get_detector()->get_name().c_str()); return 0; } @@ -2625,9 +2623,8 @@ static int add_url_pattern(lua_State* L) const char* tmp_string = lua_tolstring(L, ++index, &host_pattern_size); if (!tmp_string or !host_pattern_size) { - ErrorMessage( - "appid: Invalid host pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid host pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); return 0; } host_pattern = (uint8_t*)snort_strdup(tmp_string); @@ -2638,9 +2635,8 @@ static int add_url_pattern(lua_State* L) tmp_string = lua_tolstring(L, ++index, &path_pattern_size); if (!tmp_string or !path_pattern_size) { - ErrorMessage( - "appid: Invalid path pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid path pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); snort_free(host_pattern); return 0; } @@ -2652,9 +2648,8 @@ static int add_url_pattern(lua_State* L) tmp_string = lua_tolstring(L, ++index, &schemePatternSize); if (!tmp_string or !schemePatternSize) { - ErrorMessage( - "appid: Invalid scheme pattern string: service_id %u; client_id %u; payload_id %u.\n", - service_id, client_id, payload_id); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid scheme pattern string: service_id %u; " + "client_id %u; payload_id %u.\n", service_id, client_id, payload_id); snort_free(path_pattern); snort_free(host_pattern); return 0; @@ -2721,7 +2716,7 @@ static int add_port_pattern_client(lua_State* L) if (appid <= APP_ID_NONE or !pattern or !pattern_size or (protocol != IpProtocol::TCP and protocol != IpProtocol::UDP)) { - ErrorMessage("appid: addPortPatternClient() - Invalid input in %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: addPortPatternClient() - Invalid input in %s.\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -2778,7 +2773,7 @@ static int add_port_pattern_service(lua_State* L) if (appid <= APP_ID_NONE or !pattern or !pattern_size or (protocol != IpProtocol::TCP and protocol != IpProtocol::UDP)) { - ErrorMessage("appid: addPortPatternService() - Invalid input in %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: addPortPatternService() - Invalid input in %s.\n", ud->get_detector()->get_name().c_str()); return 0; } @@ -2813,7 +2808,7 @@ static int detector_add_sip_server(lua_State* L) const char* client_version = lua_tostring(L, ++index); if (!client_version) { - ErrorMessage("appid: Invalid sip client version string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid sip client version string.\n"); return 0; } @@ -2822,7 +2817,7 @@ static int detector_add_sip_server(lua_State* L) const char* server_pattern = lua_tolstring(L, ++index, &pattern_size); if (!server_pattern or !pattern_size) { - ErrorMessage("appid: Invalid sip server pattern string.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "appid: Invalid sip server pattern string.\n"); return 0; } @@ -3335,7 +3330,7 @@ int LuaStateDescriptor::lua_validate(AppIdDiscoveryArgs& args) auto my_lua_state = lua_detector_mgr.L; if (!my_lua_state) { - ErrorMessage("lua detector %s: no LUA state\n", package_info.name.c_str()); + appid_log(args.pkt, TRACE_ERROR_LEVEL, "lua detector %s: no LUA state\n", package_info.name.c_str()); lua_settop(my_lua_state, 0); return APPID_ENULL; } @@ -3364,7 +3359,7 @@ int LuaStateDescriptor::lua_validate(AppIdDiscoveryArgs& args) // Runtime Lua errors are suppressed in production code since detectors are written for // efficiency and with defensive minimum checks. Errors are dealt as exceptions // that don't impact processing by other detectors or future packets by the same detector. - ErrorMessage("lua detector %s: error validating %s\n", + appid_log(args.pkt, TRACE_ERROR_LEVEL, "lua detector %s: error validating %s\n", package_info.name.c_str(), lua_tostring(my_lua_state, -1)); ldp.pkt = nullptr; lua_detector_mgr.free_detector_flow(); @@ -3379,7 +3374,8 @@ int LuaStateDescriptor::lua_validate(AppIdDiscoveryArgs& args) /* retrieve result */ if (!lua_isnumber(my_lua_state, -1)) { - ErrorMessage("lua detector %s: returned non-numeric value\n", package_info.name.c_str()); + appid_log(args.pkt, TRACE_ERROR_LEVEL, "lua detector %s: returned non-numeric value\n", + package_info.name.c_str()); ldp.pkt = nullptr; lua_settop(my_lua_state, 0); return APPID_ENULL; @@ -3472,8 +3468,8 @@ int LuaServiceDetector::validate(AppIdDiscoveryArgs& args) { auto my_lua_state = odp_thread_local_ctxt->get_lua_detector_mgr().L; if (lua_gettop(my_lua_state)) - WarningMessage("appid: leak of %d lua stack elements before service validate\n", - lua_gettop(my_lua_state)); + appid_log(args.pkt, TRACE_WARNING_LEVEL, "appid: leak of %d lua stack elements before service validate\n", + lua_gettop(my_lua_state)); std::string name = this->name + "_"; lua_getglobal(my_lua_state, name.c_str()); @@ -3548,7 +3544,7 @@ int LuaClientDetector::validate(AppIdDiscoveryArgs& args) { auto my_lua_state = odp_thread_local_ctxt->get_lua_detector_mgr().L; if (lua_gettop(my_lua_state)) - WarningMessage("appid: leak of %d lua stack elements before client validate\n", + appid_log(args.pkt, TRACE_WARNING_LEVEL, "appid: leak of %d lua stack elements before client validate\n", lua_gettop(my_lua_state)); std::string name = this->name + "_"; diff --git a/src/network_inspectors/appid/lua_detector_module.cc b/src/network_inspectors/appid/lua_detector_module.cc index 9ac9afc9e..e555adab6 100644 --- a/src/network_inspectors/appid/lua_detector_module.cc +++ b/src/network_inspectors/appid/lua_detector_module.cc @@ -32,13 +32,13 @@ #include #include "appid_config.h" +#include "appid_debug.h" #include "appid_inspector.h" #include "lua_detector_util.h" #include "lua_detector_api.h" #include "lua_detector_flow_api.h" #include "utils/util.h" #include "utils/sflsq.h" -#include "log/messages.h" using namespace snort; using namespace std; @@ -165,7 +165,7 @@ LuaDetectorManager::~LuaDetectorManager() { auto L = this->L; if (lua_gettop(L)) - WarningMessage("appid: leak of %d lua stack elements before detector unload\n", + appid_log(nullptr, TRACE_WARNING_LEVEL, "appid: leak of %d lua stack elements before detector unload\n", lua_gettop(L)); if (L) @@ -186,7 +186,7 @@ LuaDetectorManager::~LuaDetectorManager() if ( lua_pcall(L, 1, 1, 0) ) { - ErrorMessage("Could not cleanup the %s client app element: %s\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not cleanup the %s client app element: %s\n", lsd->package_info.name.c_str(), lua_tostring(L, -1)); } } @@ -209,19 +209,19 @@ void LuaDetectorManager::initialize(const SnortConfig* sc, AppIdContext& ctxt, b odp_thread_local_ctxt->set_lua_detector_mgr(*lua_detector_mgr); if (!lua_detector_mgr->L) - FatalError("Error - appid: can not create new luaState, instance=%u\n", - get_instance_id()); + appid_log(nullptr, is_control? TRACE_CRITICAL_LEVEL : TRACE_ERROR_LEVEL, + "Error - appid: can not create new luaState, instance=%u\n", get_instance_id()); if (reload) { - LogMessage("AppId Lua-Detectors : loading lua detectors in control thread\n"); + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId Lua-Detectors : loading lua detectors in control thread\n"); unsigned max_threads = ThreadConfig::get_instance_max(); for (unsigned i = 0 ; i < max_threads; i++) { lua_detector_mgr_list.emplace_back(new LuaDetectorManager(ctxt, 0)); if (!lua_detector_mgr_list[i]->L) - FatalError("Error - appid: can not create new luaState, instance=%u\n", i); + appid_log(nullptr, TRACE_CRITICAL_LEVEL, "Error - appid: can not create new luaState, instance=%u\n", i); } } @@ -295,7 +295,7 @@ static inline void set_lua_tracker_size(lua_State* L, uint32_t numTrackers) { lua_pushinteger (L, numTrackers); if (lua_pcall(L, 1, 0, 0) != 0 and init(L)) - ErrorMessage("Error - appid: activating lua detector. " + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: activating lua detector. " "Setting tracker size to %u failed.\n", numTrackers); } } @@ -311,7 +311,7 @@ static inline void set_lua_tracker_size(lua_State* L, uint32_t numTrackers) { lua_pushinteger (L, numTrackers); if (lua_pcall(L, 1, 0, 0) != 0 and init(L)) - ErrorMessage("Error - appid: setting tracker size\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: setting tracker size\n"); } } @@ -355,7 +355,7 @@ LuaObject* LuaDetectorManager::create_lua_detector(const char* detector_name, int c = detector_file.peek(); detector_file.close(); if (c != EOF) - ErrorMessage("Error - appid: can not read DetectorPackageInfo table from %s\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not read DetectorPackageInfo table from %s\n", detector_name); } if (!lua_isnil(L, -1)) // pop DetectorPackageInfo index if it was pushed @@ -366,7 +366,7 @@ LuaObject* LuaDetectorManager::create_lua_detector(const char* detector_name, if (!get_lua_field(L, -1, "name", log_name)) { if (init(L)) - ErrorMessage("Error - appid: can not read DetectorPackageInfo field 'name' from %s\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not read DetectorPackageInfo field 'name' from %s\n", detector_name); lua_pop(L, 1); return nullptr; @@ -375,7 +375,7 @@ LuaObject* LuaDetectorManager::create_lua_detector(const char* detector_name, if (!get_lua_field(L, -1, "proto", proto)) { if (init(L)) - ErrorMessage("Error - appid: can not read DetectorPackageInfo field 'proto' from %s\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not read DetectorPackageInfo field 'proto' from %s\n", detector_name); lua_pop(L, 1); return nullptr; @@ -398,7 +398,7 @@ LuaObject* LuaDetectorManager::create_lua_detector(const char* detector_name, detector_name, log_name, is_custom, proto, L, ctxt.get_odp_ctxt()); } else if (init(L)) - ErrorMessage("Error - appid: can not read DetectorPackageInfo field" + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not read DetectorPackageInfo field" " 'client' or 'server' from %s\n", detector_name); lua_pop(L, 1); // pop server table @@ -423,7 +423,7 @@ bool LuaDetectorManager::load_detector(char* detector_filename, bool is_custom, if (luaL_loadbuffer(L, buf.c_str(), buf.length(), detector_filename)) { if (init(L)) - ErrorMessage("Error - appid: can not load Lua detector, %s\n", lua_tostring(L, -1)); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not load Lua detector, %s\n", lua_tostring(L, -1)); lua_pop(L, 1); return false; } @@ -440,14 +440,14 @@ bool LuaDetectorManager::load_detector(char* detector_filename, bool is_custom, if (luaL_loadfile(L, detector_filename)) { if (init(L)) - ErrorMessage("Error - appid: can not load Lua detector, %s\n", lua_tostring(L, -1)); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not load Lua detector, %s\n", lua_tostring(L, -1)); lua_pop(L, 1); return false; } if (reload and lua_dump(L, dump, &buf)) { if (init(L)) - ErrorMessage("Error - appid: can not compile Lua detector, %s\n", lua_tostring(L, -1)); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not compile Lua detector, %s\n", lua_tostring(L, -1)); lua_pop(L, 1); return false; } @@ -476,7 +476,7 @@ bool LuaDetectorManager::load_detector(char* detector_filename, bool is_custom, lua_setfenv(L, -2); if (lua_pcall(L, 0, 0, 0)) { - ErrorMessage("Error - appid: can not set env of Lua detector %s : %s\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not set env of Lua detector %s : %s\n", detector_filename, lua_tostring(L, -1)); lua_pop(L, 1); return false; @@ -501,7 +501,7 @@ void LuaDetectorManager::load_lua_detectors(const char* path, bool is_custom, bo if (rval == 0 ) { if (lua_gettop(L)) - WarningMessage("appid: leak of %d lua stack elements before detector load\n", + appid_log(nullptr, TRACE_WARNING_LEVEL, "appid: leak of %d lua stack elements before detector load\n", lua_gettop(L)); string buf; @@ -517,7 +517,7 @@ void LuaDetectorManager::load_lua_detectors(const char* path, bool is_custom, bo } if (size > MAX_LUA_DETECTOR_FILE_SIZE) { - ErrorMessage("Error - appid: can not load Lua detector %s : \ + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not load Lua detector %s : \ size exceeded maximum limit\n", globs.gl_pathv[n]); file.close(); continue; @@ -595,7 +595,7 @@ void LuaDetectorManager::activate_lua_detectors(const SnortConfig* sc) list::iterator lo = allocated_objects.begin(); if (lua_gettop(L)) - WarningMessage("appid: leak of %d lua stack elements before detector activate\n", + appid_log(nullptr, TRACE_WARNING_LEVEL, "appid: leak of %d lua stack elements before detector activate\n", lua_gettop(L)); while (lo != allocated_objects.end()) @@ -606,7 +606,7 @@ void LuaDetectorManager::activate_lua_detectors(const SnortConfig* sc) if (!lua_isfunction(L, -1)) { if (init(L)) - ErrorMessage("Error - appid: can not load DetectorInit function from %s\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not load DetectorInit function from %s\n", (*lo)->get_detector()->get_name().c_str()); if (!(*lo)->get_detector()->is_custom_detector()) num_odp_detectors--; @@ -628,7 +628,7 @@ void LuaDetectorManager::activate_lua_detectors(const SnortConfig* sc) if (lua_pcall(L, 2, 1, 0)) { if (init(L)) - ErrorMessage("Error - appid: can not run DetectorInit, %s\n", lua_tostring(L, -1)); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Error - appid: can not run DetectorInit, %s\n", lua_tostring(L, -1)); if (!(*lo)->get_detector()->is_custom_detector()) num_odp_detectors--; lua_settop(L, 0); @@ -647,7 +647,7 @@ void LuaDetectorManager::activate_lua_detectors(const SnortConfig* sc) void LuaDetectorManager::list_lua_detectors() { - LogMessage("AppId Lua-Detector Stats: instance %u, odp detectors %zu, custom detectors %zu," + appid_log(nullptr, TRACE_INFO_LEVEL, "AppId Lua-Detector Stats: instance %u, odp detectors %zu, custom detectors %zu," " total memory %d kb\n", get_instance_id(), num_odp_detectors, (allocated_objects.size() - num_odp_detectors), lua_gc(L, LUA_GCCOUNT, 0)); } diff --git a/src/network_inspectors/appid/service_plugins/alpn_patterns.cc b/src/network_inspectors/appid/service_plugins/alpn_patterns.cc index 10e0e0882..0fe26ff41 100644 --- a/src/network_inspectors/appid/service_plugins/alpn_patterns.cc +++ b/src/network_inspectors/appid/service_plugins/alpn_patterns.cc @@ -26,7 +26,6 @@ #include -#include "log/messages.h" #include "managers/inspector_manager.h" #include "utils/util.h" #include "appid_debug.h" @@ -43,7 +42,7 @@ void AlpnPatternMatchers::add_alpn_pattern(AppId app_id, const string& pattern_s if (match != alpn_load_list.end()) { if ((*match)->app_id != app_id) - WarningMessage("appid: detector %s - alpn '%s' for service app %d is already " + appid_log(nullptr, TRACE_WARNING_LEVEL, "appid: detector %s - alpn '%s' for service app %d is already " "mapped to service app %d\n", detector.c_str(), (*match)->pattern.c_str(), app_id, (*match)->app_id); } @@ -108,7 +107,7 @@ void AlpnPatternMatchers::finalize_patterns() AppIdInspector* inspector = (AppIdInspector*) InspectorManager::get_inspector(MOD_NAME, true); if (inspector and inspector->get_ctxt().config.log_alpn_service_mappings) - LogMessage("Adding ALPN service App pattern %d %s\n", + appid_log(nullptr, TRACE_INFO_LEVEL, "Adding ALPN service App pattern %d %s\n", p->app_id, p->pattern.c_str()); #endif } diff --git a/src/network_inspectors/appid/service_plugins/service_discovery.cc b/src/network_inspectors/appid/service_plugins/service_discovery.cc index 65bf6820a..775343e51 100644 --- a/src/network_inspectors/appid/service_plugins/service_discovery.cc +++ b/src/network_inspectors/appid/service_plugins/service_discovery.cc @@ -192,7 +192,7 @@ int ServiceDiscovery::add_service_port(AppIdDetector* detector, const ServiceDet } else { - ErrorMessage("Invalid protocol (%u) specified for service %s.\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Invalid protocol (%u) specified for service %s.\n", (unsigned)pp.proto, service->get_name().c_str()); return 0; } @@ -437,8 +437,7 @@ int ServiceDiscovery::identify_service(AppIdSession& asd, Packet* p, if ( sds_state == ServiceState::FAILED ) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s No service match, failed state\n", appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "No service match, failed state\n"); fail_service(asd, p, dir, nullptr, sds); return APPID_NOMATCH; } @@ -472,10 +471,9 @@ int ServiceDiscovery::identify_service(AppIdSession& asd, Packet* p, else if (ret == APPID_NOT_COMPATIBLE) got_incompatible_service = true; asd.service_search_state = SESSION_SERVICE_SEARCH_STATE::PENDING; - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s %s service detector returned %s (%d)\n", - appidDebug->get_debug_session(), asd.service_detector->get_log_name().c_str(), - asd.service_detector->get_code_string((APPID_STATUS_CODE)ret), ret); + appid_log(p, TRACE_DEBUG_LEVEL, "%s service detector returned %s (%d)\n", + asd.service_detector->get_log_name().c_str(), + asd.service_detector->get_code_string((APPID_STATUS_CODE)ret), ret); } /* Try to find detectors based on ports and patterns. */ else if (!got_brute_force) @@ -497,10 +495,8 @@ int ServiceDiscovery::identify_service(AppIdSession& asd, Packet* p, int result; result = service->validate(args); - if ( appidDebug->is_active() ) - LogMessage("AppIdDbg %s %s service candidate returned %s (%d)\n", - appidDebug->get_debug_session(), service->get_log_name().c_str(), - service->get_code_string((APPID_STATUS_CODE)result), result); + appid_log(p, TRACE_DEBUG_LEVEL, "%s service candidate returned %s (%d)\n", + service->get_log_name().c_str(), service->get_code_string((APPID_STATUS_CODE)result), result); if ( result == APPID_SUCCESS ) { @@ -529,9 +525,8 @@ int ServiceDiscovery::identify_service(AppIdSession& asd, Packet* p, // below needs to be removed. if (asd.has_no_service_inspector() or (proto == IpProtocol::UDP)) got_fail_service = true; - else if (appidDebug->is_active() and !asd.service_detector and !asd.has_no_service_candidate()) - LogMessage("AppIdDbg %s No service candidate, wait for snort service inspection\n", - appidDebug->get_debug_session()); + else if (!asd.service_detector and !asd.has_no_service_candidate()) + appid_log(p, TRACE_DEBUG_LEVEL, "No service candidate, wait for snort service inspection\n"); asd.set_no_service_candidate(); } @@ -545,9 +540,8 @@ int ServiceDiscovery::identify_service(AppIdSession& asd, Packet* p, sds = AppIdServiceState::add(ip, proto, port, group, asd.asid, asd.is_decrypted(), true); // Don't log this if fail service is not due to empty list - if (appidDebug->is_active() and !(got_fail_service and asd.service_detector)) - LogMessage("AppIdDbg %s No service %s\n", appidDebug->get_debug_session(), - got_fail_service ? "candidate" : "detector"); + if (!(got_fail_service and asd.service_detector)) + appid_log(p, TRACE_DEBUG_LEVEL, "No service %s\n", got_fail_service ? "candidate" : "detector"); got_fail_service = true; fail_service(asd, p, dir, nullptr, sds); ret = APPID_NOMATCH; @@ -654,8 +648,7 @@ bool ServiceDiscovery::do_service_discovery(AppIdSession& asd, Packet* p, if ( entry && entry->service_detector && !(entry->flags & APPINFO_FLAG_SERVICE_ADDITIONAL) ) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Stop service detection\n", appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "Stop service detection\n"); asd.stop_service_inspection(p, direction); } } diff --git a/src/network_inspectors/appid/service_plugins/service_discovery.h b/src/network_inspectors/appid/service_plugins/service_discovery.h index 20d472cf8..cffcf171c 100644 --- a/src/network_inspectors/appid/service_plugins/service_discovery.h +++ b/src/network_inspectors/appid/service_plugins/service_discovery.h @@ -28,7 +28,6 @@ #include #include "flow/flow.h" -#include "log/messages.h" #include "utils/sflsq.h" #include "appid_types.h" diff --git a/src/network_inspectors/appid/service_plugins/service_rexec.cc b/src/network_inspectors/appid/service_plugins/service_rexec.cc index 03732066b..fafefba2b 100644 --- a/src/network_inspectors/appid/service_plugins/service_rexec.cc +++ b/src/network_inspectors/appid/service_plugins/service_rexec.cc @@ -133,8 +133,7 @@ int RexecServiceDetector::validate(AppIdDiscoveryArgs& args) data_add(args.asd, rd, &rexec_free_state); rd->state = REXEC_STATE_PORT; } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s rexec state %d\n", appidDebug->get_debug_session(), rd->state); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "rexec state %d\n", rd->state); switch (rd->state) { diff --git a/src/network_inspectors/appid/service_plugins/service_rshell.cc b/src/network_inspectors/appid/service_plugins/service_rshell.cc index 736dbe79d..9462b9e36 100644 --- a/src/network_inspectors/appid/service_plugins/service_rshell.cc +++ b/src/network_inspectors/appid/service_plugins/service_rshell.cc @@ -129,8 +129,7 @@ int RshellServiceDetector::validate(AppIdDiscoveryArgs& args) rd->state = RSHELL_STATE_PORT; } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s RSHELL state %d\n", appidDebug->get_debug_session(), rd->state); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "RSHELL state %d\n",rd->state); switch (rd->state) { diff --git a/src/network_inspectors/appid/service_plugins/service_snmp.cc b/src/network_inspectors/appid/service_plugins/service_snmp.cc index bc4603dfc..2d4f69e06 100644 --- a/src/network_inspectors/appid/service_plugins/service_snmp.cc +++ b/src/network_inspectors/appid/service_plugins/service_snmp.cc @@ -26,7 +26,6 @@ #include "service_snmp.h" #include "detection/ips_context.h" -#include "log/messages.h" #include "protocols/packet.h" #include "app_info_table.h" @@ -410,8 +409,7 @@ int SnmpServiceDetector::validate(AppIdDiscoveryArgs& args) if (snmp_verify_packet(&data, data+size, &pdu, &version)) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SNMP payload verify failed\n", appidDebug->get_debug_session()); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "SNMP payload verify failed\n"); if (args.asd.get_session_flags(APPID_SESSION_UDP_REVERSED)) { if (args.dir == APP_ID_FROM_RESPONDER) @@ -428,8 +426,7 @@ int SnmpServiceDetector::validate(AppIdDiscoveryArgs& args) } } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s SNMP state %d\n", appidDebug->get_debug_session(), sd->state); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "SNMP state %d\n", sd->state); switch (sd->state) { diff --git a/src/network_inspectors/appid/service_plugins/service_tftp.cc b/src/network_inspectors/appid/service_plugins/service_tftp.cc index 8e1ee468a..24d66b6cf 100644 --- a/src/network_inspectors/appid/service_plugins/service_tftp.cc +++ b/src/network_inspectors/appid/service_plugins/service_tftp.cc @@ -144,8 +144,7 @@ int TftpServiceDetector::validate(AppIdDiscoveryArgs& args) data_add(args.asd, td, &snort_free); td->state = TFTP_STATE_CONNECTION; } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP state %d\n", appidDebug->get_debug_session(), td->state); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP state %d\n", td->state); if (td->state == TFTP_STATE_CONNECTION && args.dir == APP_ID_FROM_RESPONDER) goto fail; @@ -216,13 +215,10 @@ int TftpServiceDetector::validate(AppIdDiscoveryArgs& args) case TFTP_STATE_TRANSFER: if ((mode=tftp_verify_header(data, size, &block)) < 0) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP failed to verify\n", appidDebug->get_debug_session()); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP failed to verify\n"); goto fail; } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP mode %d and block %u\n", appidDebug->get_debug_session(), - mode, (unsigned)block); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP mode %d and block %u\n", mode, (unsigned)block); if (mode == TFTP_STATE_ACK) { if (block != 0) @@ -259,13 +255,11 @@ int TftpServiceDetector::validate(AppIdDiscoveryArgs& args) goto fail; else { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP failed to verify\n", appidDebug->get_debug_session()); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP failed to verify\n"); goto bail; } } - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP mode %d\n", appidDebug->get_debug_session(), mode); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP mode %d\n", mode); if (mode == TFTP_STATE_ERROR) { td->state = TFTP_STATE_TRANSFER; @@ -273,8 +267,7 @@ int TftpServiceDetector::validate(AppIdDiscoveryArgs& args) } if (args.dir == APP_ID_FROM_INITIATOR && mode != TFTP_STATE_DATA) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP bad mode\n", appidDebug->get_debug_session()); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP bad mode\n"); goto bail; } if (args.dir == APP_ID_FROM_RESPONDER && mode != TFTP_STATE_ACK) @@ -322,8 +315,7 @@ inprocess: return APPID_INPROCESS; success: - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s TFTP success\n", appidDebug->get_debug_session()); + appid_log(args.pkt, TRACE_DEBUG_LEVEL, "TFTP success\n"); return add_service(args.change_bits, args.asd, args.pkt, args.dir, APP_ID_TFTP); bail: diff --git a/src/network_inspectors/appid/service_plugins/test/alpn_patterns_tests.cc b/src/network_inspectors/appid/service_plugins/test/alpn_patterns_tests.cc index 3b5ec9050..5f3e9dfba 100644 --- a/src/network_inspectors/appid/service_plugins/test/alpn_patterns_tests.cc +++ b/src/network_inspectors/appid/service_plugins/test/alpn_patterns_tests.cc @@ -50,6 +50,7 @@ Inspector* InspectorManager::get_inspector(char const*, bool, const snort::Snort AppIdContext* ctxt; AppIdContext& AppIdInspector::get_ctxt() const { return *ctxt; } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } TEST_GROUP(alpn_patterns_tests) { diff --git a/src/network_inspectors/appid/service_plugins/test/service_alpn_patterns_mock.h b/src/network_inspectors/appid/service_plugins/test/service_alpn_patterns_mock.h index cd0638813..b01124e25 100644 --- a/src/network_inspectors/appid/service_plugins/test/service_alpn_patterns_mock.h +++ b/src/network_inspectors/appid/service_plugins/test/service_alpn_patterns_mock.h @@ -21,10 +21,6 @@ namespace snort { -// Stubs for messages -void LogMessage(const char*,...) { } -void WarningMessage(const char*,...) { } - // Stubs for search_tool.cc SearchTool::SearchTool(bool) { } SearchTool::~SearchTool() = default; diff --git a/src/network_inspectors/appid/service_state.cc b/src/network_inspectors/appid/service_state.cc index cb8611893..7340038ef 100644 --- a/src/network_inspectors/appid/service_state.cc +++ b/src/network_inspectors/appid/service_state.cc @@ -28,7 +28,6 @@ #include #include -#include "log/messages.h" #include "sfip/sf_ip.h" #include "time/packet_time.h" #include "utils/util.h" @@ -65,18 +64,14 @@ ServiceDetector* ServiceDiscoveryState::select_detector_by_brute_force(IpProtoco if ( !tcp_brute_force_mgr ) tcp_brute_force_mgr = new AppIdDetectorList(IpProtocol::TCP, sd); service = tcp_brute_force_mgr->next(); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Brute-force state %s\n", appidDebug->get_debug_session(), - service? "" : "failed - no more TCP detectors"); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Brute-force state %s\n", service? "" : "failed - no more TCP detectors"); } else if (proto == IpProtocol::UDP) { if ( !udp_brute_force_mgr ) udp_brute_force_mgr = new AppIdDetectorList(IpProtocol::UDP, sd); service = udp_brute_force_mgr->next(); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Brute-force state %s\n", appidDebug->get_debug_session(), - service? "" : "failed - no more UDP detectors"); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Brute-force state %s\n", service? "" : "failed - no more UDP detectors"); } else service = nullptr; @@ -238,7 +233,8 @@ void AppIdServiceState::remove(const SfIp* ip, IpProtocol proto, uint16_t port, ipstr[0] = 0; sfip_ntop(ip, ipstr, sizeof(ipstr)); - ErrorMessage("Failed to remove from hash: %s:%u:%hu\n", ipstr, (unsigned)proto, port); + appid_log(CURRENT_PACKET, TRACE_ERROR_LEVEL, "Failed to remove from hash: %s:%u:%hu\n", ipstr, + (unsigned)proto, port); } } diff --git a/src/network_inspectors/appid/test/app_info_table_test.cc b/src/network_inspectors/appid/test/app_info_table_test.cc index 42ed8e837..96fb66482 100644 --- a/src/network_inspectors/appid/test/app_info_table_test.cc +++ b/src/network_inspectors/appid/test/app_info_table_test.cc @@ -41,9 +41,6 @@ char* snort_strdup(const char* str) return p; } -void ErrorMessage(const char*,...) { } -void WarningMessage(const char*,...) { } -void LogMessage(const char*,...) { } void ParseWarning(WarningGroup, const char*, ...) { } const char* UT_TEST_APP_NAME_001 = "ut_app_001"; diff --git a/src/network_inspectors/appid/test/appid_debug_test.cc b/src/network_inspectors/appid/test/appid_debug_test.cc index 59f54212c..b5d154384 100644 --- a/src/network_inspectors/appid/test/appid_debug_test.cc +++ b/src/network_inspectors/appid/test/appid_debug_test.cc @@ -41,12 +41,23 @@ namespace snort { unsigned get_instance_id() { return 3; } +Packet::Packet(bool) {} +Packet::~Packet() = default; FlowData::FlowData(unsigned, Inspector*) { } FlowData::~FlowData() = default; AppIdSessionApi::AppIdSessionApi(const AppIdSession* asd, const SfIp& ip) : StashGenericObject(STASH_GENERIC_OBJECT_APPID), asd(asd), initiator_ip(ip) {} +[[noreturn]] void FatalError(const char*,...) { exit(-1); } +void ErrorMessage(const char*, va_list&) { } +void WarningMessage(const char*, va_list&) { } +void LogMessage(const char*, va_list&) { } +void TraceApi::filter(snort::Packet const&) { } +void trace_vprintf(const char*, unsigned char, const char*, const Packet*, const char*, va_list) { } +uint8_t TraceApi::get_constraints_generation() { return 0; } } +THREAD_LOCAL const snort::Trace* appid_trace; + void ApplicationDescriptor::set_id(const Packet&, AppIdSession&, AppidSessionDirection, AppId, AppidChangeBits&) { } class AppIdInspector { diff --git a/src/network_inspectors/appid/test/appid_discovery_test.cc b/src/network_inspectors/appid/test/appid_discovery_test.cc index 3080e4d60..60fcb096b 100644 --- a/src/network_inspectors/appid/test/appid_discovery_test.cc +++ b/src/network_inspectors/appid/test/appid_discovery_test.cc @@ -80,12 +80,9 @@ void Module::reset_stats() {} PegCount Module::get_global_count(char const*) const { return 0; } // Stubs for logs -void LogMessage(const char*,...) {} -void ErrorMessage(const char*,...) {} void LogLabel(const char*, FILE*) {} void LogText(const char*, FILE*) {} - // Stubs for utils char* snort_strdup(const char* str) { @@ -305,6 +302,8 @@ THREAD_LOCAL AppIdStats appid_stats; THREAD_LOCAL AppIdDebug* appidDebug = nullptr; void AppIdDebug::activate(const Flow*, const AppIdSession*, bool) { active = false; } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } + bool AppIdReloadTuner::tinit() { return false; } bool AppIdReloadTuner::tune_resources(unsigned int) diff --git a/src/network_inspectors/appid/test/appid_eve_process_event_handler_test.cc b/src/network_inspectors/appid/test/appid_eve_process_event_handler_test.cc index ee268b2a2..2659eae64 100644 --- a/src/network_inspectors/appid/test/appid_eve_process_event_handler_test.cc +++ b/src/network_inspectors/appid/test/appid_eve_process_event_handler_test.cc @@ -60,6 +60,8 @@ Packet* DetectionEngine::get_current_packet() } } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } + AppIdSession* AppIdSession::allocate_session(const Packet*, IpProtocol, AppidSessionDirection, AppIdInspector&, OdpContext&) { diff --git a/src/network_inspectors/appid/test/appid_http_event_test.cc b/src/network_inspectors/appid/test/appid_http_event_test.cc index feae9a717..f19f2af00 100644 --- a/src/network_inspectors/appid/test/appid_http_event_test.cc +++ b/src/network_inspectors/appid/test/appid_http_event_test.cc @@ -65,6 +65,8 @@ AppIdSessionApi::AppIdSessionApi(const AppIdSession*, const SfIp&) : StashGenericObject(STASH_GENERIC_OBJECT_APPID) {} } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } + const char* content_type = nullptr; const char* cookie = nullptr; const char* host = nullptr; diff --git a/src/network_inspectors/appid/test/appid_http_session_test.cc b/src/network_inspectors/appid/test/appid_http_session_test.cc index dd89907a8..8a3d306ca 100644 --- a/src/network_inspectors/appid/test/appid_http_session_test.cc +++ b/src/network_inspectors/appid/test/appid_http_session_test.cc @@ -49,6 +49,9 @@ using namespace snort; namespace snort { +Packet::Packet(bool) {} +Packet::~Packet() = default; +Packet* DetectionEngine::get_current_packet() { return nullptr; } AppIdSessionApi::AppIdSessionApi(const AppIdSession*, const SfIp&) : StashGenericObject(STASH_GENERIC_OBJECT_APPID) {} } @@ -60,6 +63,8 @@ const char* AppInfoManager::get_app_name(AppId) return ""; } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } + // HttpPatternMatchers mock functions void HttpPatternMatchers::scan_key_chp(ChpMatchDescriptor&) { @@ -205,7 +210,6 @@ TEST(appid_http_session, http_field_ids_enum_order) // to make sure the order of the HttpFieldIds has not changed // in appid_http_session.h. AppidChangeBits change_bits; - mock_hsession->set_field( (HttpFieldIds)0, new std::string("agent"), change_bits); mock_hsession->set_field( (HttpFieldIds)1, new std::string("host"), change_bits); mock_hsession->set_field( (HttpFieldIds)2, new std::string("referer"), change_bits); diff --git a/src/network_inspectors/appid/test/service_state_test.cc b/src/network_inspectors/appid/test/service_state_test.cc index 074f3fa35..cd840f9e3 100644 --- a/src/network_inspectors/appid/test/service_state_test.cc +++ b/src/network_inspectors/appid/test/service_state_test.cc @@ -30,16 +30,24 @@ namespace snort { +Packet::Packet(bool) { } +Packet::~Packet() = default; +Packet* DetectionEngine::get_current_packet() { return nullptr; } + // Stubs for logs char test_log[256]; +void LogMessage(const char* format, va_list& args) +{ + vsprintf(test_log, format, args); +} void LogMessage(const char* format,...) { va_list args; va_start(args, format); - vsprintf(test_log, format, args); + LogMessage(format, args); va_end(args); } -void ErrorMessage(const char*,...) {} + void LogLabel(const char*, FILE*) {} void LogText(const char* s, FILE*) { LogMessage("%s\n", s); } @@ -131,6 +139,13 @@ AlpnPatternMatchers::~AlpnPatternMatchers() = default; CipPatternMatchers::~CipPatternMatchers() = default; snort::SearchTool::SearchTool(bool) { } snort::SearchTool::~SearchTool() = default; +void appid_log(const snort::Packet*, unsigned char, char const* fmt, ...) +{ + va_list args; + va_start(args, fmt); + LogMessage(fmt, args); + va_end(args); +} TEST_GROUP(service_state_tests) { @@ -150,15 +165,14 @@ TEST(service_state_tests, select_detector_by_brute_force) { ServiceDiscovery sd; ServiceDiscoveryState sds; - // Testing end of brute-force walk for supported and unsupported protocols test_log[0] = '\0'; sds.select_detector_by_brute_force(IpProtocol::TCP, sd); - STRCMP_EQUAL(test_log, "AppIdDbg Brute-force state failed - no more TCP detectors\n"); + STRCMP_EQUAL(test_log, "Brute-force state failed - no more TCP detectors\n"); test_log[0] = '\0'; sds.select_detector_by_brute_force(IpProtocol::UDP, sd); - STRCMP_EQUAL(test_log, "AppIdDbg Brute-force state failed - no more UDP detectors\n"); + STRCMP_EQUAL(test_log, "Brute-force state failed - no more UDP detectors\n"); test_log[0] = '\0'; sds.select_detector_by_brute_force(IpProtocol::IP, sd); diff --git a/src/network_inspectors/appid/test/tp_lib_handler_test.cc b/src/network_inspectors/appid/test/tp_lib_handler_test.cc index 230bef82e..c05d189b0 100644 --- a/src/network_inspectors/appid/test/tp_lib_handler_test.cc +++ b/src/network_inspectors/appid/test/tp_lib_handler_test.cc @@ -68,6 +68,7 @@ void ServiceDiscovery::initialize(AppIdInspector&) { } void ServiceDiscovery::reload() { } int ServiceDiscovery::add_service_port(AppIdDetector*, const ServiceDetectorPort&) { return 0; } +void appid_log(const snort::Packet*, unsigned char, char const*, ...) { } TEST_GROUP(tp_lib_handler) { diff --git a/src/network_inspectors/appid/tp_appid_utils.cc b/src/network_inspectors/appid/tp_appid_utils.cc index 0bec1c740..f376fb0e4 100644 --- a/src/network_inspectors/appid/tp_appid_utils.cc +++ b/src/network_inspectors/appid/tp_appid_utils.cc @@ -26,7 +26,6 @@ #include #include -#include "log/messages.h" #include "profiler/profiler.h" #include "protocols/packet.h" #include "stream/stream.h" @@ -417,8 +416,7 @@ static inline void process_quic(AppIdSession& asd, if ( !asd.tsession->get_tls_host() and (field=attribute_data.quic_sni()) != nullptr ) { - if ( appidDebug->is_active() ) - LogMessage("AppIdDbg %s Flow is QUIC\n", appidDebug->get_debug_session()); + appid_log(CURRENT_PACKET, TRACE_DEBUG_LEVEL, "Flow is QUIC\n"); asd.tsession->set_tls_host(field->c_str(), field->size(), change_bits); if ( asd.get_service_id() <= APP_ID_NONE ) asd.set_service_appid_data(APP_ID_QUIC, change_bits); @@ -434,16 +432,13 @@ static inline void process_third_party_results(const Packet& p, AppIdSession& as if ( contains(proto_list, APP_ID_HTTP) ) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Flow is HTTP\n", appidDebug->get_debug_session()); + appid_log(&p, TRACE_DEBUG_LEVEL, "Flow is HTTP\n"); asd.set_session_flags(APPID_SESSION_HTTP_SESSION); } if ( contains(proto_list, APP_ID_SPDY) ) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Flow is SPDY\n", appidDebug->get_debug_session()); - + appid_log(&p, TRACE_DEBUG_LEVEL, "Flow is SPDY\n"); asd.set_session_flags(APPID_SESSION_HTTP_SESSION | APPID_SESSION_SPDY_SESSION); } @@ -498,9 +493,7 @@ static void set_tp_reinspect(AppIdSession& asd, const Packet* p, AppidSessionDir { asd.tp_reinspect_by_initiator = true; asd.set_session_flags(APPID_SESSION_APP_REINSPECT); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s 3rd party allow reinspect http\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "3rd party allow reinspect http\n"); asd.init_tpPackets = 0; asd.resp_tpPackets = 0; asd.clear_http_data(); @@ -529,8 +522,7 @@ bool do_tp_discovery(ThirdPartyAppIdContext& tp_appid_ctxt, AppIdSession& asd, I if ( p->ptrs.ip_api.tos() == 8 ) { asd.set_payload_id(APP_ID_SFTP); - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Payload is SFTP\n", appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "Payload is SFTP\n"); } return true; @@ -559,7 +551,7 @@ bool do_tp_discovery(ThirdPartyAppIdContext& tp_appid_ctxt, AppIdSession& asd, I TpAppIdCreateSession tpsf = tph->tpsession_factory(); if ( !(asd.tpsession = tpsf(tp_appid_ctxt)) ) { - ErrorMessage("Could not allocate asd.tpsession data"); + appid_log(p, TRACE_ERROR_LEVEL, "Could not allocate asd.tpsession data"); return false; } } @@ -585,12 +577,8 @@ bool do_tp_discovery(ThirdPartyAppIdContext& tp_appid_ctxt, AppIdSession& asd, I TP_SESSION_FLAG_TUNNELING | TP_SESSION_FLAG_FUTUREFLOW); } - if (appidDebug->is_active()) - { - const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(tp_app_id); - LogMessage("AppIdDbg %s 3rd party returned %s (%d)\n", - appidDebug->get_debug_session(), app_name ? app_name : "unknown", tp_app_id); - } + const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(tp_app_id); + appid_log(p, TRACE_DEBUG_LEVEL, "3rd party returned %s (%d)\n", app_name ? app_name : "unknown", tp_app_id); process_third_party_results(*p, asd, tp_confidence, tp_proto_list, tp_attribute_data, change_bits); @@ -603,9 +591,7 @@ bool do_tp_discovery(ThirdPartyAppIdContext& tp_appid_ctxt, AppIdSession& asd, I if (tp_app_id == APP_ID_SSH) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s Setting the ignore and early detection flag\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "Setting the ignore and early detection flag\n"); asd.get_odp_ctxt().get_app_info_mgr().set_app_info_flags(tp_app_id, APPINFO_FLAG_IGNORE); asd.set_session_flags(APPID_SESSION_EARLY_SSH_DETECTED); } @@ -624,9 +610,7 @@ bool do_tp_discovery(ThirdPartyAppIdContext& tp_appid_ctxt, AppIdSession& asd, I if ( app_info_flags & APPINFO_FLAG_IGNORE ) { - if (appidDebug->is_active()) - LogMessage("AppIdDbg %s 3rd party ignored\n", - appidDebug->get_debug_session()); + appid_log(p, TRACE_DEBUG_LEVEL, "3rd party ignored\n"); if (asd.get_session_flags(APPID_SESSION_HTTP_SESSION)) tp_app_id = APP_ID_HTTP; @@ -711,27 +695,19 @@ bool do_tp_discovery(ThirdPartyAppIdContext& tp_appid_ctxt, AppIdSession& asd, I //SSL policy determines IMAPS/POP3S etc before appId sees first server // packet asd.set_port_service_id(portAppId); - if (appidDebug->is_active()) - { - const char *service_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(tp_app_id); - const char *port_service_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(asd.get_port_service_id()); - LogMessage("AppIdDbg %s SSL is service %s (%d), portServiceAppId %s (%d)\n", - appidDebug->get_debug_session(), - service_name ? service_name : "unknown", tp_app_id, - port_service_name ? port_service_name : "unknown", asd.get_port_service_id()); - } + const char *service_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(tp_app_id); + const char *port_service_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(asd.get_port_service_id()); + appid_log(p, TRACE_DEBUG_LEVEL, "SSL is service %s (%d), portServiceAppId %s (%d)\n", + service_name ? service_name : "unknown", tp_app_id, + port_service_name ? port_service_name : "unknown", asd.get_port_service_id()); } else { if (!(asd.scan_flags & SCAN_SPOOFED_SNI_FLAG)) asd.set_tp_payload_app_id(*p, direction, tp_app_id, change_bits); tp_app_id = portAppId; - if (appidDebug->is_active()) - { - const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(tp_app_id); - LogMessage("AppIdDbg %s SSL is %s (%d)\n", appidDebug->get_debug_session(), - app_name ? app_name : "unknown", tp_app_id); - } + const char *app_name = asd.get_odp_ctxt().get_app_info_mgr().get_app_name(tp_app_id); + appid_log(p, TRACE_DEBUG_LEVEL, "SSL is %s (%d)\n", app_name ? app_name : "unknown", tp_app_id); } snort_app_id = APP_ID_SSL; } diff --git a/src/network_inspectors/appid/tp_lib_handler.cc b/src/network_inspectors/appid/tp_lib_handler.cc index 571f579f4..64cf7eb7a 100644 --- a/src/network_inspectors/appid/tp_lib_handler.cc +++ b/src/network_inspectors/appid/tp_lib_handler.cc @@ -25,8 +25,8 @@ #include #include "appid_config.h" +#include "appid_debug.h" -#include "log/messages.h" #include "trace/trace_api.h" #include "tp_lib_handler.h" @@ -43,7 +43,7 @@ bool TPLibHandler::load_callback(const char* const path) self->tp_so_handle = dlopen(path, RTLD_NOW | RTLD_LOCAL); if (self->tp_so_handle == nullptr) { - ErrorMessage("Failed to load 3rd party AppID library: %s - %s\n", path, dlerror()); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Failed to load 3rd party AppID library: %s - %s\n", path, dlerror()); return false; } @@ -69,7 +69,7 @@ bool TPLibHandler::load_callback(const char* const path) if (*(index->local_sym) == nullptr) { char* error; - ErrorMessage("AppId: Failed to resolve symbol: %s %s\n", index->lib_sym, + appid_log(nullptr, TRACE_ERROR_LEVEL, "AppId: Failed to resolve symbol: %s %s\n", index->lib_sym, (error = dlerror()) ? error : ""); dlclose(self->tp_so_handle); self->tp_so_handle = nullptr; @@ -107,7 +107,7 @@ ThirdPartyAppIdContext* TPLibHandler::create_tp_appid_ctxt(const AppIdConfig& co ThirdPartyAppIdContext* tp_appid_ctxt = self->tp_appid_create_ctxt(tp_config); if (tp_appid_ctxt == nullptr) { - ErrorMessage("Failed to create third party appId context.\n"); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Failed to create third party appId context.\n"); dlclose(self->tp_so_handle); self->tp_so_handle = nullptr; return nullptr; @@ -116,7 +116,7 @@ ThirdPartyAppIdContext* TPLibHandler::create_tp_appid_ctxt(const AppIdConfig& co if ( (tp_appid_ctxt->get_api_version() != THIRD_PARTY_APPID_API_VERSION) || (tp_appid_ctxt->module_name().empty()) ) { - ErrorMessage("Ignoring incomplete 3rd party AppID module (%s, %u, %s)!\n", + appid_log(nullptr, TRACE_ERROR_LEVEL, "Ignoring incomplete 3rd party AppID module (%s, %u, %s)!\n", config.tp_appid_path.c_str(), tp_appid_ctxt->get_api_version(), tp_appid_ctxt->module_name().empty() ? "empty" : tp_appid_ctxt->module_name().c_str()); @@ -139,7 +139,7 @@ void TPLibHandler::tfini() ret = self->tp_appid_tfini(); if (ret != 0) - ErrorMessage("Could not terminate packet thread in 3rd party AppID module (%d)!\n", ret); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not terminate packet thread in 3rd party AppID module (%d)!\n", ret); } void TPLibHandler::pfini() @@ -152,7 +152,7 @@ void TPLibHandler::pfini() ret = self->tp_appid_pfini(); if (ret != 0) - ErrorMessage("Could not terminate 3rd party AppID module (%d)!\n", ret); + appid_log(nullptr, TRACE_ERROR_LEVEL, "Could not terminate 3rd party AppID module (%d)!\n", ret); AppIdContext::delete_tp_appid_ctxt(); diff --git a/src/trace/trace.h b/src/trace/trace.h index ba8ba2fce..d95982e88 100644 --- a/src/trace/trace.h +++ b/src/trace/trace.h @@ -29,6 +29,7 @@ #define DEFAULT_TRACE_LOG_LEVEL 1 #define TRACE_CRITICAL_LEVEL 2 #define TRACE_ERROR_LEVEL 3 +#define TRACE_WARNING_LEVEL 4 #define TRACE_INFO_LEVEL 6 #define TRACE_DEBUG_LEVEL 7 #define DEFAULT_TRACE_OPTION_ID 0 diff --git a/src/trace/trace_api.h b/src/trace/trace_api.h index b61be450c..8f0097e64 100644 --- a/src/trace/trace_api.h +++ b/src/trace/trace_api.h @@ -121,6 +121,16 @@ static inline void trace_printf(TraceLevel log_level, va_end(ap); } +template +static inline void trace_printf(TraceLevel log_level, const snort::Trace* trace, TraceOptionID trace_option_id, + const snort::Packet* p, const char* fmt, va_list ap) +{ + if ( !trace_enabled(trace, trace_option_id, log_level, p) ) + return; + const char* trace_option_name = trace->option_name(trace_option_id); + trace_vprintf(trace->module_name(), log_level, trace_option_name, p, fmt, ap); +} + template static inline void trace_printf(TraceLevel log_level, const snort::Trace* trace, const snort::Packet* p,