Merge pull request #932 from IvanNardi/log

Log

15 files changed, 77 insertions, 43 deletions

diff --git a/example/ndpiReader.c b/example/ndpiReader.c
index e4745990c..a03c461be 100644
--- a/example/ndpiReader.c
+++ b/example/ndpiReader.c
@@ -383,7 +383,10 @@ static void help(u_int long_help) {
 	 "                            | 3 = port stats\n"
 	 "  -V <1-4>                  | nDPI logging level\n"
 	 "                            | 1 - trace, 2 - debug, 3 - full debug\n"
-	 "                            | >3 - full debug + dbg_proto = all\n"
+	 "                            | >3 - full debug + log enabled for all protocols (i.e. '-u all')\n"
+	 "  -u all|proto|num[,...]    | Enable logging only for such protocol(s)\n"
+	 "                            | If this flag is present multiple times (directly, or via '-V'),\n"
+	 "                            | only the last instance will be considered\n"
 	 "  -T <num>                  | Max number of TCP processed packets before giving up [default: %u]\n"
 	 "  -U <num>                  | Max number of UDP processed packets before giving up [default: %u]\n"
 	 ,
@@ -402,7 +405,6 @@ static void help(u_int long_help) {
 	 "  --extcap-capture-filter\n"
 	 "  --fifo <path to file or pipe>\n"
 	 "  --debug\n"
-	 "  --dbg-proto proto|num[,...]\n"
     );
 #endif
 
@@ -434,7 +436,6 @@ static struct option longopts[] = {
   { "extcap-capture-filter", required_argument, NULL, '6'},
   { "fifo", required_argument, NULL, '7'},
   { "debug", no_argument, NULL, '8'},
-  { "dbg-proto", required_argument, NULL, 257},
   { "ndpi-proto-filter", required_argument, NULL, '9'},
 
   /* ndpiReader options */
@@ -453,6 +454,7 @@ static struct option longopts[] = {
   { "revision", no_argument, NULL, 'r'},
   { "verbose", no_argument, NULL, 'v'},
   { "version", no_argument, NULL, 'V'},
+  { "dbg-proto", required_argument, NULL, 'u'},
   { "help", no_argument, NULL, 'h'},
   { "joy", required_argument, NULL, 'J'},
   { "payload-analysis", required_argument, NULL, 'P'},
@@ -660,7 +662,7 @@ static void parseOptions(int argc, char **argv) {
   }
 #endif
 
-  while((opt = getopt_long(argc, argv, "e:c:C:df:g:i:hp:P:l:s:tv:V:n:Jrp:w:q0123:456:7:89:m:T:U:",
+  while((opt = getopt_long(argc, argv, "e:c:C:df:g:i:hp:P:l:s:tv:V:u:n:Jrp:w:q0123:456:7:89:m:T:U:",
 			   longopts, &option_idx)) != EOF) {
 #ifdef DEBUG_TRACE
     if(trace) fprintf(trace, " #### -%c [%s] #### \n", opt, optarg ? optarg : "");
@@ -736,10 +738,16 @@ static void parseOptions(int argc, char **argv) {
       if(nDPI_LogLevel < 0) nDPI_LogLevel = 0;
       if(nDPI_LogLevel > 3) {
 	nDPI_LogLevel = 3;
+	free(_debug_protocols);
 	_debug_protocols = strdup("all");
       }
       break;
 
+    case 'u':
+      free(_debug_protocols);
+      _debug_protocols = strdup(optarg);
+      break;
+
     case 'h':
       help(1);
       break;
@@ -815,6 +823,7 @@ static void parseOptions(int argc, char **argv) {
 
     case '8':
       nDPI_LogLevel = NDPI_LOG_DEBUG_EXTRA;
+      free(_debug_protocols);
       _debug_protocols = strdup("all");
       break;
 
@@ -823,10 +832,6 @@ static void parseOptions(int argc, char **argv) {
       if(extcap_packet_filter == NDPI_PROTOCOL_UNKNOWN) extcap_packet_filter = atoi(optarg);
       break;
 
-    case 257:
-      _debug_protocols = strdup(optarg);
-      break;
-
     case 'T':
       max_num_tcp_dissected_pkts = atoi(optarg);
       if(max_num_tcp_dissected_pkts < 3) max_num_tcp_dissected_pkts = 3;
@@ -3574,6 +3579,7 @@ int orginal_main(int argc, char **argv) {
     if(extcap_fifo_h) pcap_close(extcap_fifo_h);
     if(ndpi_info_mod) ndpi_exit_detection_module(ndpi_info_mod);
     if(csv_fp)        fclose(csv_fp);
+    free(_debug_protocols);
 
     return 0;
   }
diff --git a/example/reader_util.c b/example/reader_util.c
index 94d5188ad..43afcd402 100644
--- a/example/reader_util.c
+++ b/example/reader_util.c
@@ -419,13 +419,13 @@ struct ndpi_workflow* ndpi_workflow_init(const struct ndpi_workflow_prefs * pref
   module = ndpi_init_detection_module(ndpi_no_prefs);
 
   if(module == NULL) {
-    NDPI_LOG(0, NULL, NDPI_LOG_ERROR, "global structure initialization failed\n");
+    LOG(NDPI_LOG_ERROR, "global structure initialization failed\n");
     exit(-1);
   }
 
   workflow = ndpi_calloc(1, sizeof(struct ndpi_workflow));
   if(workflow == NULL) {
-    NDPI_LOG(0, NULL, NDPI_LOG_ERROR, "global structure initialization failed\n");
+    LOG(NDPI_LOG_ERROR, "global structure initialization failed\n");
     ndpi_free(module);
     exit(-1);
   }
@@ -441,13 +441,8 @@ struct ndpi_workflow* ndpi_workflow_init(const struct ndpi_workflow_prefs * pref
       exit(-1);
     _debug_protocols_ok = 1;
   }
-
-#ifdef NDPI_ENABLE_DEBUG_MESSAGES
-  NDPI_BITMASK_RESET(module->debug_bitmask);
-
   if(_debug_protocols_ok)
-    module->debug_bitmask = debug_bitmask;
-#endif
+    ndpi_set_debug_bitmask(module, debug_bitmask);
 
   workflow->ndpi_flows_root = ndpi_calloc(workflow->prefs.num_roots, sizeof(void *));
 
@@ -817,7 +812,7 @@ static struct ndpi_flow_info *get_ndpi_flow_info(struct ndpi_workflow * workflow
 
   if(ret == NULL) {
     if(workflow->stats.ndpi_flow_count == workflow->prefs.max_ndpi_flows) {
-      NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_ERROR,
+      LOG(NDPI_LOG_ERROR,
 	       "maximum flow count (%u) has been exceeded\n",
 	       workflow->prefs.max_ndpi_flows);
       exit(-1);
@@ -825,7 +820,7 @@ static struct ndpi_flow_info *get_ndpi_flow_info(struct ndpi_workflow * workflow
       struct ndpi_flow_info *newflow = (struct ndpi_flow_info*)malloc(sizeof(struct ndpi_flow_info));
 
       if(newflow == NULL) {
-	NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_ERROR, "[NDPI] %s(1): not enough memory\n", __FUNCTION__);
+	LOG(NDPI_LOG_ERROR, "[NDPI] %s(1): not enough memory\n", __FUNCTION__);
 	return(NULL);
       } else
         workflow->num_allocated_flows++;
@@ -862,7 +857,7 @@ static struct ndpi_flow_info *get_ndpi_flow_info(struct ndpi_workflow * workflow
       }
 
       if((newflow->ndpi_flow = ndpi_flow_malloc(SIZEOF_FLOW_STRUCT)) == NULL) {
-	NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_ERROR, "[NDPI] %s(2): not enough memory\n", __FUNCTION__);
+	LOG(NDPI_LOG_ERROR, "[NDPI] %s(2): not enough memory\n", __FUNCTION__);
 #ifdef DIRECTION_BINS
 	ndpi_free_bin(&newflow->payload_len_bin_src2dst), ndpi_free_bin(&newflow->payload_len_bin_dst2src);
 #else
@@ -874,7 +869,7 @@ static struct ndpi_flow_info *get_ndpi_flow_info(struct ndpi_workflow * workflow
 	memset(newflow->ndpi_flow, 0, SIZEOF_FLOW_STRUCT);
 
       if((newflow->src_id = ndpi_malloc(SIZEOF_ID_STRUCT)) == NULL) {
-	NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_ERROR, "[NDPI] %s(3): not enough memory\n", __FUNCTION__);
+	LOG(NDPI_LOG_ERROR, "[NDPI] %s(3): not enough memory\n", __FUNCTION__);
 #ifdef DIRECTION_BINS
 	ndpi_free_bin(&newflow->payload_len_bin_src2dst), ndpi_free_bin(&newflow->payload_len_bin_dst2src);
 #else
@@ -886,7 +881,7 @@ static struct ndpi_flow_info *get_ndpi_flow_info(struct ndpi_workflow * workflow
 	memset(newflow->src_id, 0, SIZEOF_ID_STRUCT);
 
       if((newflow->dst_id = ndpi_malloc(SIZEOF_ID_STRUCT)) == NULL) {
-	NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_ERROR, "[NDPI] %s(4): not enough memory\n", __FUNCTION__);
+	LOG(NDPI_LOG_ERROR, "[NDPI] %s(4): not enough memory\n", __FUNCTION__);
 #ifdef DIRECTION_BINS
 	ndpi_free_bin(&newflow->payload_len_bin_src2dst), ndpi_free_bin(&newflow->payload_len_bin_dst2src);
 #else
@@ -1760,7 +1755,7 @@ struct ndpi_proto ndpi_workflow_process_packet(struct ndpi_workflow * workflow,
 
       if(cap_warning_used == 0) {
 	if(!workflow->prefs.quiet_mode)
-	  NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_DEBUG,
+	  LOG(NDPI_LOG_DEBUG,
 		   "\n\nWARNING: packet capture size is smaller than packet size, DETECTION MIGHT NOT WORK CORRECTLY\n\n");
 	cap_warning_used = 1;
       }
@@ -1783,7 +1778,7 @@ struct ndpi_proto ndpi_workflow_process_packet(struct ndpi_workflow * workflow,
 
       if(ipv4_frags_warning_used == 0) {
 	if(!workflow->prefs.quiet_mode)
-	  NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_DEBUG, "\n\nWARNING: IPv4 fragments are not handled by this demo (nDPI supports them)\n");
+	  LOG(NDPI_LOG_DEBUG, "\n\nWARNING: IPv4 fragments are not handled by this demo (nDPI supports them)\n");
 	ipv4_frags_warning_used = 1;
       }
 
@@ -1817,7 +1812,7 @@ struct ndpi_proto ndpi_workflow_process_packet(struct ndpi_workflow * workflow,
   v4_warning:
     if(ipv4_warning_used == 0) {
       if(!workflow->prefs.quiet_mode)
-        NDPI_LOG(0, workflow->ndpi_struct, NDPI_LOG_DEBUG,
+        LOG(NDPI_LOG_DEBUG,
 		 "\n\nWARNING: only IPv4/IPv6 packets are supported in this demo (nDPI supports both IPv4 and IPv6), all other packets will be discarded\n\n");
       ipv4_warning_used = 1;
     }
diff --git a/example/reader_util.h b/example/reader_util.h
index c94998496..75d66bfd4 100644
--- a/example/reader_util.h
+++ b/example/reader_util.h
@@ -336,4 +336,14 @@ float ndpi_flow_get_byte_count_entropy(const uint32_t byte_count[256], unsigned
 
 extern int nDPI_LogLevel;
 
+#ifdef NDPI_ENABLE_DEBUG_MESSAGES
+ #define LOG(log_level, args...)	\
+  {					\
+    if(log_level <= nDPI_LogLevel)	\
+      printf(args);			\
+  }
+#else
+ #define LOG(...) {}
+#endif
+
 #endif
diff --git a/src/include/ndpi_api.h.in b/src/include/ndpi_api.h.in
index ed94c5bf3..865ddc8dd 100644
--- a/src/include/ndpi_api.h.in
+++ b/src/include/ndpi_api.h.in
@@ -844,6 +844,7 @@ extern "C" {
   u_int ndpi_get_ndpi_num_custom_protocols(struct ndpi_detection_module_struct *ndpi_mod);
   u_int ndpi_get_ndpi_detection_module_size(void);
   void ndpi_set_log_level(struct ndpi_detection_module_struct *ndpi_mod, u_int l);
+  void ndpi_set_debug_bitmask(struct ndpi_detection_module_struct *ndpi_mod, NDPI_PROTOCOL_BITMASK debug_bitmask);
 
   /* LRU cache */
   struct ndpi_lru_cache* ndpi_lru_cache_init(u_int32_t num_entries);
diff --git a/src/include/ndpi_define.h.in b/src/include/ndpi_define.h.in
index 13989a60e..5add2e1c8 100644
--- a/src/include/ndpi_define.h.in
+++ b/src/include/ndpi_define.h.in
@@ -179,6 +179,8 @@
 #define NDPI_JABBER_FT_TIMEOUT				         5
 #define NDPI_SOULSEEK_CONNECTION_IP_TICK_TIMEOUT               600
 
+#include "ndpi_config.h"	/* To have access to NDPI_ENABLE_DEBUG_MESSAGES */
+
 #ifdef NDPI_ENABLE_DEBUG_MESSAGES
  #define NDPI_LOG(proto, m, log_level, args...)		                                 \
   {								                         \
@@ -196,7 +198,7 @@
   */
 
  #ifndef NDPI_CURRENT_PROTO
- #define NDPI_CURRENT_PROTO NDPI_PROTO_UNKNOWN
+ #define NDPI_CURRENT_PROTO NDPI_PROTOCOL_UNKNOWN
  #endif
 
  #define NDPI_LOG_ERR(mod, args...)		                                 \
diff --git a/src/lib/ndpi_main.c b/src/lib/ndpi_main.c
index 7715f0460..199c34a5b 100644
--- a/src/lib/ndpi_main.c
+++ b/src/lib/ndpi_main.c
@@ -1953,9 +1953,10 @@ struct ndpi_detection_module_struct *ndpi_init_detection_module(ndpi_init_prefs
   int i;
 
   if(ndpi_str == NULL) {
-#ifdef NDPI_ENABLE_DEBUG_MESSAGES
-    NDPI_LOG_ERR(ndpi_str, "ndpi_init_detection_module initial malloc failed for ndpi_str\n");
-#endif /* NDPI_ENABLE_DEBUG_MESSAGES */
+    /* Logging this error is a bit tricky. At this point, we can't use NDPI_LOG*
+       functions yet, we don't have a custom log function and, as a library,
+       we shouldn't use stdout/stderr. Since this error is quite unlikely,
+       simply avoid any logs at all */
     return(NULL);
   }
 
@@ -1963,6 +1964,7 @@ struct ndpi_detection_module_struct *ndpi_init_detection_module(ndpi_init_prefs
 
 #ifdef NDPI_ENABLE_DEBUG_MESSAGES
   set_ndpi_debug_function(ndpi_str, (ndpi_debug_function_ptr) ndpi_debug_printf);
+  NDPI_BITMASK_RESET(ndpi_str->debug_bitmask);
 #endif /* NDPI_ENABLE_DEBUG_MESSAGES */
 
   if((ndpi_str->protocols_ptree = ndpi_New_Patricia(32 /* IPv4 */)) != NULL)
@@ -2008,8 +2010,10 @@ struct ndpi_detection_module_struct *ndpi_init_detection_module(ndpi_init_prefs
   ndpi_str->custom_categories.ipAddresses = ndpi_New_Patricia(32 /* IPv4 */);
   ndpi_str->custom_categories.ipAddresses_shadow = ndpi_New_Patricia(32 /* IPv4 */);
 
-  if((ndpi_str->custom_categories.ipAddresses == NULL) || (ndpi_str->custom_categories.ipAddresses_shadow == NULL))
+  if((ndpi_str->custom_categories.ipAddresses == NULL) || (ndpi_str->custom_categories.ipAddresses_shadow == NULL)) {
+    NDPI_LOG_ERR(ndpi_str, "[NDPI] Error allocating Patricia trees\n");
     return(NULL);
+  }
 
   ndpi_init_protocol_defaults(ndpi_str);
 
@@ -6286,6 +6290,12 @@ u_int ndpi_get_ndpi_detection_module_size() {
   return(sizeof(struct ndpi_detection_module_struct));
 }
 
+void ndpi_set_debug_bitmask(struct ndpi_detection_module_struct *ndpi_str, NDPI_PROTOCOL_BITMASK debug_bitmask) {
+#ifdef NDPI_ENABLE_DEBUG_MESSAGES
+  ndpi_str->debug_bitmask = debug_bitmask;
+#endif
+}
+
 void ndpi_set_log_level(struct ndpi_detection_module_struct *ndpi_str, u_int l){
   ndpi_str->ndpi_log_level = l;
 }
diff --git a/src/lib/protocols/dnp3.c b/src/lib/protocols/dnp3.c
index 7d0c17f70..805f8f335 100644
--- a/src/lib/protocols/dnp3.c
+++ b/src/lib/protocols/dnp3.c
@@ -6,9 +6,8 @@
  */
 
 #include "ndpi_protocol_ids.h"
-#include "ndpi_api.h"
-
 #define NDPI_CURRENT_PROTO NDPI_PROTOCOL_DNP3
+#include "ndpi_api.h"
 
 void ndpi_search_dnp3_tcp(struct ndpi_detection_module_struct *ndpi_struct,
                             struct ndpi_flow_struct *flow) {
diff --git a/src/lib/protocols/http.c b/src/lib/protocols/http.c
index 9ac26785c..8f74d22ad 100644
--- a/src/lib/protocols/http.c
+++ b/src/lib/protocols/http.c
@@ -558,6 +558,14 @@ static void check_http_payload(struct ndpi_detection_module_struct *ndpi_struct,
 
 /* ************************************************************* */
 
+#ifdef NDPI_ENABLE_DEBUG_MESSAGES
+static uint8_t non_ctrl(uint8_t c) {
+  return c < 32 ? '.':c;
+}
+#endif
+
+/* ************************************************************* */
+
 /**
  * Functions to check whether the packet begins with a valid http request
  * @param ndpi_struct
@@ -589,8 +597,10 @@ static u_int16_t http_request_url_offset(struct ndpi_detection_module_struct *nd
   int i;
 
   NDPI_LOG_DBG2(ndpi_struct, "====>>>> HTTP: %c%c%c%c [len: %u]\n",
-		non_ctrl(packet->payload[0]), non_ctrl(packet->payload[1]),
-		non_ctrl(packet->payload[2]), non_ctrl(packet->payload[3]),
+		packet->payload_packet_len > 0 ? non_ctrl(packet->payload[0]) : '.',
+		packet->payload_packet_len > 1 ? non_ctrl(packet->payload[1]) : '.',
+		packet->payload_packet_len > 2 ? non_ctrl(packet->payload[2]) : '.',
+		packet->payload_packet_len > 3 ? non_ctrl(packet->payload[3]) : '.',
 		packet->payload_packet_len);
 
   /* Check first char */
diff --git a/src/lib/protocols/iec60870-5-104.c b/src/lib/protocols/iec60870-5-104.c
index 040a1842a..e5e5325bf 100644
--- a/src/lib/protocols/iec60870-5-104.c
+++ b/src/lib/protocols/iec60870-5-104.c
@@ -25,9 +25,8 @@
  */
 
 #include "ndpi_protocol_ids.h"
-#include "ndpi_api.h"
-
 #define NDPI_CURRENT_PROTO NDPI_PROTOCOL_IEC60870
+#include "ndpi_api.h"
 
 void ndpi_search_iec60870_tcp(struct ndpi_detection_module_struct *ndpi_struct,
                             struct ndpi_flow_struct *flow) {
diff --git a/src/lib/protocols/mining.c b/src/lib/protocols/mining.c
index 78ed9ff29..1f86987fb 100644
--- a/src/lib/protocols/mining.c
+++ b/src/lib/protocols/mining.c
@@ -21,7 +21,7 @@
  *
  */
 #include "ndpi_protocol_ids.h"
-
+#define NDPI_CURRENT_PROTO NDPI_PROTOCOL_MINING
 #include "ndpi_api.h"
 
 /* ************************************************************************** */
diff --git a/src/lib/protocols/modbus.c b/src/lib/protocols/modbus.c
index 2a6dd2a49..c98c71298 100644
--- a/src/lib/protocols/modbus.c
+++ b/src/lib/protocols/modbus.c
@@ -24,9 +24,8 @@
 
 
 #include "ndpi_protocol_ids.h"
-#include "ndpi_api.h"
-
 #define NDPI_CURRENT_PROTO NDPI_PROTOCOL_MODBUS
+#include "ndpi_api.h"
 
 void ndpi_search_modbus_tcp(struct ndpi_detection_module_struct *ndpi_struct,
                             struct ndpi_flow_struct *flow) {
diff --git a/src/lib/protocols/mqtt.c b/src/lib/protocols/mqtt.c
index 45669c03a..bf8538604 100644
--- a/src/lib/protocols/mqtt.c
+++ b/src/lib/protocols/mqtt.c
@@ -79,7 +79,11 @@ void ndpi_search_mqtt (struct ndpi_detection_module_struct *ndpi_struct,
 	}
 
 	NDPI_LOG_DBG2(ndpi_struct, "====>>>> Mqtt header: %4x%4x%4x%4x [len: %u]\n",
-			packet->payload[0], packet->payload[1], packet->payload[2], packet->payload[3], packet->payload_packet_len);
+		      packet->payload_packet_len > 0 ? packet->payload[0] : '.',
+		      packet->payload_packet_len > 1 ? packet->payload[1] : '.',
+		      packet->payload_packet_len > 2 ? packet->payload[2] : '.',
+		      packet->payload_packet_len > 3 ? packet->payload[3] : '.',
+		      packet->payload_packet_len);
 	if (packet->payload_packet_len < 2) {
 		NDPI_LOG_DBG(ndpi_struct, "Excluding Mqtt .. mandatory header not found!\n");
 		NDPI_ADD_PROTOCOL_TO_BITMASK(flow->excluded_protocol_bitmask, NDPI_PROTOCOL_MQTT);
diff --git a/src/lib/protocols/nats.c b/src/lib/protocols/nats.c
index 300cc838d..da99a36de 100644
--- a/src/lib/protocols/nats.c
+++ b/src/lib/protocols/nats.c
@@ -20,9 +20,8 @@
  */
 
 #include "ndpi_protocol_ids.h"
-#include "ndpi_api.h"
-
 #define NDPI_CURRENT_PROTO NDPI_PROTOCOL_NATS
+#include "ndpi_api.h"
 
 static const char* commands[] =
   {
diff --git a/src/lib/protocols/s7comm.c b/src/lib/protocols/s7comm.c
index 7d2b92642..ec32c106e 100644
--- a/src/lib/protocols/s7comm.c
+++ b/src/lib/protocols/s7comm.c
@@ -21,8 +21,8 @@
  * 

  */

 #include "ndpi_protocol_ids.h"

-#include "ndpi_api.h"

 #define NDPI_CURRENT_PROTO NDPI_PROTOCOL_S7COMM

+#include "ndpi_api.h"

 

 void ndpi_search_s7comm_tcp(struct ndpi_detection_module_struct *ndpi_struct,

                             struct ndpi_flow_struct *flow) {

diff --git a/src/lib/protocols/smb.c b/src/lib/protocols/smb.c
index b50f59346..a70072853 100644
--- a/src/lib/protocols/smb.c
+++ b/src/lib/protocols/smb.c
@@ -21,7 +21,7 @@
  *
  */
 #include "ndpi_protocol_ids.h"
-
+#define NDPI_CURRENT_PROTO NDPI_PROTOCOL_SMBV23
 #include "ndpi_api.h"