Log file:line instead of function; add cs_log_set_file_level()

cs_log_set_filter() is removed in favor of cs_log_set_file_level() which
allows setting log verbosity of individual files and/or lines.

E.g.: `mg_=1,mjs=1,=4` - level for for everything except mjs and mongoose.

We use the fact that we are usually pretty careful with our file names and use prefixes consistently.

In mos, `debug.file_level` sets the option on boot and `Sys.SetDebug` is updated to parse `file_level` option to change it at runtime.

CL: Log file:line instead of function; add cs_log_set_file_level()

PUBLISHED_FROM=49f18d4d0d3dd224865129a4f8fe6cccd1d9bc12

examples/CC3200/bm222.c

@@ -98,7 +98,8 @@ bool bm222_get_data(struct bm222_ctx *ctx) {
       s->y = v[3];
       s->z = v[5];
       if (d > max_d) max_d = d;
-      LOG(LL_VERBOSE_DEBUG, ("dx %d dy %d dz %d d %d", dx, dy, dz, d));
+      LOG(LL_VERBOSE_DEBUG,
+          ("dx %d dy %d dz %d d %d", (int) dx, (int) dy, (int) dz, (int) d));
     }
   }
   return (overflow ? bm222_fifo_init(ctx) : true); /* Clear the ovf flag. */

examples/CC3200/cs_dbg.h

 /*
- * Copyright (c) 2014-2016 Cesanta Software Limited
+ * Copyright (c) 2014-2018 Cesanta Software Limited
  * All rights reserved
+ *
+ * Licensed under the Apache License, Version 2.0 (the ""License"");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an ""AS IS"" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
  */
 
 #ifndef CS_COMMON_CS_DBG_H_
 #define CS_COMMON_CS_DBG_H_
 
+#include "common/platform.h"
+
 #if CS_ENABLE_STDIO
 #include <stdio.h>
 #endif
@@ -14,6 +28,10 @@
 #define CS_ENABLE_DEBUG 0
 #endif
 
+#ifndef CS_LOG_PREFIX_LEN
+#define CS_LOG_PREFIX_LEN 24
+#endif
+
 #ifndef CS_LOG_ENABLE_TS_DIFF
 #define CS_LOG_ENABLE_TS_DIFF 0
 #endif
