Download raw body.
relayd: allow setting log level in relayd.conf (fix relayctl log command)
relayd: allow setting log level in relayd.conf (fix relayctl log command)
On Sat, 01 Aug 2026 14:49:37 +0200,
Rafael Sadowski <rafael@sizeofvoid.org> wrote:
>
> "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?
>
Make sense and reads OK kirill@
> 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)
>
--
wbr, Kirill
relayd: allow setting log level in relayd.conf (fix relayctl log command)
relayd: allow setting log level in relayd.conf (fix relayctl log command)