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;
return;
default:
- syslog(LOG_ERR, "Killed (got signal %d)...", sig);
+ err("Killed (got signal %d)...", sig);
exit(-1);
}
}
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;
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;
}
static void common_shutdown(void)
{
if (daemon_process) {
- syslog(LOG_INFO, "Stopping...");
+ info("stopping...");
}
pidfile_close();
for (int i = -1; __madexit[i]; i--) {
#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)
#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);
signal(SIGTERM, &common_sighandler); \
signal(SIGHUP, &common_sighandler); \
signal(SIGSEGV, &common_sighandler); \
- syslog(LOG_INFO, "Starting..."); \
+ info("starting..."); \
return 0; \
} \
\
if (sighup && refresh) {
if (!refresh(config)) {
- syslog(LOG_ERR, "error while refreshing configuration");
+ crit("error while refreshing configuration");
return EXIT_FAILURE;
}
}
--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();
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) {
}
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;
}
if (p == q) {
buffer_addstr(&srsd->obuf, "400 empty request ???\n");
- syslog(LOG_WARNING, "empty request");
+ warn("empty request");
goto skip;
}
++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);
}
if (!lineno) {
- syslog(LOG_CRIT, "%s: empty file, no secrets", sfile);
+ crit("%s: empty file, no secrets", sfile);
goto error;
}
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) {
array_deep_wipe(config->params, filter_params_wipe);
if (!ok) {
- syslog(LOG_ERR, "no entry point defined");
+ err("no entry point defined");
}
return ok;
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 { \
return true;
badeof:
- syslog(LOG_ERR, "Unexpected end of file");
+ err("Unexpected end of file");
error:
if (filter.name) {
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);
{
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;
}
}}
{
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;
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;
}
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);
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);
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();
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);
/** 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) {
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);
}
}
*/
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;
}
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));
}
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));
#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));
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;
}
}
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
*/
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.
* - 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;
}
#define PARSE_CHECK(Expr, Str, ...) \
if (!(Expr)) { \
- syslog(LOG_ERR, Str, ##__VA_ARGS__); \
+ err(Str, ##__VA_ARGS__); \
greylist_config_delete(&config); \
return false; \
}
{
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;
}
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);
}
}
}
if (nb == 0) {
if (pcy->ibuf.len)
- syslog(LOG_ERR, "unexpected end of data");
+ err("unexpected end of data");
return -1;
}
" -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);
}
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;
case 'f':
daemonize = false;
break;
+ case 'd':
+ ++log_level;
+ break;
default:
usage();
return EXIT_FAILURE;
}
if (drop_privileges(RUNAS_USER, RUNAS_GROUP) < 0) {
- syslog(LOG_CRIT, "unable to drop privileges");
+ crit("unable to drop privileges");
return EXIT_FAILURE;
}
} 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 {
#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; \
}
#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:
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;
}
}
#define PARSE_CHECK(expr, error, ...) \
do { \
if (!(expr)) { \
- syslog(LOG_ERR, error, ##__VA_ARGS__); \
+ err(error, ##__VA_ARGS__); \
return false; \
} \
} while (0)
break;
default:
- syslog(LOG_WARNING, "unexpected key, skipped: %.*s", klen, k);
+ warn("unexpected key, skipped: %.*s", klen, k);
continue;
}
}
--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);
# 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;
}
#define PARSE_CHECK(Expr, Str, ...) \
if (!(Expr)) { \
- syslog(LOG_ERR, Str, ##__VA_ARGS__); \
+ err(Str, ##__VA_ARGS__); \
rbl_filter_delete(&data); \
return false; \
}
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) {
--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();
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;
#define PARSE_CHECK(Expr, Str, ...) \
if (!(Expr)) { \
- syslog(LOG_ERR, Str, ##__VA_ARGS__); \
+ err(Str, ##__VA_ARGS__); \
strlist_config_delete(&config); \
return false; \
}
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) \
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;
}
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;
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;
}