Cleanup logging.

Signed-off-by: Florent Bruneau <florent.bruneau@polytechnique.org>

diff --git a/common/common.c b/common/common.c
index c2abeb4..af95efa 100644 (file)
--- a/common/common.c
+++ b/common/common.c
@@ -45,12 +45,14 @@ sig_atomic_t sigint  = false;
 sig_atomic_t sighup  = false;
 
 bool daemon_process  = true;
+int  log_level       = LOG_INFO;
 
 static FILE *pidfile = NULL;
 
 void common_sighandler(int sig)
 {
     switch (sig) {
+                       case SIGTERM:
       case SIGINT:
         sigint = true;
         return;
@@ -60,7 +62,7 @@ void common_sighandler(int sig)
         return;
 
       default:
-        syslog(LOG_ERR, "Killed (got signal %d)...", sig);
+                               err("Killed (got signal %d)...", sig);
         exit(-1);
     }
 }
@@ -242,7 +244,7 @@ int pidfile_open(const char *name)
         if (!pidfile)
             return -1;
                                if (fcntl(fileno(pidfile), F_SETLK, &lock) == -1) {
-                                               syslog(LOG_ERR, "program already started");
+                                               crit("program already started");
                                                fclose(pidfile);
                                                pidfile = NULL;
                                                return -1;
@@ -282,17 +284,17 @@ int common_setup(const char* pidfilename, bool unsafe, const char* runas_user,
                  const char* runas_group, bool daemonize)
 {
     if (!unsafe && drop_privileges(runas_user, runas_group) < 0) {
-        syslog(LOG_CRIT, "unable to drop privileges");
+        crit("unable to drop privileges");
         return EXIT_FAILURE;
     }
 
     if (daemonize && daemon_detach() < 0) {
-        syslog(LOG_CRIT, "unable to fork");
+        crit("unable to fork");
         return EXIT_FAILURE;
     }
 
                if (pidfile_open(pidfilename) < 0) {
-        syslog(LOG_CRIT, "unable to write pidfile %s", pidfilename);
+        crit("unable to write pidfile %s", pidfilename);
         return EXIT_FAILURE;
     }
 
@@ -306,7 +308,7 @@ extern exitcall_t __madexit[];
 static void common_shutdown(void)
 {
                if (daemon_process) {
-                               syslog(LOG_INFO, "Stopping...");
+                               info("stopping...");
                }
                pidfile_close();
     for (int i = -1; __madexit[i]; i--) {

diff --git a/common/common.h b/common/common.h
index 9b86f09..03d2fbb 100644 (file)
--- a/common/common.h
+++ b/common/common.h
@@ -57,9 +57,6 @@
 
 #include "mem.h"
 
-#define UNIXERR(fun)                                    \
-        syslog(LOG_ERR, "%s:%d:%s: %s: %m",             \
-               __FILE__, __LINE__, __func__, fun)
 
 #define __tostr(x)  #x
 #define STR(x)      __tostr(x)
@@ -73,8 +70,26 @@ typedef void (*exitcall_t)(void);
 #define module_init(fn)  static __init initcall_t __init_##fn = fn;
 #define module_exit(fn)  static __exit exitcall_t __exit_##fn = fn;
 
+#define __log(Level, Fmt, ...)                                    \
+    if (log_level >= Level) {                                     \
+        syslog(Level, Fmt, ##__VA_ARGS__);                        \
+    }
+
+#define debug(Fmt, ...)  __log(LOG_DEBUG,   Fmt, ##__VA_ARGS__)
+#define notice(Fmt, ...) __log(LOG_NOTICE,  Fmt, ##__VA_ARGS__)
+#define info(Fmt, ...)   __log(LOG_INFO,    Fmt, ##__VA_ARGS__)
+#define warn(Fmt, ...)   __log(LOG_WARNING, Fmt, ##__VA_ARGS__)
+#define err(Fmt, ...)    __log(LOG_ERR,     Fmt, ##__VA_ARGS__)
+#define crit(Fmt, ...)   __log(LOG_CRIT,    Fmt, ##__VA_ARGS__)
+#define alert(Fmt, ...)  __log(LOG_ALERT,   Fmt, ##__VA_ARGS__)
+#define emerg(Fmt, ...)  __log(LOG_ALERT,   Fmt, ##__VA_ARGS__)
+
+#define UNIXERR(fun)     err("%s:%d:%s %s: %m",                      \
+                             __FILE__, __LINE__, __func__, fun)
+
 extern sig_atomic_t sigint;
 extern sig_atomic_t sighup;
+extern int          log_level;
 
 void common_sighandler(int sig);
 
@@ -102,7 +117,7 @@ int common_setup(const char* pidfile, bool unsafe, const char* runas_user,
         signal(SIGTERM, &common_sighandler);                      \
         signal(SIGHUP,  &common_sighandler);                      \
         signal(SIGSEGV, &common_sighandler);                      \
-        syslog(LOG_INFO, "Starting...");                          \
+        info("starting...");                                      \
         return 0;                                                 \
     }                                                             \
                                                                   \

diff --git a/common/server.c b/common/server.c
index 6ea1a9a..9f0681b 100644 (file)
--- a/common/server.c
+++ b/common/server.c
@@ -142,7 +142,7 @@ int server_loop(start_client_t starter, delete_client_t deleter,
 
         if (sighup && refresh) {
             if (!refresh(config)) {
-                syslog(LOG_ERR, "error while refreshing configuration");
+                crit("error while refreshing configuration");
                 return EXIT_FAILURE;
             }
         }

diff --git a/common/tst-trie.c b/common/tst-trie.c
index 78977a8..c9e16dc 100644 (file)
--- a/common/tst-trie.c
+++ b/common/tst-trie.c
@@ -54,8 +54,7 @@ static trie_t *create_trie_from_file(const char *file)
         --end;
     }
     if (end != map.end) {
-        syslog(LOG_WARNING, "file %s miss a final \\n, ignoring last line",
-               file);
+        warn("file %s miss a final \\n, ignoring last line", file);
     }
 
     db = trie_new();

diff --git a/pfix-srsd/main-srsd.c b/pfix-srsd/main-srsd.c
index e7f4906..9f1bdd3 100644 (file)
--- a/pfix-srsd/main-srsd.c
+++ b/pfix-srsd/main-srsd.c
@@ -122,7 +122,7 @@ int process_srs(server_t *srsd, void* vconfig)
         nl = strchr(srsd->ibuf.data + 4, '\n');
         if (!nl) {
             if (srsd->ibuf.len > BUFSIZ) {
-                syslog(LOG_ERR, "unreasonnable amount of data without a \\n");
+                err("unreasonnable amount of data without a \\n");
                 return -1;
             }
             if (srsd->obuf.len) {
@@ -132,7 +132,7 @@ int process_srs(server_t *srsd, void* vconfig)
         }
 
         if (strncmp("get ", srsd->ibuf.data, 4)) {
-            syslog(LOG_ERR, "bad request, not starting with \"get \"");
+                                               err("bad request, not starting with \"get \"");
             return -1;
         }
 
@@ -141,7 +141,7 @@ int process_srs(server_t *srsd, void* vconfig)
 
         if (p == q) {
             buffer_addstr(&srsd->obuf, "400 empty request ???\n");
-            syslog(LOG_WARNING, "empty request");
+            warn("empty request");
             goto skip;
         }
 
@@ -234,7 +234,7 @@ static srs_t *srs_read_secrets(const char *sfile)
 
         ++lineno;
         if (n == sizeof(buf) - 1 && buf[n - 1] != '\n') {
-            syslog(LOG_CRIT, "%s:%d: line too long", sfile, lineno);
+            crit("%s:%d: line too long", sfile, lineno);
             goto error;
         }
         m_strrtrim(buf);
@@ -242,7 +242,7 @@ static srs_t *srs_read_secrets(const char *sfile)
     }
 
     if (!lineno) {
-        syslog(LOG_CRIT, "%s: empty file, no secrets", sfile);
+        crit("%s: empty file, no secrets", sfile);
         goto error;
     }
 

diff --git a/postlicyd/config.c b/postlicyd/config.c
index 8486858..d1e4d83 100644 (file)
--- a/postlicyd/config.c
+++ b/postlicyd/config.c
@@ -128,7 +128,7 @@ static bool config_second_pass(config_t *config)
     ok = false;
 #define PARSE_CHECK(Expr, Fmt, ...)                                            \
     if (!(Expr)) {                                                             \
-        syslog(LOG_ERR, Fmt, ##__VA_ARGS__);                                   \
+        err(Fmt, ##__VA_ARGS__);                                               \
         return false;                                                          \
     }
     foreach (filter_param_t *param, config->params) {
@@ -158,7 +158,7 @@ static bool config_second_pass(config_t *config)
     array_deep_wipe(config->params, filter_params_wipe);
 
     if (!ok) {
-        syslog(LOG_ERR, "no entry point defined");
+        err("no entry point defined");
     }
 
     return ok;
@@ -187,7 +187,7 @@ static bool config_load(config_t *config)
     linep = p = map.map;
 
 #define READ_LOG(Lev, Fmt, ...)                                                \
-    syslog(LOG_ ## Lev, "config file %s:%d:%d: " Fmt, config->filename,        \
+    __log(LOG_ ## Lev, "config file %s:%d:%d: " Fmt, config->filename,         \
            line + 1, p - linep + 1, ##__VA_ARGS__)
 #define READ_ERROR(Fmt, ...)                                                   \
     do {                                                                       \
@@ -391,7 +391,7 @@ ok:
     return true;
 
 badeof:
-    syslog(LOG_ERR, "Unexpected end of file");
+    err("Unexpected end of file");
 
 error:
     if (filter.name) {

diff --git a/postlicyd/filter.c b/postlicyd/filter.c
index 3f9991b..d277542 100644 (file)
--- a/postlicyd/filter.c
+++ b/postlicyd/filter.c
@@ -111,8 +111,8 @@ bool filter_update_references(filter_t *filter, A(filter_t) *filter_list)
         if (!hook->postfix) {
             hook->filter_id = filter_find_with_name(filter_list, hook->value);
             if (hook->filter_id == -1) {
-                syslog(LOG_ERR, "invalid filter name %s for hook %s",
-                       hook->value, htokens[hook->type]);
+                err("invalid filter name %s for hook %s",
+                    hook->value, htokens[hook->type]);
                 return false;
             }
             p_delete(&hook->value);
@@ -145,7 +145,7 @@ bool filter_check_safety(A(filter_t) *array)
 {
     foreach (filter_t *filter, *array) {
         if (!filter_check_loop(filter, array, __Ai)) {
-            syslog(LOG_ERR, "the filter tree contains a loop");
+            err("the filter tree contains a loop");
             return false;
         }
     }}
@@ -167,21 +167,20 @@ const filter_hook_t *filter_run(const filter_t *filter, const query_t *query)
 {
     int start = 0;
     int end   = filter->hooks.len;
-    //syslog(LOG_DEBUG, "running filter %s (%s)",
-    //       filter->name, ftokens[filter->type]);
+    debug("running filter %s (%s)", filter->name, ftokens[filter->type]);
     filter_result_t res = runners[filter->type](filter, query);
 
     if (res == HTK_ABORT) {
         return NULL;
     }
-    //syslog(LOG_DEBUG, "filter run, result is %s", htokens[res]);
+    debug("filter run, result is %s", htokens[res]);
 
     while (start < end) {
         int mid = (start + end) / 2;
         filter_hook_t *hook = array_ptr(filter->hooks, mid);
         if (hook->type == res) {
-            //syslog(LOG_DEBUG, "return hook of type %s, value %s",
-            //       htokens[hook->type], hook->value);
+            debug("return hook of type %s, value %s",
+                  htokens[hook->type], hook->value);
             return hook;
         } else if (res < hook->type) {
             end = mid;
@@ -189,8 +188,7 @@ const filter_hook_t *filter_run(const filter_t *filter, const query_t *query)
             start = mid + 1;
         }
     }
-    syslog(LOG_WARNING, "missing hook %s for filter %s", 
-           htokens[res], filter->name);
+    warn("missing hook %s for filter %s", htokens[res], filter->name);
     return &default_hook;
 }
 
@@ -216,12 +214,12 @@ bool filter_add_param(filter_t *filter, const char *name, ssize_t name_len,
     filter_param_t param;
     param.type = param_tokenize(name, name_len);
     if (param.type == ATK_UNKNOWN) {
-        syslog(LOG_ERR, "unknown parameter %.*s", name_len, name);
+        err("unknown parameter %.*s", name_len, name);
         return false;
     }
     if (!params[filter->type][param.type]) {
-        syslog(LOG_ERR, "hook %s is not valid for filter %s",
-               atokens[param.type], ftokens[filter->type]);
+        err("hook %s is not valid for filter %s",
+            atokens[param.type], ftokens[filter->type]);
         return false;
     }
     param.value     = p_dupstr(value, value_len);
@@ -236,12 +234,12 @@ bool filter_add_hook(filter_t *filter, const char *name, ssize_t name_len,
     filter_hook_t hook;
     hook.type  = hook_tokenize(name, name_len);
     if (hook.type == HTK_UNKNOWN) {
-        syslog(LOG_ERR, "unknown hook type %.*s", name_len, name);
+        err("unknown hook type %.*s", name_len, name);
         return false;
     }
     if (!hooks[filter->type][hook.type] || hook.type == HTK_ABORT) {
-        syslog(LOG_ERR, "hook %s not is valid for filter %s",
-               htokens[hook.type], ftokens[filter->type]);
+        err("hook %s not is valid for filter %s",
+            htokens[hook.type], ftokens[filter->type]);
         return false;
     }
     hook.postfix = (strncmp(value, "postfix:", 8) == 0);

diff --git a/postlicyd/greylist.c b/postlicyd/greylist.c
index 53bcf33..a2b3346 100644 (file)
--- a/postlicyd/greylist.c
+++ b/postlicyd/greylist.c
@@ -101,7 +101,7 @@ static TCBDB *greylist_db_get(const greylist_config_t *config,
         char tmppath[PATH_MAX];
         snprintf(tmppath, PATH_MAX, "%s.tmp", path);
 
-        syslog(LOG_INFO, "database cleanup started");
+        info("database cleanup started");
         awl_db = tcbdbnew();
         if (tcbdbopen(awl_db, path, BDBOREADER)) {
             tmp_db = tcbdbnew();
@@ -132,13 +132,13 @@ static TCBDB *greylist_db_get(const greylist_config_t *config,
                 tcbdbcurdel(cur);
                 tcbdbsync(tmp_db);
             } else {
-                syslog(LOG_ERR, "cannot run database cleanup: can't open destination database: %s",
-                       tcbdberrmsg(tcbdbecode(awl_db)));
+                warn("cannot run database cleanup: can't open destination database: %s",
+                     tcbdberrmsg(tcbdbecode(awl_db)));
             }
             tcbdbdel(tmp_db);
         } else {
             int ecode = tcbdbecode(awl_db);
-            syslog(LOG_ERR, "can not open database: %s", tcbdberrmsg(ecode));
+            warn("can not open database: %s", tcbdberrmsg(ecode));
             trashable = ecode != TCENOPERM && ecode != TCEOPEN && ecode != TCENOFILE && ecode != TCESUCCESS;
         }
         tcbdbdel(awl_db);
@@ -146,10 +146,10 @@ static TCBDB *greylist_db_get(const greylist_config_t *config,
         /** Cleanup successful, replace the old database with the new one.
          */
         if (trashable) {
-            syslog(LOG_INFO, "database cleanup finished: database was corrupted, create a new one");
+            info("database cleanup finished: database was corrupted, create a new one");
             unlink(path);
         } else if (replace) {
-            syslog(LOG_INFO, "database cleanup finished: before %u entries, after %d entries",
+            info("database cleanup finished: before %u entries, after %d entries",
                    old_count, new_count);
             unlink(path);
             if (rename(tmppath, path) != 0) {
@@ -157,7 +157,7 @@ static TCBDB *greylist_db_get(const greylist_config_t *config,
                 return NULL;
             }
         } else {
-            syslog(LOG_INFO, "database cleanup finished: nothing to do, %u entries", new_count);
+            info("database cleanup finished: nothing to do, %u entries", new_count);
         }
     }
 
@@ -165,7 +165,7 @@ static TCBDB *greylist_db_get(const greylist_config_t *config,
      */
     awl_db = tcbdbnew();
     if (!tcbdbopen(awl_db, path, BDBOWRITER | BDBOCREAT)) {
-        syslog(LOG_ERR, "can not open database: %s", tcbdberrmsg(tcbdbecode(awl_db)));
+        err("can not open database: %s", tcbdberrmsg(tcbdbecode(awl_db)));
         tcbdbdel(awl_db);
         return NULL;
     }
@@ -180,7 +180,7 @@ static bool greylist_initialize(greylist_config_t *config,
 
     if (config->client_awl) {
         snprintf(path, sizeof(path), "%s/%swhitelist.db", directory, prefix);
-        syslog(LOG_INFO, "loading auto-whitelist database");
+        info("loading auto-whitelist database");
         config->awl_db = greylist_db_get(config, path, true,
                                          sizeof(struct awl_entry),
                                          (db_entry_checker_t)(greylist_check_awlentry));
@@ -190,7 +190,7 @@ static bool greylist_initialize(greylist_config_t *config,
     }
 
     snprintf(path, sizeof(path), "%s/%sgreylist.db", directory, prefix);
-    syslog(LOG_INFO, "loading greylist database");
+    info("loading greylist database");
     config->obj_db = greylist_db_get(config, path, true,
                                      sizeof(struct obj_entry),
                                      (db_entry_checker_t)(greylist_check_object));
@@ -296,6 +296,8 @@ static bool try_greylist(const greylist_config_t *config,
 #define INCR_AWL                                              \
     aent.count++;                                             \
     aent.last = now;                                          \
+    debug("whitelist entry for %.*s updated, count %d",       \
+          c_addrlen, c_addr, aent.count);                     \
     tcbdbput(config->awl_db, c_addr, c_addrlen, &aent,        \
              sizeof(aent));
 
@@ -314,23 +316,27 @@ static bool try_greylist(const greylist_config_t *config,
         res = tcbdbget3(config->awl_db, c_addr, c_addrlen, &len);
         if (res && len == sizeof(aent)) {
             memcpy(&aent, res, len);
+            debug("client %.*s has a whitelist entry, count is %d",
+                  c_addrlen, c_addr, aent.count);
         }
 
         if (!greylist_check_awlentry(config, &aent, now)) {
             aent.count = 0;
             aent.last  = 0;
+            debug("client %.*s whitelist entry too old",
+                  c_addrlen, c_addr);
         }
 
         /* Whitelist if count is enough.
          */
         if (aent.count >= config->client_awl) {
+            debug("client %.*s whitelisted", c_addrlen, c_addr);
             if (now < aent.last + 3600) {
                 INCR_AWL
             }
 
             /* OK.
              */
-            //syslog(LOG_INFO, "client whitelisted");
             return true;
         }
     }
@@ -345,7 +351,7 @@ static bool try_greylist(const greylist_config_t *config,
     res = tcbdbget3(config->obj_db, key, klen, &len);
     if (res && len == sizeof(oent)) {
         memcpy(&oent, res, len);
-        greylist_check_object(config, &oent, now);
+        debug("found a greylist entry for %.*s", klen, key);
     }
 
     /* Discard stored first-seen if it is the first retrial and
@@ -353,6 +359,11 @@ static bool try_greylist(const greylist_config_t *config,
      */
     if (!greylist_check_object(config, &oent, now)) {
         oent.first = now;
+        debug("invalid retry for %.*s: %s", klen, key,
+              (config->max_age > 0 && now - oent.last > config->max_age) ?
+                  "too old entry"
+                : (oent.last - oent.first < config->delay ?
+                  "retry too early" : "retry too late" ));
     }
 
     /* Update.
@@ -368,19 +379,18 @@ static bool try_greylist(const greylist_config_t *config,
      *        - client whitelisted already ? -> update last-seen timestamp.
      */
     if (oent.first + config->delay < now) {
+        debug("valid retry for %.*s", klen, key);
         if (config->client_awl) {
             INCR_AWL
         }
 
         /* OK
          */
-        //syslog(LOG_INFO, "client whitelisted");
         return true;
     }
 
     /* DUNNO
      */
-    //syslog(LOG_INFO, "client greylisted");
     return false;
 }
 
@@ -413,7 +423,7 @@ static bool greylist_filter_constructor(filter_t *filter)
 
 #define PARSE_CHECK(Expr, Str, ...)                                            \
     if (!(Expr)) {                                                             \
-        syslog(LOG_ERR, Str, ##__VA_ARGS__);                                   \
+        err(Str, ##__VA_ARGS__);                                               \
         greylist_config_delete(&config);                                       \
         return false;                                                          \
     }
@@ -452,7 +462,7 @@ static filter_result_t greylist_filter(const filter_t *filter,
 {
     const greylist_config_t *config = filter->data;
     if (query->state != SMTP_RCPT) {
-        syslog(LOG_WARNING, "greylisting only works as smtpd_recipient_restrictions");
+        warn("greylisting only works as smtpd_recipient_restrictions");
         return HTK_ABORT;
     }
 

diff --git a/postlicyd/main-postlicyd.c b/postlicyd/main-postlicyd.c
index cfe2c56..07fe1de 100644 (file)
--- a/postlicyd/main-postlicyd.c
+++ b/postlicyd/main-postlicyd.c
@@ -81,28 +81,35 @@ static bool policy_process(server_t *pcy, const config_t *config)
     const query_t* query = pcy->data;
     const filter_t *filter;
     if (config->entry_points[query->state] == -1) {
-        syslog(LOG_WARNING, "no filter defined for current protocol_state (%d)", query->state);
+        warn("no filter defined for current protocol_state (%d)", query->state);
         return false;
     }
     filter = array_ptr(config->filters, config->entry_points[query->state]);
     while (true) {
         const filter_hook_t *hook = filter_run(filter, query);
         if (hook == NULL) {
-            syslog(LOG_WARNING, "request client=%s, from=<%s>, to=<%s>: aborted",
-                   query->client_name,
-                   query->sender == NULL ? "undefined" : query->sender,
-                   query->recipient == NULL ? "undefined" : query->recipient);
+            warn("request client=%s, from=<%s>, to=<%s>: aborted",
+                 query->client_name,
+                 query->sender == NULL ? "undefined" : query->sender,
+                 query->recipient == NULL ? "undefined" : query->recipient);
             return false;
         } else if (hook->postfix) {
-            syslog(LOG_INFO, "request client=%s, from=<%s>, to=<%s>: "
-                  "awswer %s from filter %s",
-                   query->client_name,
-                   query->sender == NULL ? "undefined" : query->sender,
-                   query->recipient == NULL ? "undefined" : query->recipient,
-                   htokens[hook->type], filter->name);
+            info("request client=%s, from=<%s>, to=<%s>: "
+                 "awswer %s from filter %s: \"%s\"",
+                 query->client_name,
+                 query->sender == NULL ? "undefined" : query->sender,
+                 query->recipient == NULL ? "undefined" : query->recipient,
+                 htokens[hook->type], filter->name, hook->value);
             policy_answer(pcy, "%s", hook->value);
             return true;
         } else {
+            notice("request client=%s, from=<%s>, to=<%s>: "
+                   "awswer %s from filter %s: next filter %s",
+                   query->client_name,
+                   query->sender == NULL ? "undefined" : query->sender,
+                   query->recipient == NULL ? "undefined" : query->recipient,
+                   htokens[hook->type], filter->name,
+                   (array_ptr(config->filters, hook->filter_id))->name);
             filter = array_ptr(config->filters, hook->filter_id);
         }
     }
@@ -124,7 +131,7 @@ static int policy_run(server_t *pcy, void* vconfig)
     }
     if (nb == 0) {
         if (pcy->ibuf.len)
-            syslog(LOG_ERR, "unexpected end of data");
+            err("unexpected end of data");
         return -1;
     }
 
@@ -153,6 +160,8 @@ void usage(void)
           "    -l <port>    port to listen to\n"
           "    -p <pidfile> file to write our pid to\n"
           "    -f           stay in foreground\n"
+          "    -d           grow logging level\n"
+          "    -u           unsafe mode (don't drop privileges)\n"
          , stderr);
 }
 
@@ -166,7 +175,7 @@ int main(int argc, char *argv[])
     int port = DEFAULT_PORT;
     bool port_from_cli = false;
 
-    for (int c = 0; (c = getopt(argc, argv, "hf" "l:p:")) >= 0; ) {
+    for (int c = 0; (c = getopt(argc, argv, "ufd" "l:p:")) >= 0; ) {
         switch (c) {
           case 'p':
             pidfile = optarg;
@@ -181,6 +190,9 @@ int main(int argc, char *argv[])
           case 'f':
             daemonize = false;
             break;
+          case 'd':
+            ++log_level;
+            break;
           default:
             usage();
             return EXIT_FAILURE;
@@ -193,7 +205,7 @@ int main(int argc, char *argv[])
     }
 
     if (drop_privileges(RUNAS_USER, RUNAS_GROUP) < 0) {
-        syslog(LOG_CRIT, "unable to drop privileges");
+        crit("unable to drop privileges");
         return EXIT_FAILURE;
     }
 

diff --git a/postlicyd/match.c b/postlicyd/match.c
index 41ce317..b6d108f 100644 (file)
--- a/postlicyd/match.c
+++ b/postlicyd/match.c
@@ -54,6 +54,15 @@ typedef struct match_condition_t {
 } match_condition_t;
 ARRAY(match_condition_t)
 
+static const char *condition_names[] = {
+  "unknown",
+  "equals to",
+  "differs from",
+  "contains",
+  "is contained",
+  "is empty"
+};
+
 #define CONDITION_INIT { PTK_UNKNOWN, false, MATCH_UNKNOWN, NULL, 0 }
 
 typedef struct match_config_t {
@@ -86,8 +95,8 @@ static bool match_filter_constructor(filter_t *filter)
 
 #define PARSE_CHECK(Expr, Str, ...)                                            \
     if (!(Expr)) {                                                             \
-        syslog(LOG_ERR, Str, ##__VA_ARGS__);                                   \
-        match_config_delete(&config);                                        \
+        err(Str, ##__VA_ARGS__);                                               \
+        match_config_delete(&config);                                          \
         return false;                                                          \
     }
 
@@ -201,6 +210,10 @@ static inline bool match_condition(const match_condition_t *cond, const query_t
 #undef CASE
       default: return false;
     }
+    debug("running condition: \"%s\" %s %s\"%s\"",
+          field, condition_names[cond->condition],
+          cond->case_sensitive ? "" : "(alternative) ",
+          cond->value ? cond->value : "(none)");
     switch (cond->condition) {
       case MATCH_EQUAL:
       case MATCH_DIFFER:
@@ -253,14 +266,18 @@ static filter_result_t match_filter(const filter_t *filter, const query_t *query
     foreach (const match_condition_t *condition, config->conditions) {
         bool r = match_condition(condition, query);
         if (!r && config->match_all) {
+            debug("condition failed, match_all failed");
             return HTK_FAIL;
         } else if (r && !(config->match_all)) {
+            debug("condition succeed, not-match_all succeed");
             return HTK_MATCH;
         }
     }}
     if (config->match_all) {
+        debug("all conditions matched, match_all succeed");
         return HTK_MATCH;
     } else {
+        debug("no condition matched, not-match_all failed");
         return HTK_FAIL;
     }
 }

diff --git a/postlicyd/query.c b/postlicyd/query.c
index e2511c1..26b590a 100644 (file)
--- a/postlicyd/query.c
+++ b/postlicyd/query.c
@@ -42,7 +42,7 @@ bool query_parse(query_t *query, char *p)
 #define PARSE_CHECK(expr, error, ...)                                        \
     do {                                                                     \
         if (!(expr)) {                                                       \
-            syslog(LOG_ERR, error, ##__VA_ARGS__);                           \
+            err(error, ##__VA_ARGS__);                                       \
             return false;                                                    \
         }                                                                    \
     } while (0)
@@ -124,7 +124,7 @@ bool query_parse(query_t *query, char *p)
             break;
 
           default:
-            syslog(LOG_WARNING, "unexpected key, skipped: %.*s", klen, k);
+            warn("unexpected key, skipped: %.*s", klen, k);
             continue;
         }
     }

diff --git a/postlicyd/rbl.c b/postlicyd/rbl.c
index 1341f02..b3d7d45 100644 (file)
--- a/postlicyd/rbl.c
+++ b/postlicyd/rbl.c
@@ -133,8 +133,8 @@ rbldb_t *rbldb_create(const char *file, bool lock)
         --end;
     }
     if (end != map.end) {
-        syslog(LOG_WARNING, "file %s miss a final \\n, ignoring last line",
-               file);
+        warn("file %s miss a final \\n, ignoring last line",
+             file);
     }
 
     db = p_new(rbldb_t, 1);
@@ -167,7 +167,7 @@ rbldb_t *rbldb_create(const char *file, bool lock)
 #       include "qsort.c"
     }
 
-    syslog(LOG_INFO, "rbl %s loaded, %d IPs", file, db->ips.len);
+    info("rbl %s loaded, %d IPs", file, db->ips.len);
     return db;
 }
 
@@ -242,7 +242,7 @@ static bool rbl_filter_constructor(filter_t *filter)
 
 #define PARSE_CHECK(Expr, Str, ...)                                            \
     if (!(Expr)) {                                                             \
-        syslog(LOG_ERR, Str, ##__VA_ARGS__);                                   \
+        err(Str, ##__VA_ARGS__);                                               \
         rbl_filter_delete(&data);                                              \
         return false;                                                          \
     }
@@ -348,8 +348,8 @@ static filter_result_t rbl_filter(const filter_t *filter, const query_t *query)
     const rbl_filter_t *data = filter->data;
 
     if (parse_ipv4(query->client_address, &end, &ip) != 0) {
-        syslog(LOG_WARNING, "invalid client address: %s, expected ipv4",
-               query->client_address);
+        warn("invalid client address: %s, expected ipv4",
+             query->client_address);
         return HTK_ERROR;
     }
     for (uint32_t i = 0 ; i < data->rbls.len ; ++i) {

diff --git a/postlicyd/strlist.c b/postlicyd/strlist.c
index 4ca2057..a8316a4 100644 (file)
--- a/postlicyd/strlist.c
+++ b/postlicyd/strlist.c
@@ -111,8 +111,8 @@ static trie_t *strlist_create(const char *file, bool reverse, bool lock)
         --end;
     }
     if (end != map.end) {
-        syslog(LOG_WARNING, "file %s miss a final \\n, ignoring last line",
-               file);
+        warn("file %s miss a final \\n, ignoring last line",
+             file);
     }
 
     db = trie_new();
@@ -122,7 +122,7 @@ static trie_t *strlist_create(const char *file, bool reverse, bool lock)
             eol = end;
         }
         if (eol - p >= BUFSIZ) {
-            syslog(LOG_ERR, "unreasonnable long line");
+            err("unreasonnable long line");
             file_map_close(&map);
             trie_delete(&db);
             return NULL;
@@ -154,7 +154,7 @@ static bool strlist_filter_constructor(filter_t *filter)
 
 #define PARSE_CHECK(Expr, Str, ...)                                            \
     if (!(Expr)) {                                                             \
-        syslog(LOG_ERR, Str, ##__VA_ARGS__);                                   \
+        err(Str, ##__VA_ARGS__);                                               \
         strlist_config_delete(&config);                                        \
         return false;                                                          \
     }
@@ -319,12 +319,11 @@ static filter_result_t strlist_filter(const filter_t *filter, const query_t *que
     if (config->is_email && 
         ((config->match_sender && query->state < SMTP_MAIL)
         || (config->match_recipient && query->state != SMTP_RCPT))) {
-        syslog(LOG_WARNING, "trying to match an email against a field that is not "
-               "available in current protocol state");
+        warn("trying to match an email against a field that is not "
+             "available in current protocol state");
         return HTK_ABORT;
     } else if (config->is_hostname && config->match_helo && query->state < SMTP_HELO) {
-        syslog(LOG_WARNING, "trying to match hostname against helo before helo "
-               "is received");
+        warn("trying to match hostname against helo before helo is received");
         return HTK_ABORT;
     }
 #define LOOKUP(Flag, Field)                                                    \

diff --git a/postlicyd/tst-filters.c b/postlicyd/tst-filters.c
index 9b83fad..2e322fb 100644 (file)
--- a/postlicyd/tst-filters.c
+++ b/postlicyd/tst-filters.c
@@ -54,7 +54,7 @@ static char *read_query(const char *basepath, const char *filename,
             return NULL;
         }
         if (map.end - map.map >= BUFSIZ) {
-            syslog(LOG_ERR, "File too large for a testcase: %s", path);
+            err("File too large for a testcase: %s", path);
             file_map_close(&map);
             return NULL;
         }
@@ -73,7 +73,7 @@ static char *read_query(const char *basepath, const char *filename,
         return NULL;
     }
     if (!query_parse(q, buff)) {
-        syslog(LOG_ERR, "Cannot parse query from file %s", filename);
+        err("Cannot parse query from file %s", filename);
         return NULL;
     }
     return eoq + 2;
@@ -100,21 +100,21 @@ static bool run_testcase(const config_t *config, const char *basepath,
         char *sep = memchr(eol, '=', neol - eol);
         if (sep == NULL) {
             eol = neol + 1;
-            syslog(LOG_ERR, "missing separator");
+            err("missing separator");
             continue;
         }
         *sep = '\0';
 
         int pos = filter_find_with_name(&config->filters, eol);
         if (pos == -1) {
-            syslog(LOG_ERR, "Unknown filter %s", eol);
+            err("Unknown filter %s", eol);
             eol = neol + 1;
             continue;
         }
         ++sep;
         filter_result_t result = hook_tokenize(sep, neol - sep);
         if (result == HTK_UNKNOWN) {
-            syslog(LOG_ERR, "Unknown filter result %.*s", neol - sep, sep);
+            err("Unknown filter result %.*s", neol - sep, sep);
             eol = neol + 1;
             continue;
         }