@@ -22,6 +40,9 @@
 extern "C" {
 #endif /* __cplusplus */
 
+/*
+ * Log level; `LL_INFO` is the default. Use `cs_log_set_level()` to change it.
+ */
 enum cs_log_level {
   LL_NONE = -1,
   LL_ERROR = 0,
@@ -34,29 +55,78 @@ enum cs_log_level {
   _LL_MAX = 5,
 };
 
+/*
+ * Set max log level to print; messages with the level above the given one will
+ * not be printed.
+ */
 void cs_log_set_level(enum cs_log_level level);
 
+/*
+ * A comma-separated set of prefix=level.
+ * prefix is matched against the log prefix exactly as printed, including line
+ * number, but partial match is ok. Check stops on first matching entry.
+ * If nothing matches, default level is used.
+ *
+ * Examples:
+ *   main.c:=4 - everything from main C at verbose debug level.
+ *   mongoose.c=1,mjs.c=1,=4 - everything at verbose debug except mg_* and mjs_*
+ *
+ */
+void cs_log_set_file_level(const char *file_level);
+
+/*
+ * Helper function which prints message prefix with the given `level`.
+ * If message should be printed (according to the current log level
+ * and filter), prints the prefix and returns 1, otherwise returns 0.
+ *
+ * Clients should typically just use `LOG()` macro.
+ */
+int cs_log_print_prefix(enum cs_log_level level, const char *fname, int line);
+
+extern enum cs_log_level cs_log_level;
+
 #if CS_ENABLE_STDIO
 
+/*
+ * Set file to write logs into. If `NULL`, logs go to `stderr`.
+ */
 void cs_log_set_file(FILE *file);
 
-extern enum cs_log_level cs_log_threshold;
-void cs_log_print_prefix(const char *func);
-void cs_log_printf(const char *fmt, ...);
+/*
+ * Prints log to the current log file, appends "\n" in the end and flushes the
+ * stream.
+ */
+void cs_log_printf(const char *fmt, ...) PRINTF_LIKE(1, 2);
+
+#if CS_ENABLE_STDIO
+
+/*
+ * Format and print message `x` with the given level `l`. Example:
+ *
+ * ```c
+ * LOG(LL_INFO, ("my info message: %d", 123));
+ * LOG(LL_DEBUG, ("my debug message: %d", 123));
+ * ```
+ */
+#define LOG(l, x)                                     \
+  do {                                                \
+    if (cs_log_print_prefix(l, __FILE__, __LINE__)) { \
+      cs_log_printf x;                                \
+    }                                                 \
+  } while (0)
 
-#define LOG(l, x)                  \
-  if (cs_log_threshold >= l) {     \
-    cs_log_print_prefix(__func__); \
-    cs_log_printf x;               \
-  }
+#else
+
+#define LOG(l, x) ((void) l)
+
+#endif
 
 #ifndef CS_NDEBUG
 
-#define DBG(x)                                \
-  if (cs_log_threshold >= LL_VERBOSE_DEBUG) { \
-    cs_log_print_prefix(__func__);            \
-    cs_log_printf x;                          \
-  }
+/*
+ * Shortcut for `LOG(LL_VERBOSE_DEBUG, (...))`
+ */
+#define DBG(x) LOG(LL_VERBOSE_DEBUG, x)
 
 #else /* NDEBUG */
 

examples/CC3200/wifi.c

@@ -25,7 +25,7 @@ void SimpleLinkWlanEventHandler(SlWlanEvent_t *e) {
       LOG(LL_INFO, ("WiFi: station disconnected"));
       break;
     default:
-      LOG(LL_INFO, ("WiFi: event %d", e->Event));
+      LOG(LL_INFO, ("WiFi: event %d", (int) e->Event));
   }
 }
 
@@ -39,7 +39,7 @@ void SimpleLinkNetAppEventHandler(SlNetAppEvent_t *e) {
   } else if (e->Event == SL_NETAPP_IP_LEASED_EVENT) {
     LOG(LL_INFO, ("IP leased"));
   } else {
-    LOG(LL_INFO, ("NetApp event %d", e->Event));
+    LOG(LL_INFO, ("NetApp event %d", (int) e->Event));
   }
 }
 

mongoose.c

