Download raw body.
relayd: allow setting log level in relayd.conf (fix relayctl log command)
"relayctl log verbose|brief" is simply useless and doesn't change a thing.
We've hidden everything useful for debugging behind DPRINF. You can use
the diffs to debug relayd again or to get useful information if something
isn't working in your setup.
I don't know the history here. Performance? But performance doesn't help me
when I need to debug my config ;).
With these diffs, we can also configure it with "log level
brief|verbose". I'd prefer have info|warn|fatal|debug (like the log
functions we have). But log.c doesn't support that, and I don't want to
modify log.c
Details, see commit msg.
OK?
commit 2f79b1b972e5c80d55562a0381120774463bd669
Author: Rafael Sadowski <rafael@sizeofvoid.org>
Date: Sat Aug 1 14:06:54 2026 +0200
relayd: allow setting log level from relayd.conf
Add "log level (brief|verbose)" which sets or clears RELAYD_OPT_VERBOSE
just like relayctl log verbose|brief does at runtime.
This makes sense now because the recent DPRINTF removal turned all
DPRINTF calls into real log_debug calls. Some debug logs moved to
warning. Some remained DPRINF().
Before that change the toggle had almost nothing to gate. All debug
output was compiled out unless relayd was built with DEBUG > 1. So
"log verbose" in relayctl was practically a no-op for users.
It was impossible for the user to work out why the setup/config wasn't
working.
Now the toggle actually does what its name suggests. Pinning the
level in the config file lets it survive restarts and SIGHUP reloads.
diff --git a/agentx_control.c b/agentx_control.c
index 7af1c0e..41bb2d7 100644
--- a/agentx_control.c
+++ b/agentx_control.c
@@ -1003,7 +1003,7 @@ snmp_element(const char *oidstr, enum snmp_type type, void *buf, int64_t val,
u_int64_t l;
struct snmp_oid oid;
- DPRINTF("%s: oid %s type %d buf %p val %lld", __func__,
+ log_debug("%s: oid %s type %d buf %p val %lld", __func__,
oidstr, type, buf, val);
if (snmp_string2oid(oidstr, &oid) == -1)
diff --git a/ca.c b/ca.c
index f3d3dc0..93dfab6 100644
--- a/ca.c
+++ b/ca.c
@@ -268,7 +268,7 @@ ca_dispatch_relay(int fd, struct privsep_proc *p, struct imsg *imsg)
if ((rsa = EVP_PKEY_get1_RSA(pkey)) == NULL)
fatalx("%s: invalid relay key", __func__);
- DPRINTF("%s:%d: key hash %s proc %d",
+ log_debug("%s:%d: key hash %s proc %d",
__func__, __LINE__, cko.cko_hash, cko.cko_proc);
if ((to = calloc(1, cko.cko_tlen)) == NULL)
@@ -508,14 +508,18 @@ rsae_send_imsg(int flen, const u_char *from, u_char *to, RSA *rsa,
int
rsae_priv_enc(int flen, const u_char *from, u_char *to, RSA *rsa, int padding)
{
- DPRINTF("%s:%d", __func__, __LINE__);
+#if DEBUG_CERT
+ log_debug("%s:%d", __func__, __LINE__);
+#endif
return rsae_send_imsg(flen, from, to, rsa, padding, IMSG_CA_PRIVENC);
}
int
rsae_priv_dec(int flen, const u_char *from, u_char *to, RSA *rsa, int padding)
{
- DPRINTF("%s:%d", __func__, __LINE__);
+#if DEBUG_CERT
+ log_debug("%s:%d", __func__, __LINE__);
+#endif
return rsae_send_imsg(flen, from, to, rsa, padding, IMSG_CA_PRIVDEC);
}
@@ -701,7 +705,9 @@ ecdsae_do_sign(const unsigned char *dgst, int dgst_len, const BIGNUM *inv,
ECDSA_SIG *(*psign_sig)(const unsigned char *, int, const BIGNUM *,
const BIGNUM *, EC_KEY *);
- DPRINTF("%s:%d", __func__, __LINE__);
+#if DEBUG_CERT
+ log_debug("%s:%d", __func__, __LINE__);
+#endif
if (EC_KEY_get_ex_data(eckey, 0) != NULL)
return (ecdsae_send_enc_imsg(dgst, dgst_len, inv, rp, eckey));
EC_KEY_METHOD_get_sign(ecdsa_default, NULL, NULL, &psign_sig);
diff --git a/check_script.c b/check_script.c
index 07b02b8..4caca71 100644
--- a/check_script.c
+++ b/check_script.c
@@ -106,7 +106,7 @@ script_exec(struct relayd *env, struct ctl_script *scr)
return (-1);
}
- DPRINTF("%s: running script %s, host %s",
+ log_debug("%s: running script %s, host %s",
__func__, scr->path, scr->name);
arg = scr->name;
diff --git a/check_tls.c b/check_tls.c
index f659ba1..3ff55be 100644
--- a/check_tls.c
+++ b/check_tls.c
@@ -206,8 +206,6 @@ check_tls_cleanup(struct ctl_tcp_event *cte)
void
check_tls_error(struct ctl_tcp_event *cte, const char *where, const char *what)
{
- if (log_getverbose() < 2)
- return;
log_debug("TLS error: %s: %s: %s", where, what, tls_error(cte->tls));
}
diff --git a/config.c b/config.c
index b273fd7..a6fe546 100644
--- a/config.c
+++ b/config.c
@@ -273,6 +273,8 @@ config_getcfg(struct relayd *env, struct imsg *imsg)
return (-1);
}
+ log_setverbose((env->sc_conf.opts & RELAYD_OPT_VERBOSE) ? 2 : 0);
+
what = ps->ps_what[privsep_process];
if (what & CONFIG_TABLES) {
@@ -316,7 +318,7 @@ config_settable(struct relayd *env, struct table *tb)
if (id == PROC_HCE && tb->conf.check == CHECK_NOCHECK)
continue;
- DPRINTF("%s: sending table %s %d to %s", __func__,
+ log_debug("%s: sending table %s %d to %s", __func__,
tb->conf.name, tb->conf.id, env->sc_ps->ps_title[id]);
c = 0;
@@ -379,7 +381,7 @@ config_gettable(struct relayd *env, struct imsg *imsg)
env->sc_tablecount++;
- DPRINTF("%s: %s %d received table %d (%s)", __func__,
+ log_debug("%s: %s %d received table %d (%s)", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
tb->conf.id, tb->conf.name);
@@ -423,7 +425,7 @@ config_gethost(struct relayd *env, struct imsg *imsg)
TAILQ_INSERT_TAIL(&tb->hosts, host, entry);
TAILQ_INSERT_TAIL(&env->sc_hosts, host, globalentry);
- DPRINTF("%s: %s %d received host %s for table %s", __func__,
+ log_debug("%s: %s %d received host %s for table %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
host->conf.name, tb->conf.name);
@@ -442,7 +444,7 @@ config_setrdr(struct relayd *env, struct rdr *rdr)
id == privsep_process)
continue;
- DPRINTF("%s: sending rdr %s to %s", __func__,
+ log_debug("%s: sending rdr %s to %s", __func__,
rdr->conf.name, ps->ps_title[id]);
proc_compose(ps, id, IMSG_CFG_RDR,
@@ -487,7 +489,7 @@ config_getrdr(struct relayd *env, struct imsg *imsg)
env->sc_rdrcount++;
- DPRINTF("%s: %s %d received rdr %s", __func__,
+ log_debug("%s: %s %d received rdr %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
rdr->conf.name);
@@ -517,7 +519,7 @@ config_getvirt(struct relayd *env, struct imsg *imsg)
TAILQ_INSERT_TAIL(&rdr->virts, virt, entry);
- DPRINTF("%s: %s %d received address for rdr %s", __func__,
+ log_debug("%s: %s %d received address for rdr %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
rdr->conf.name);
@@ -536,7 +538,7 @@ config_setrt(struct relayd *env, struct router *rt)
id == privsep_process)
continue;
- DPRINTF("%s: sending router %s to %s tbl %d", __func__,
+ log_debug("%s: sending router %s to %s tbl %d", __func__,
rt->rt_conf.name, ps->ps_title[id], rt->rt_conf.gwtable);
proc_compose(ps, id, IMSG_CFG_ROUTER,
@@ -576,7 +578,7 @@ config_getrt(struct relayd *env, struct imsg *imsg)
env->sc_routercount++;
- DPRINTF("%s: %s %d received router %s", __func__,
+ log_debug("%s: %s %d received router %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
rt->rt_conf.name);
@@ -618,7 +620,7 @@ config_getroute(struct relayd *env, struct imsg *imsg)
env->sc_routecount++;
- DPRINTF("%s: %s %d received route %d for router %s", __func__,
+ log_debug("%s: %s %d received route %d for router %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
nr->nr_conf.id, rt->rt_conf.name);
@@ -638,7 +640,7 @@ config_setproto(struct relayd *env, struct protocol *proto)
id == privsep_process)
continue;
- DPRINTF("%s: sending protocol %s to %s", __func__,
+ log_debug("%s: sending protocol %s to %s", __func__,
proto->name, ps->ps_title[id]);
c = 0;
@@ -670,7 +672,7 @@ config_setrule(struct relayd *env, struct protocol *proto)
id == privsep_process)
continue;
- DPRINTF("%s: sending rules %s to %s", __func__,
+ log_debug("%s: sending rules %s to %s", __func__,
proto->name, ps->ps_title[id]);
/* Now send all the rules */
@@ -746,7 +748,7 @@ config_getproto(struct relayd *env, struct imsg *imsg)
env->sc_protocount++;
- DPRINTF("%s: %s %d received protocol %s", __func__,
+ log_debug("%s: %s %d received protocol %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
proto->name);
@@ -791,7 +793,7 @@ config_getrule(struct relayd *env, struct imsg *imsg)
free(rule); \
return (-1); \
} \
- DPRINTF("%s: %s %s (len %ld, option %d): %s", __func__, \
+ log_debug("%s: %s %s (len %ld, option %d): %s", __func__,\
#_n, #_f, len, \
rule->rule_kv[_n].kv_option, \
rule->rule_kv[_n].kv_##_f); \
@@ -818,7 +820,7 @@ config_getrule(struct relayd *env, struct imsg *imsg)
TAILQ_INSERT_TAIL(&proto->rules, rule, rule_entry);
- DPRINTF("%s: %s %d received rule %u for protocol %s", __func__,
+ log_debug("%s: %s %d received rule %u for protocol %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
rule->rule_id, proto->name);
@@ -869,7 +871,7 @@ config_setrelay(struct relayd *env, struct relay *rlay)
if ((what & CONFIG_RELAYS) == 0 || id == privsep_process)
continue;
- DPRINTF("%s: sending relay %s to %s fd %d", __func__,
+ log_debug("%s: sending relay %s to %s fd %d", __func__,
rlay->rl_conf.name, ps->ps_title[id], rlay->rl_s);
memcpy(&rl, &rlay->rl_conf, sizeof(rl));
@@ -1106,7 +1108,7 @@ config_getrelay(struct relayd *env, struct imsg *imsg)
env->sc_relaycount++;
- DPRINTF("%s: %s %d received relay %s", __func__,
+ log_debug("%s: %s %d received relay %s", __func__,
ps->ps_title[privsep_process], ps->ps_instance,
rlay->rl_conf.name);
@@ -1151,7 +1153,7 @@ config_getrelaytable(struct relayd *env, struct imsg *imsg)
TAILQ_INSERT_TAIL(&rlay->rl_tables, rlt, rlt_entry);
- DPRINTF("%s: %s %d received relay table %s for relay %s", __func__,
+ log_debug("%s: %s %d received relay table %s for relay %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
table->conf.name, rlay->rl_conf.name);
@@ -1213,7 +1215,7 @@ config_getrelayfd(struct relayd *env, struct imsg *imsg)
break;
}
- DPRINTF("%s: %s %d received relay type %d for relay %s", __func__,
+ log_debug("%s: %s %d received relay type %d for relay %s", __func__,
env->sc_ps->ps_title[privsep_process], env->sc_ps->ps_instance,
crfd.type, rlay->rl_conf.name);
diff --git a/control.c b/control.c
index fb64608..3ed43bf 100644
--- a/control.c
+++ b/control.c
@@ -265,7 +265,7 @@ control_dispatch_imsg(int fd, short event, void *arg)
break;
if (c->waiting) {
- log_debug("%s: unexpected imsg %d",
+ log_warn("%s: unexpected imsg %d",
__func__, imsg_get_type(&imsg));
imsg_free(&imsg);
control_close(fd, cs);
diff --git a/parse.y b/parse.y
index e89d40e..0c6839d 100644
--- a/parse.y
+++ b/parse.y
@@ -183,7 +183,7 @@ typedef struct {
%token TIMEOUT TLS TO ROUTER RTLABEL TRANSPARENT URL WITH TTL RTABLE
%token MATCH PARAMS RANDOM LEASTSTATES SRCHASH KEY CERTIFICATE PASSWORD ECDHE
%token EDH TICKETS CONNECTION CONNECTIONS CONTEXT ERRORS STATE CHANGES CHECKS
-%token WEBSOCKETS PFLOG CLIENT PROXYPROTO V1 V2
+%token WEBSOCKETS PFLOG CLIENT PROXYPROTO V1 V2 VERBOSE BRIEF LEVEL
%token <v.string> STRING
%token <v.number> NUMBER
%type <v.string> context hostname interface table value path
@@ -412,6 +412,12 @@ main : INTERVAL NUMBER {
| LOG loglevel {
conf->sc_conf.opts |= $2;
}
+ | LOG LEVEL VERBOSE {
+ conf->sc_conf.opts |= RELAYD_OPT_VERBOSE;
+ }
+ | LOG LEVEL BRIEF {
+ conf->sc_conf.opts &= ~RELAYD_OPT_VERBOSE;
+ }
| TIMEOUT timeout {
bcopy(&$2, &conf->sc_conf.timeout,
sizeof(struct timeval));
@@ -2524,6 +2530,7 @@ lookup(char *s)
{ "backup", BACKUP },
{ "binary", BINARY },
{ "block", BLOCK },
+ { "brief", BRIEF },
{ "buffer", BUFFER },
{ "ca", CA },
{ "cache", CACHE },
@@ -2566,6 +2573,7 @@ lookup(char *s)
{ "keypair", KEYPAIR },
{ "label", LABEL },
{ "least-states", LEASTSTATES },
+ { "level", LEVEL },
{ "listen", LISTEN },
{ "loadbalance", LOADBALANCE },
{ "log", LOG },
@@ -2632,6 +2640,7 @@ lookup(char *s)
{ "v1", V1 },
{ "v2", V2 },
{ "value", VALUE },
+ { "verbose", VERBOSE },
{ "websockets", WEBSOCKETS },
{ "with", WITH }
};
diff --git a/pfe.c b/pfe.c
index c66ad06..1438171 100644
--- a/pfe.c
+++ b/pfe.c
@@ -351,7 +351,7 @@ pfe_dispatch_relay(int fd, struct privsep_proc *p, struct imsg *imsg)
TAILQ_REMOVE(&env->sc_sessions, s, se_entry);
free(s);
} else {
- DPRINTF("removal of unpublished session %i", sid);
+ log_debug("removal of unpublished session %i", sid);
}
break;
default:
diff --git a/pfe_filter.c b/pfe_filter.c
index a3587dd..f3dbdae 100644
--- a/pfe_filter.c
+++ b/pfe_filter.c
@@ -414,7 +414,7 @@ sync_ruleset(struct relayd *env, struct rdr *rdr, int enable)
rio.rule.dst.port[1] = address->port.val[1];
rio.rule.rtableid = -1; /* stay in the main routing table */
rio.rule.onrdomain = env->sc_rtable;
- DPRINTF("%s rtable %d", __func__, env->sc_rtable);
+ log_debug("%s rtable %d", __func__, env->sc_rtable);
if (rio.rule.proto == IPPROTO_TCP)
rio.rule.timeout[PFTM_TCP_ESTABLISHED] =
diff --git a/relay.c b/relay.c
index 6992900..efc2045 100644
--- a/relay.c
+++ b/relay.c
@@ -724,7 +724,7 @@ relay_connected(int fd, short sig, void *arg)
return;
}
- DPRINTF("%s: session %d: successful", __func__, con->se_id);
+ log_debug("%s: session %d: successful", __func__, con->se_id);
/* Log destination if it was changed in a keep-alive connection */
if ((con->se_table != con->se_table0) &&
@@ -951,7 +951,7 @@ relay_splice(struct ctl_relay_event *cre)
return (0);
if (!(cre->toread == TOREAD_UNLIMITED || cre->toread > 0)) {
- DPRINTF("%s: session %d: splice dir %d, nothing to read %lld",
+ log_debug("%s: session %d: splice dir %d, nothing to read %lld",
__func__, con->se_id, cre->dir, cre->toread);
return (0);
}
@@ -959,7 +959,7 @@ relay_splice(struct ctl_relay_event *cre)
/* do not splice before buffers have not been completely flushed */
if (EVBUFFER_LENGTH(cre->bev->input) ||
EVBUFFER_LENGTH(cre->dst->bev->output)) {
- DPRINTF("%s: session %d: splice dir %d, dirty buffer",
+ log_debug("%s: session %d: splice dir %d, dirty buffer",
__func__, con->se_id, cre->dir);
bufferevent_disable(cre->bev, EV_READ);
return (0);
@@ -977,7 +977,7 @@ relay_splice(struct ctl_relay_event *cre)
cre->splicelen = 0;
bufferevent_enable(cre->bev, EV_READ);
- DPRINTF("%s: session %d: splice dir %d, maximum %lld, successful",
+ log_debug("%s: session %d: splice dir %d, maximum %lld, successful",
__func__, con->se_id, cre->dir, cre->toread);
return (1);
@@ -1000,7 +1000,7 @@ relay_splicelen(struct ctl_relay_event *cre)
return (-1);
}
- DPRINTF("%s: session %d: splice dir %d, length %lld",
+ log_debug("%s: session %d: splice dir %d, length %lld",
__func__, con->se_id, cre->dir, len);
if (len > cre->splicelen) {
@@ -1034,7 +1034,7 @@ relay_error(struct bufferevent *bev, short error, void *arg)
struct rsession *con = cre->con;
struct evbuffer *dst;
- DPRINTF("%s: session %d: dir %d state %d to read %lld event error %x",
+ log_debug("%s: session %d: dir %d state %d to read %lld event error %x",
__func__, con->se_id, cre->dir, cre->state, cre->toread, error);
if (error & EVBUFFER_TIMEOUT) {
if (cre->splicelen >= 0) {
@@ -1132,7 +1132,7 @@ relay_accept(int fd, short event, void *arg)
event_del(&rlay->rl_ev);
evtimer_add(&rlay->rl_evt, &evtpause);
- log_debug("%s: deferring connections", __func__);
+ DPRINTF("%s: deferring connections", __func__);
}
return;
}
@@ -1367,7 +1367,7 @@ relay_from_table(struct rsession *con)
host = rlt->rlt_host[idx];
- DPRINTF("%s: session %d: table %s host %s, "
+ log_debug("%s: session %d: table %s host %s, "
"p 0x%016llx, idx %d, cnt %d, max %d",
__func__, con->se_id, table->conf.name,
host->conf.name, p, idx, cnt, maxtries);
@@ -1379,20 +1379,20 @@ relay_from_table(struct rsession *con)
} else {
/* handle all non-hashing algorithms */
host = rlt->rlt_host[idx];
- DPRINTF("%s: session %d: table %s host %s, p 0x%016llx, idx %d",
+ log_debug("%s: session %d: table %s host %s, p 0x%016llx, idx %d",
__func__, con->se_id, table->conf.name, host->conf.name,
p, idx);
}
while (host != NULL) {
- DPRINTF("%s: session %d: host %s", __func__,
+ log_debug("%s: session %d: host %s", __func__,
con->se_id, host->conf.name);
if (!table->conf.check || host->up == HOST_UP)
goto found;
host = TAILQ_NEXT(host, entry);
}
TAILQ_FOREACH(host, &table->hosts, entry) {
- DPRINTF("%s: session %d: next host %s",
+ log_debug("%s: session %d: next host %s",
__func__, con->se_id, host->conf.name);
if (!table->conf.check || host->up == HOST_UP)
goto found;
@@ -1518,7 +1518,7 @@ void
relay_connect_state(struct rsession *con, struct ctl_relay_event *cre,
enum relay_state new)
{
- DPRINTF("%s: session %d: %s state %s -> %s",
+ log_debug("%s: session %d: %s state %s -> %s",
__func__, con->se_id,
cre->dir == RELAY_DIR_REQUEST ? "accept" : "connect",
relay_state(cre->state), relay_state(new));
@@ -1538,7 +1538,7 @@ relay_connect_retry(int fd, short sig, void *arg)
relay_inflight = 1;
}
- DPRINTF("%s: retry %d of %d, inflight: %d", __func__,
+ log_debug("%s: retry %d of %d, inflight: %d", __func__,
con->se_retrycount, con->se_retry, relay_inflight);
if (sig != EV_TIMEOUT)
@@ -1551,7 +1551,7 @@ relay_connect_retry(int fd, short sig, void *arg)
* available: client could have closed it while we were waiting?
*/
- DPRINTF("%s: got EV_TIMEOUT", __func__);
+ log_debug("%s: got EV_TIMEOUT", __func__);
if (getdtablecount() + FD_RESERVE +
relay_inflight > getdtablesize()) {
@@ -1598,7 +1598,7 @@ relay_connect_retry(int fd, short sig, void *arg)
else
relay_connect_state(con, &con->se_out, STATE_CONNECTED);
relay_inflight--;
- DPRINTF("%s: inflight decremented, now %d", __func__, relay_inflight);
+ log_debug("%s: inflight decremented, now %d", __func__, relay_inflight);
event_add(&rlay->rl_ev, NULL);
@@ -1724,7 +1724,7 @@ relay_connect(struct rsession *con)
relay_connect_state(con, &con->se_out, STATE_CONNECTED);
relay_inflight--;
- DPRINTF("%s: inflight decremented, now %d", __func__,
+ log_debug("%s: inflight decremented, now %d", __func__,
relay_inflight);
if (errno == EINPROGRESS)
@@ -1927,7 +1927,7 @@ relay_dispatch_pfe(int fd, struct privsep_proc *p, struct imsg *imsg)
NULL)
fatalx("%s: invalid table id", __func__);
- DPRINTF("%s: [%d] state %d for "
+ log_debug("%s: [%d] state %d for "
"host %u %s", __func__, p->p_ps->ps_instance, st.up,
host->conf.id, host->conf.name);
@@ -2445,11 +2445,7 @@ relay_tls_handshake(int fd, short event, void *arg)
ret = tls_handshake(cre->tls);
if (ret == 0) {
-#ifdef DEBUG
- log_info(
-#else
log_debug(
-#endif
"relay %s, tls session %d %s (%d active)",
rlay->rl_conf.name, con->se_id,
cre->dir == RELAY_DIR_REQUEST ? "established" : "connected",
@@ -2498,7 +2494,7 @@ relay_tls_handshake(int fd, short event, void *arg)
return;
}
- DPRINTF("%s: session %d: scheduling on %s", __func__, con->se_id,
+ log_debug("%s: session %d: scheduling on %s", __func__, con->se_id,
(retry_flag == EV_READ) ? "EV_READ" : "EV_WRITE");
event_again(&con->se_ev, fd, EV_TIMEOUT|retry_flag, relay_tls_handshake,
&con->se_tv_start, &rlay->rl_conf.timeout, cre);
diff --git a/relay_http.c b/relay_http.c
index dbaafa7..e3a668f 100644
--- a/relay_http.c
+++ b/relay_http.c
@@ -123,8 +123,7 @@ relay_http_priv_init(struct rsession *con)
if ((hs = calloc(1, sizeof(*hs))) == NULL)
return (-1);
SIMPLEQ_INIT(&hs->hs_methods);
- DPRINTF("%s: session %d http_session %p", __func__,
- con->se_id, hs);
+ log_debug("%s: session %d http_session %p", __func__, con->se_id, hs);
con->se_priv = hs;
return (relay_httpdesc_init(&con->se_in));
}
@@ -203,7 +202,7 @@ relay_read_http(struct bufferevent *bev, void *arg)
cre->timedout = 0;
size = EVBUFFER_LENGTH(src);
- DPRINTF("%s: session %d: size %lu, to read %lld",
+ log_debug("%s: session %d: size %lu, to read %lld",
__func__, con->se_id, size, cre->toread);
if (size == 0) {
if (cre->dir == RELAY_DIR_RESPONSE)
@@ -280,7 +279,7 @@ relay_read_http(struct bufferevent *bev, void *arg)
key = desc->http_lastheader->kv_key;
value = desc->http_lastheader->kv_value;
- DPRINTF("%s: session %d: header '%s: %s'", __func__,
+ log_debug("%s: session %d: header '%s: %s'", __func__,
con->se_id, key, value);
if (desc->http_method != HTTP_METHOD_NONE &&
@@ -644,7 +643,7 @@ relay_read_httpcontent(struct bufferevent *bev, void *arg)
cre->timedout = 0;
size = EVBUFFER_LENGTH(src);
- DPRINTF("%s: session %d: size %lu, to read %lld", __func__,
+ log_debug("%s: session %d: size %lu, to read %lld", __func__,
con->se_id, size, cre->toread);
if (!size)
return;
@@ -664,7 +663,7 @@ relay_read_httpcontent(struct bufferevent *bev, void *arg)
goto fail;
cre->toread -= size;
}
- DPRINTF("%s: done, size %lu, to read %lld", __func__,
+ log_debug("%s: done, size %lu, to read %lld", __func__,
size, cre->toread);
}
if (cre->toread == 0) {
@@ -705,7 +704,7 @@ relay_read_httpchunks(struct bufferevent *bev, void *arg)
cre->timedout = 0;
size = EVBUFFER_LENGTH(src);
- DPRINTF("%s: session %d: size %lu, to read %lld", __func__,
+ log_debug("%s: session %d: size %lu, to read %lld", __func__,
con->se_id, size, cre->toread);
if (!size)
return;
@@ -725,7 +724,7 @@ relay_read_httpchunks(struct bufferevent *bev, void *arg)
goto fail;
cre->toread -= size;
}
- DPRINTF("%s: done, size %lu, to read %lld", __func__,
+ log_debug("%s: done, size %lu, to read %lld", __func__,
size, cre->toread);
}
switch (cre->toread) {
@@ -768,7 +767,7 @@ relay_read_httpchunks(struct bufferevent *bev, void *arg)
free(line);
if ((cre->toread = llval) == 0) {
- DPRINTF("%s: last chunk", __func__);
+ log_debug("%s: last chunk", __func__);
cre->toread = TOREAD_HTTP_CHUNK_TRAILER;
}
break;
@@ -870,7 +869,7 @@ _relay_lookup_url(struct ctl_relay_event *cre, char *host, char *path,
break;
}
- DPRINTF("%s: session %d: %s, %s: %d", __func__, con->se_id,
+ log_debug("%s: session %d: %s, %s: %d", __func__, con->se_id,
str, kv->kv_key, strcasecmp(kv->kv_key, str));
if (strcasecmp(kv->kv_key, str) == 0) {
@@ -903,7 +902,7 @@ relay_lookup_url(struct ctl_relay_event *cre, const char *host, struct kv *kv)
* developers_guide.html#PerformingLookups
*/
- DPRINTF("%s: host '%s', path '%s', query '%s'",
+ log_debug("%s: host '%s', path '%s', query '%s'",
__func__, host, desc->http_path,
desc->http_query == NULL ? "" : desc->http_query);
@@ -995,7 +994,7 @@ relay_lookup_cookie(struct ctl_relay_event *cre, const char *str,
if (value[strlen(value) - 1] == '"')
value[strlen(value) - 1] = '\0';
- DPRINTF("%s: key %s = %s, %s = %s : %d",
+ log_debug("%s: key %s = %s, %s = %s : %d",
__func__, key, value, kv->kv_key, kv->kv_value,
strcasecmp(kv->kv_key, key));
@@ -1178,13 +1177,13 @@ relay_close_http(struct rsession *con)
struct http_session *hs = con->se_priv;
struct http_method_node *hmn;
- DPRINTF("%s: session %d http_session %p", __func__,
+ log_debug("%s: session %d http_session %p", __func__,
con->se_id, hs);
if (hs != NULL)
while (!SIMPLEQ_EMPTY(&hs->hs_methods)) {
hmn = SIMPLEQ_FIRST(&hs->hs_methods);
SIMPLEQ_REMOVE_HEAD(&hs->hs_methods, hmn_entry);
- DPRINTF("%s: session %d freeing %s", __func__,
+ log_debug("%s: session %d freeing %s", __func__,
con->se_id, relay_httpmethod_byid(hmn->hmn_method));
free(hmn);
}
@@ -1298,7 +1297,7 @@ relay_writeresponse_http(struct ctl_relay_event *dst,
{
struct http_descriptor *desc = (struct http_descriptor *)cre->desc;
- DPRINTF("version: %s rescode: %s resmsg: %s", desc->http_version,
+ log_debug("version: %s rescode: %s resmsg: %s", desc->http_version,
desc->http_rescode, desc->http_resmesg);
if (relay_bufferevent_print(dst, desc->http_version) == -1 ||
@@ -1852,12 +1851,12 @@ relay_apply_actions(struct ctl_relay_event *cre, struct kvlist *actions,
#define RELAY_GET_SKIP_STEP(i) \
do { \
r = r->rule_skip[i]; \
- DPRINTF("%s:%d: skip %d rules", __func__, __LINE__, i); \
+ log_debug("%s:%d: skip %d rules", __func__, __LINE__, i);\
} while (0)
#define RELAY_GET_NEXT_STEP \
do { \
- DPRINTF("%s:%d: next rule", __func__, __LINE__); \
+ log_debug("%s:%d: next rule", __func__, __LINE__); \
goto nextrule; \
} while (0)
@@ -1909,7 +1908,7 @@ relay_test(struct protocol *proto, struct ctl_relay_event *cre)
else if ((res = relay_httpcookie_test(cre, r, &matches)) != 0)
RELAY_GET_NEXT_STEP;
else {
- DPRINTF("%s: session %d: matched rule %d",
+ log_debug("%s: session %d: matched rule %d",
__func__, con->se_id, r->rule_id);
if (r->rule_action == RULE_ACTION_MATCH) {
@@ -1939,7 +1938,7 @@ relay_test(struct protocol *proto, struct ctl_relay_event *cre)
nextrule:
/* Continue to find last matching policy */
- DPRINTF("%s: session %d, res %d", __func__,
+ log_debug("%s: session %d, res %d", __func__,
con->se_id, res);
if (res == RES_BAD || res == RES_INTERNAL)
return (res);
@@ -1959,7 +1958,7 @@ relay_test(struct protocol *proto, struct ctl_relay_event *cre)
action = RES_DROP;
}
- DPRINTF("%s: session %d: action %d", __func__,
+ log_debug("%s: session %d: action %d", __func__,
con->se_id, action);
return (action);
@@ -2045,7 +2044,7 @@ relay_http_parse_startline(struct ctl_relay_event *cre, char *line,
char *key, *value;
const char *errstr;
- DPRINTF("%s: session %d http_session %p", __func__, con->se_id, hs);
+ log_debug("%s: session %d http_session %p", __func__, con->se_id, hs);
key = line;
if ((value = strchr(key, ' ')) == NULL) {
@@ -2064,12 +2063,12 @@ relay_http_parse_startline(struct ctl_relay_event *cre, char *line,
*/
if (hmn == NULL) {
*request_method = HTTP_METHOD_NONE;
- DPRINTF("%s: session %d unbalanced response",
+ log_debug("%s: session %d unbalanced response",
__func__, con->se_id);
} else {
SIMPLEQ_REMOVE_HEAD(&hs->hs_methods, hmn_entry);
*request_method = hmn->hmn_method;
- DPRINTF("%s: session %d dequeuing %s",
+ log_debug("%s: session %d dequeuing %s",
__func__, con->se_id,
relay_httpmethod_byid(*request_method));
free(hmn);
@@ -2098,13 +2097,13 @@ relay_http_parse_startline(struct ctl_relay_event *cre, char *line,
desc->http_status = strtonum(desc->http_rescode, 100, 599,
&errstr);
if (errstr) {
- DPRINTF(
+ log_debug(
"%s: http_status %s: errno %d, %s",
__func__, desc->http_rescode, errno,
errstr);
goto fail;
}
- DPRINTF("http_version %s http_rescode %s http_resmesg %s",
+ log_debug("http_version %s http_rescode %s http_resmesg %s",
desc->http_version, desc->http_rescode,
desc->http_resmesg);
} else if (cre->dir == RELAY_DIR_REQUEST) {
@@ -2116,7 +2115,7 @@ relay_http_parse_startline(struct ctl_relay_event *cre, char *line,
if ((hmn = calloc(1, sizeof *hmn)) == NULL)
goto fail;
hmn->hmn_method = desc->http_method;
- DPRINTF("%s: session %d enqueuing %s", __func__, con->se_id,
+ log_debug("%s: session %d enqueuing %s", __func__, con->se_id,
relay_httpmethod_byid(hmn->hmn_method));
SIMPLEQ_INSERT_TAIL(&hs->hs_methods, hmn, hmn_entry);
/*
diff --git a/relay_udp.c b/relay_udp.c
index 7226861..27ec18b 100644
--- a/relay_udp.c
+++ b/relay_udp.c
@@ -491,13 +491,13 @@ relay_dns_request(struct rsession *con)
(struct sockaddr *)&con->se_out.ss, slen) == -1) {
if (con->se_retry) {
con->se_retry--;
- log_debug("%s: session %d: "
+ log_warn("%s: session %d: "
"forward failed: %s, %s", __func__,
con->se_id, strerror(errno),
con->se_retry ? "next retry" : "last retry");
goto retry;
}
- log_debug("%s: session %d: forward failed: %s", __func__,
+ log_warn("%s: session %d: forward failed: %s", __func__,
con->se_id, strerror(errno));
return (-1);
}
diff --git a/relayd.c b/relayd.c
index 7043735..34ae0d0 100644
--- a/relayd.c
+++ b/relayd.c
@@ -70,6 +70,8 @@ void parent_tls_ticket_rekey(int, short, void *);
struct relayd *relayd_env;
+static int cli_verbose;
+
static struct privsep_proc procs[] = {
{ "pfe", PROC_PFE, parent_dispatch_pfe, pfe },
{ "hce", PROC_HCE, parent_dispatch_hce, hce },
@@ -121,7 +123,7 @@ int
main(int argc, char *argv[])
{
int c;
- int debug = 0, verbose = 0;
+ int debug = 0;
u_int32_t opts = 0;
struct relayd *env;
struct privsep *ps;
@@ -149,7 +151,7 @@ main(int argc, char *argv[])
conffile = optarg;
break;
case 'v':
- verbose++;
+ cli_verbose = 1;
opts |= RELAYD_OPT_VERBOSE;
break;
case 'P':
@@ -197,6 +199,10 @@ main(int argc, char *argv[])
if (debug)
env->sc_conf.opts |= RELAYD_OPT_LOGUPDATE;
+ /* CLI always wins over log level form config. */
+ if (cli_verbose)
+ env->sc_conf.opts |= RELAYD_OPT_VERBOSE;
+
if (geteuid())
errx(1, "need root privileges");
@@ -204,7 +210,7 @@ main(int argc, char *argv[])
errx(1, "unknown user %s", RELAYD_USER);
log_init(debug, LOG_DAEMON);
- log_setverbose(verbose);
+ log_setverbose(env->sc_conf.opts & RELAYD_OPT_VERBOSE ? 2 : 0);
if (env->sc_conf.opts & RELAYD_OPT_NOACTION)
ps->ps_noaction = 1;
@@ -311,6 +317,10 @@ parent_configure(struct relayd *env)
/* HCE, PFE, CA and the relays need to reload their config. */
env->sc_reload = 2 + (2 * env->sc_conf.prefork_relay);
+ /* CLI always wins over log level form config. */
+ if (cli_verbose)
+ env->sc_conf.opts |= RELAYD_OPT_VERBOSE;
+
for (id = 0; id < PROC_MAX; id++) {
if (id == privsep_process)
continue;
@@ -343,14 +353,14 @@ parent_reload(struct relayd *env, u_int reset, const char *filename)
if (reset == CONFIG_RELOAD) {
if (load_config(filename, env) == -1) {
- log_debug("%s: failed to load config file %s",
+ log_warn("%s: failed to load config file %s",
__func__, filename);
}
config_setreset(env, CONFIG_ALL);
if (parent_configure(env) == -1) {
- log_debug("%s: failed to commit config from %s",
+ log_warn("%s: failed to commit config from %s",
__func__, filename);
}
} else
@@ -878,10 +888,8 @@ kv_find_value(struct kvtree *keys, char *key, const char *value,
/* not matched */
match = NULL;
done:
-#ifdef DEBUG
if (match != NULL)
- DPRINTF("%s: matched %s: %s", __func__, key, value);
-#endif
+ log_debug("%s: matched %s: %s", __func__, key, value);
free(val);
return (match);
}
@@ -1516,7 +1524,6 @@ expand_string(char *label, size_t len, const char *srch, const char *repl)
char *p, *q;
if ((tmp = calloc(1, len)) == NULL) {
- log_debug("%s: calloc", __func__);
return (-1);
}
p = label;
@@ -1524,7 +1531,7 @@ expand_string(char *label, size_t len, const char *srch, const char *repl)
*q = '\0';
if ((strlcat(tmp, p, len) >= len) ||
(strlcat(tmp, repl, len) >= len)) {
- log_debug("%s: string too long", __func__);
+ log_warn("%s: string too long", __func__);
free(tmp);
return (-1);
}
@@ -1532,7 +1539,7 @@ expand_string(char *label, size_t len, const char *srch, const char *repl)
p = q;
}
if (strlcat(tmp, p, len) >= len) {
- log_debug("%s: string too long", __func__);
+ log_warn("%s: string too long", __func__);
free(tmp);
return (-1);
}
@@ -1669,7 +1676,7 @@ parse_url(const char *url, char **protoptr, char **hostptr, char **pathptr)
/* strip path after host */
host[strcspn(host, "/")] = '\0';
- DPRINTF("%s: %s proto %s, host %s, path %s", __func__,
+ log_debug("%s: %s proto %s, host %s, path %s", __func__,
url, proto, host, path);
*protoptr = proto;
@@ -1913,7 +1920,8 @@ accept_reserve(int sockfd, struct sockaddr *addr, socklen_t *addrlen,
if ((ret = accept4(sockfd, addr, addrlen, SOCK_NONBLOCK)) > -1) {
(*counter)++;
- DPRINTF("%s: inflight incremented, now %d", __func__, *counter);
+ log_debug("%s: inflight incremented, now %d", __func__,
+ *counter);
}
return (ret);
}
@@ -1926,7 +1934,7 @@ parent_tls_ticket_rekey(int fd, short events, void *arg)
struct timeval tv;
struct relay_ticket_key key;
- log_debug("%s: rekeying tickets", __func__);
+ DPRINTF("%s: rekeying tickets", __func__);
key.tt_keyrev = arc4random();
arc4random_buf(key.tt_key, sizeof(key.tt_key));
diff --git a/relayd.conf.5 b/relayd.conf.5
index 4c48620..5cb3c5f 100644
--- a/relayd.conf.5
+++ b/relayd.conf.5
@@ -165,6 +165,18 @@ or
When using relays, log all TCP connections.
Optionally log only
.Ic connection errors .
+.It Xo
+.Ic log level
+.Pq Ic brief Ns | Ns Ic verbose
+.Xc
+Set the log verbosity.
+.Ic brief
+is the default;
+.Ic verbose
+enables debug logging, equivalent to starting
+.Xr relayd 8
+with
+.Fl v .
.It Ic prefork Ar number
When using relays, run the specified number of processes to handle
relayed connections.
diff --git a/relayd.h b/relayd.h
index 2aa6eab..4cfd547 100644
--- a/relayd.h
+++ b/relayd.h
@@ -1159,9 +1159,7 @@ int cmdline_symset(char *);
const char *host_error(enum host_error);
const char *host_status(enum host_status);
const char *table_check(enum table_check);
-#ifdef DEBUG
const char *relay_state(enum relay_state);
-#endif
const char *print_availability(u_long, u_long);
const char *print_host(struct sockaddr_storage *, char *, size_t);
const char *print_time(struct timeval *, struct timeval *, char *, size_t);
diff --git a/util.c b/util.c
index 527891f..472b99f 100644
--- a/util.c
+++ b/util.c
@@ -179,7 +179,6 @@ table_check(enum table_check check)
return ("invalid");
}
-#ifdef DEBUG
const char *
relay_state(enum relay_state state)
{
@@ -200,7 +199,6 @@ relay_state(enum relay_state state)
/* NOTREACHED */
return ("invalid");
}
-#endif
const char *
print_availability(u_long cnt, u_long up)
relayd: allow setting log level in relayd.conf (fix relayctl log command)