@@ -462,6 +462,10 @@ int cs_base64_decode(const unsigned char *s, int len, char *dst, int *dec_len) {
 #define CS_ENABLE_DEBUG 0
 #endif
 
+#ifndef CS_LOG_PREFIX_LEN
+#define CS_LOG_PREFIX_LEN 24
+#endif
+
 #ifndef CS_LOG_ENABLE_TS_DIFF
 #define CS_LOG_ENABLE_TS_DIFF 0
 #endif
@@ -492,51 +496,28 @@ enum cs_log_level {
 void cs_log_set_level(enum cs_log_level level);
 
 /*
- * Set log filter. NULL (a default) logs everything.
- * Otherwise, function name and file name will be tested against the given
- * pattern, and only matching messages will be printed.
- *
- * For the pattern syntax, refer to `mg_match_prefix()` in `str_util.h`.
- *
- * Example:
- * ```c
- * void foo(void) {
- *   LOG(LL_INFO, ("hello from foo"));
- * }
+ * A comma-separated set of prefix=level.
+ * prefix is matched against the log prefix exactly as printed, including line
+ * number, but partial match is ok. Check stops on first matching entry.
+ * If nothing matches, default level is used.
  *
- * void bar(void) {
- *   LOG(LL_INFO, ("hello from bar"));
- * }
+ * Examples:
+ *   main.c:=4 - everything from main C at verbose debug level.
+ *   mongoose.c=1,mjs.c=1,=4 - everything at verbose debug except mg_* and mjs_*
  *
- * void test(void) {
- *   cs_log_set_filter(NULL);
- *   foo();
- *   bar();
- *
- *   cs_log_set_filter("f*");
- *   foo();
- *   bar(); // Will NOT print anything
- *
- *   cs_log_set_filter("bar");
- *   foo(); // Will NOT print anything
- *   bar();
- * }
- * ```
  */
-void cs_log_set_filter(const char *pattern);
+void cs_log_set_file_level(const char *file_level);
 
 /*
- * Helper function which prints message prefix with the given `level`, function
- * name `func` and `filename`. If message should be printed (accordingly to the
- * current log level and filter), prints the prefix and returns 1, otherwise
- * returns 0.
+ * Helper function which prints message prefix with the given `level`.
+ * If message should be printed (according to the current log level
+ * and filter), prints the prefix and returns 1, otherwise returns 0.
  *
  * Clients should typically just use `LOG()` macro.
  */
-int cs_log_print_prefix(enum cs_log_level level, const char *func,
-                        const char *filename);
+int cs_log_print_prefix(enum cs_log_level level, const char *fname, int line);
 
-extern enum cs_log_level cs_log_threshold;
+extern enum cs_log_level cs_log_level;
 
 #if CS_ENABLE_STDIO
 
@@ -561,9 +542,11 @@ void cs_log_printf(const char *fmt, ...) PRINTF_LIKE(1, 2);
  * LOG(LL_DEBUG, ("my debug message: %d", 123));
  * ```
  */
-#define LOG(l, x)                                                    \
-  do {                                                               \
-    if (cs_log_print_prefix(l, __func__, __FILE__)) cs_log_printf x; \
+#define LOG(l, x)                                     \
+  do {                                                \
+    if (cs_log_print_prefix(l, __FILE__, __LINE__)) { \
+      cs_log_printf x;                                \
+    }                                                 \
   } while (0)
 
 #else
@@ -626,7 +609,7 @@ void cs_log_printf(const char *fmt, ...) PRINTF_LIKE(1, 2);
 /* Amalgamated: #include "common/cs_time.h" */
 /* Amalgamated: #include "common/str_util.h" */
 
-enum cs_log_level cs_log_threshold WEAK =
+enum cs_log_level cs_log_level WEAK =
 #if CS_ENABLE_DEBUG
     LL_VERBOSE_DEBUG;
 #else
@@ -634,10 +617,9 @@ enum cs_log_level cs_log_threshold WEAK =
 #endif
 
 #if CS_ENABLE_STDIO
-static char *s_filter_pattern = NULL;
-static size_t s_filter_pattern_len;
+static char *s_file_level = NULL;
 
-void cs_log_set_filter(const char *pattern) WEAK;
+void cs_log_set_file_level(const char *file_level) WEAK;
 
 FILE *cs_log_file WEAK = NULL;
 
@@ -647,34 +629,62 @@ double cs_log_ts WEAK;
 
 enum cs_log_level cs_log_cur_msg_level WEAK = LL_NONE;
 
-void cs_log_set_filter(const char *pattern) {
-  free(s_filter_pattern);
-  if (pattern != NULL) {
-    s_filter_pattern = strdup(pattern);
-    s_filter_pattern_len = strlen(pattern);
+void cs_log_set_file_level(const char *file_level) {
+  char *fl = s_file_level;
+  if (file_level != NULL) {
+    s_file_level = strdup(file_level);
   } else {
-    s_filter_pattern = NULL;
-    s_filter_pattern_len = 0;
+    s_file_level = NULL;
   }
+  free(fl);
 }
 
-int cs_log_print_prefix(enum cs_log_level, const char *, const char *) WEAK;
-int cs_log_print_prefix(enum cs_log_level level, const char *func,
-                        const char *filename) {
-  char prefix[21];
+int cs_log_print_prefix(enum cs_log_level level, const char *file, int ln) WEAK;
+int cs_log_print_prefix(enum cs_log_level level, const char *file, int ln) {
+  char prefix[CS_LOG_PREFIX_LEN], *q;
+  const char *p;
+  size_t fl = 0, ll = 0, pl = 0;
+
+  if (level > cs_log_level && s_file_level == NULL) return 0;
 
-  if (level > cs_log_threshold) return 0;
-  if (s_filter_pattern != NULL &&
-      mg_match_prefix(s_filter_pattern, s_filter_pattern_len, func) == 0 &&
-      mg_match_prefix(s_filter_pattern, s_filter_pattern_len, filename) == 0) {
-    return 0;
+  p = file + strlen(file);
+
+  while (p != file) {
+    const char c = *(p - 1);
+    if (c == '/' || c == '\\') break;
+    p--;
+    fl++;
+  }
+
+  ll = (ln < 10000 ? (ln < 1000 ? (ln < 100 ? (ln < 10 ? 1 : 2) : 3) : 4) : 5);
+  if (fl > (sizeof(prefix) - ll - 2)) fl = (sizeof(prefix) - ll - 2);
+
+  pl = fl + 1 + ll;
+  memcpy(prefix, p, fl);
+  q = prefix + pl;
+  memset(q, ' ', sizeof(prefix) - pl);
+  do {
+    *(--q) = '0' + (ln % 10);
+    ln /= 10;
+  } while (ln > 0);
+  *(--q) = ':';
+
+  if (s_file_level != NULL) {
+    enum cs_log_level pll = cs_log_level;
+    struct mg_str fl = mg_mk_str(s_file_level), ps = MG_MK_STR_N(prefix, pl);
+    struct mg_str k, v;
+    while ((fl = mg_next_comma_list_entry_n(fl, &k, &v)).p != NULL) {
+      bool yes = !(!mg_str_starts_with(ps, k) || v.len == 0);
+      if (!yes) continue;
+      pll = (enum cs_log_level)(*v.p - '0');
+      break;
+    }
+    if (level > pll) return 0;
   }
 
-  strncpy(prefix, func, 20);
-  prefix[20] = '\0';
   if (cs_log_file == NULL) cs_log_file = stderr;
   cs_log_cur_msg_level = level;
-  fprintf(cs_log_file, "%-20s ", prefix);
+  fwrite(prefix, 1, sizeof(prefix), cs_log_file);
 #if CS_LOG_ENABLE_TS_DIFF
   {
     double now = cs_time();
@@ -703,15 +713,15 @@ void cs_log_set_file(FILE *file) {
 
 #else
 
-void cs_log_set_filter(const char *pattern) {
-  (void) pattern;
+void cs_log_set_file_level(const char *file_level) {
+  (void) file_level;
 }
 
 #endif /* CS_ENABLE_STDIO */
 
 void cs_log_set_level(enum cs_log_level level) WEAK;
 void cs_log_set_level(enum cs_log_level level) {
-  cs_log_threshold = level;
+  cs_log_level = level;
 #if CS_LOG_ENABLE_TS_DIFF && CS_ENABLE_STDIO
   cs_log_ts = cs_time();
 #endif

mongoose.h

@@ -2647,6 +2647,8 @@ const char *mg_next_comma_list_entry(const char *list, struct mg_str *val,
 
 /*
  * Like `mg_next_comma_list_entry()`, but takes `list` as `struct mg_str`.
+ * NB: Test return value's .p, not .len. On last itreation that yields result
+ * .len will be 0 but .p will not. When finished, .p will be NULL.
  */
 struct mg_str mg_next_comma_list_entry_n(struct mg_str list, struct mg_str *val,
                                          struct mg_str *eq_val);

src/common/cs_dbg.c

@@ -24,7 +24,7 @@
 #include "common/cs_time.h"
 #include "common/str_util.h"
 
-enum cs_log_level cs_log_threshold WEAK =
+enum cs_log_level cs_log_level WEAK =
 #if CS_ENABLE_DEBUG
     LL_VERBOSE_DEBUG;
 #else
@@ -32,10 +32,9 @@ enum cs_log_level cs_log_threshold WEAK =
 #endif
 
 #if CS_ENABLE_STDIO
-static char *s_filter_pattern = NULL;
-static size_t s_filter_pattern_len;
+static char *s_file_level = NULL;
 
-void cs_log_set_filter(const char *pattern) WEAK;
+void cs_log_set_file_level(const char *file_level) WEAK;
 
 FILE *cs_log_file WEAK = NULL;
 
@@ -45,34 +44,62 @@ double cs_log_ts WEAK;
 
 enum cs_log_level cs_log_cur_msg_level WEAK = LL_NONE;
 
-void cs_log_set_filter(const char *pattern) {
-  free(s_filter_pattern);
-  if (pattern != NULL) {
-    s_filter_pattern = strdup(pattern);
-    s_filter_pattern_len = strlen(pattern);
+void cs_log_set_file_level(const char *file_level) {
+  char *fl = s_file_level;
+  if (file_level != NULL) {
+    s_file_level = strdup(file_level);
   } else {
-    s_filter_pattern = NULL;
-    s_filter_pattern_len = 0;
+    s_file_level = NULL;
   }
+  free(fl);
 }
 
-int cs_log_print_prefix(enum cs_log_level, const char *, const char *) WEAK;
-int cs_log_print_prefix(enum cs_log_level level, const char *func,
-                        const char *filename) {
-  char prefix[21];
+int cs_log_print_prefix(enum cs_log_level level, const char *file, int ln) WEAK;
+int cs_log_print_prefix(enum cs_log_level level, const char *file, int ln) {
+  char prefix[CS_LOG_PREFIX_LEN], *q;
+  const char *p;
+  size_t fl = 0, ll = 0, pl = 0;
 
-  if (level > cs_log_threshold) return 0;
-  if (s_filter_pattern != NULL &&
-      mg_match_prefix(s_filter_pattern, s_filter_pattern_len, func) == 0 &&
-      mg_match_prefix(s_filter_pattern, s_filter_pattern_len, filename) == 0) {
-    return 0;
+  if (level > cs_log_level && s_file_level == NULL) return 0;
+
+  p = file + strlen(file);
+
+  while (p != file) {
+    const char c = *(p - 1);
+    if (c == '/' || c == '\\') break;
+    p--;
+    fl++;
+  }
+
+  ll = (ln < 10000 ? (ln < 1000 ? (ln < 100 ? (ln < 10 ? 1 : 2) : 3) : 4) : 5);
+  if (fl > (sizeof(prefix) - ll - 2)) fl = (sizeof(prefix) - ll - 2);
+
+  pl = fl + 1 + ll;
+  memcpy(prefix, p, fl);
+  q = prefix + pl;
+  memset(q, ' ', sizeof(prefix) - pl);
+  do {
+    *(--q) = '0' + (ln % 10);
+    ln /= 10;
+  } while (ln > 0);
+  *(--q) = ':';
+
+  if (s_file_level != NULL) {
+    enum cs_log_level pll = cs_log_level;
+    struct mg_str fl = mg_mk_str(s_file_level), ps = MG_MK_STR_N(prefix, pl);
+    struct mg_str k, v;
+    while ((fl = mg_next_comma_list_entry_n(fl, &k, &v)).p != NULL) {
+      bool yes = !(!mg_str_starts_with(ps, k) || v.len == 0);
+      if (!yes) continue;
+      pll = (enum cs_log_level)(*v.p - '0');
+      break;
+    }
+    if (level > pll) return 0;
   }
 
-  strncpy(prefix, func, 20);
-  prefix[20] = '\0';
   if (cs_log_file == NULL) cs_log_file = stderr;
   cs_log_cur_msg_level = level;
-  fprintf(cs_log_file, "%-20s ", prefix);
+  fwrite(prefix, 1, sizeof(prefix), cs_log_file);
 #if CS_LOG_ENABLE_TS_DIFF
   {
     double now = cs_time();
@@ -101,15 +128,15 @@ void cs_log_set_file(FILE *file) {
 
 #else
 
-void cs_log_set_filter(const char *pattern) {
-  (void) pattern;
+void cs_log_set_file_level(const char *file_level) {
+  (void) file_level;
 }
 
 #endif /* CS_ENABLE_STDIO */
 
 void cs_log_set_level(enum cs_log_level level) WEAK;
 void cs_log_set_level(enum cs_log_level level) {
-  cs_log_threshold = level;
+  cs_log_level = level;
 #if CS_LOG_ENABLE_TS_DIFF && CS_ENABLE_STDIO
   cs_log_ts = cs_time();
 #endif

src/common/cs_dbg.h

@@ -28,6 +28,10 @@
 #define CS_ENABLE_DEBUG 0
 #endif
 
+#ifndef CS_LOG_PREFIX_LEN
+#define CS_LOG_PREFIX_LEN 24
+#endif
+
 #ifndef CS_LOG_ENABLE_TS_DIFF
 #define CS_LOG_ENABLE_TS_DIFF 0
 #endif
@@ -58,51 +62,28 @@ enum cs_log_level {
 void cs_log_set_level(enum cs_log_level level);
 
 /*
- * Set log filter. NULL (a default) logs everything.
- * Otherwise, function name and file name will be tested against the given
- * pattern, and only matching messages will be printed.
- *
- * For the pattern syntax, refer to `mg_match_prefix()` in `str_util.h`.
- *
- * Example:
- * ```c
- * void foo(void) {
- *   LOG(LL_INFO, ("hello from foo"));
- * }
- *
- * void bar(void) {
- *   LOG(LL_INFO, ("hello from bar"));
- * }
+ * A comma-separated set of prefix=level.
+ * prefix is matched against the log prefix exactly as printed, including line
+ * number, but partial match is ok. Check stops on first matching entry.
+ * If nothing matches, default level is used.
  *
- * void test(void) {
- *   cs_log_set_filter(NULL);
- *   foo();
- *   bar();
+ * Examples:
+ *   main.c:=4 - everything from main C at verbose debug level.
+ *   mongoose.c=1,mjs.c=1,=4 - everything at verbose debug except mg_* and mjs_*
  *
- *   cs_log_set_filter("f*");
- *   foo();
- *   bar(); // Will NOT print anything
- *
- *   cs_log_set_filter("bar");
- *   foo(); // Will NOT print anything
- *   bar();
- * }
- * ```
  */
-void cs_log_set_filter(const char *pattern);
+void cs_log_set_file_level(const char *file_level);
 
 /*
- * Helper function which prints message prefix with the given `level`, function
- * name `func` and `filename`. If message should be printed (accordingly to the
- * current log level and filter), prints the prefix and returns 1, otherwise
- * returns 0.
+ * Helper function which prints message prefix with the given `level`.
+ * If message should be printed (according to the current log level
+ * and filter), prints the prefix and returns 1, otherwise returns 0.
  *
  * Clients should typically just use `LOG()` macro.
  */
-int cs_log_print_prefix(enum cs_log_level level, const char *func,
-                        const char *filename);
+int cs_log_print_prefix(enum cs_log_level level, const char *fname, int line);
 
-extern enum cs_log_level cs_log_threshold;
+extern enum cs_log_level cs_log_level;
 
 #if CS_ENABLE_STDIO
 
@@ -127,9 +108,11 @@ void cs_log_printf(const char *fmt, ...) PRINTF_LIKE(1, 2);
  * LOG(LL_DEBUG, ("my debug message: %d", 123));
  * ```
  */
-#define LOG(l, x)                                                    \
-  do {                                                               \
-    if (cs_log_print_prefix(l, __func__, __FILE__)) cs_log_printf x; \
+#define LOG(l, x)                                     \
+  do {                                                \
+    if (cs_log_print_prefix(l, __FILE__, __LINE__)) { \
+      cs_log_printf x;                                \
+    }                                                 \
   } while (0)
 
 #else