flow.h has a collection of logging helpers that automatically include
information about a specific flow. Which variants are present are a bit
ad-hoc, based on what we happened to want use (e.g. there are no
LOG_WARNING level versions, at present). There's also a rather awkward
and only occasionally used flow_log_details_() helper to print additional
log messages with more details of the flow (basically its addresses).
It's particularly awkward to try to combine that with ratelimiting.
Re-organise this to be based around a flow_log__() internal helper, which
has bool parameters to include strerror() / perror information and/or
the extra details. Add wrapper macros for all combinations of perror,
ratelimiting and DEBUG/WARNING/ERR priorities.
Be a little more consistent about parameter order between the various
functions / macros / wrappers while we're at it.
Signed-off-by: David Gibson
---
flow.c | 89 ++++++++++++++++++++++++++++------------------------------
flow.h | 70 +++++++++++++++++++++++----------------------
tcp.c | 4 +--
udp.c | 6 ++--
4 files changed, 85 insertions(+), 84 deletions(-)
diff --git a/flow.c b/flow.c
index 565ed2b2..6cf3905a 100644
--- a/flow.c
+++ b/flow.c
@@ -270,17 +270,20 @@ int flowside_connect(const struct ctx *c, int s,
return connect(s, &sa.sa, socklen_inany(&sa));
}
-/** flow_log_ - Log flow-related message
+/** flow_log__ - Log flow-related message, internal helper
* @f: flow the message is related to
- * @newline: Append newline at the end of the message, if missing
* @pri: Log priority
+ * @perror: Append strerror(errno) output
+ * @details: Add lines with flow addresses
+ * @state: State to display details for (used during state changes)
* @fmt: Format string
* @...: printf-arguments
*/
-void flow_log_(const struct flow_common *f, bool newline, int pri,
- const char *fmt, ...)
+void flow_log__(const struct flow_common *f, int pri, bool perror, bool details,
+ enum flow_state state, const char *fmt, ...)
{
const char *type_or_state;
+ int errno_ = errno;
char msg[BUFSIZ];
va_list args;
@@ -294,45 +297,41 @@ void flow_log_(const struct flow_common *f, bool newline, int pri,
else
type_or_state = FLOW_TYPE(f);
- logmsg(newline, false, pri,
+ logmsg(!perror, false, pri,
"Flow %u (%s): %s", flow_idx(f), type_or_state, msg);
-}
-/** flow_log_details_() - Log the details of a flow
- * @f: flow to log
- * @pri: Log priority
- * @state: State to log details according to
- *
- * Logs the details of the flow: endpoints, interfaces, type etc.
- */
-void flow_log_details_(const struct flow_common *f, int pri,
- enum flow_state state)
-{
- char estr0[INANY_ADDRSTRLEN], fstr0[INANY_ADDRSTRLEN];
- char estr1[INANY_ADDRSTRLEN], fstr1[INANY_ADDRSTRLEN];
- const struct flowside *ini = &f->side[INISIDE];
- const struct flowside *tgt = &f->side[TGTSIDE];
-
- if (state >= FLOW_STATE_TGT)
- flow_log_(f, true, pri,
- "%s [%s]:%hu -> [%s]:%hu => %s [%s]:%hu -> [%s]:%hu",
- pif_name(f->pif[INISIDE]),
- inany_ntop(&ini->eaddr, estr0, sizeof(estr0)),
- ini->eport,
- inany_ntop(&ini->oaddr, fstr0, sizeof(fstr0)),
- ini->oport,
- pif_name(f->pif[TGTSIDE]),
- inany_ntop(&tgt->oaddr, fstr1, sizeof(fstr1)),
- tgt->oport,
- inany_ntop(&tgt->eaddr, estr1, sizeof(estr1)),
- tgt->eport);
- else if (state >= FLOW_STATE_INI)
- flow_log_(f, true, pri, "%s [%s]:%hu -> [%s]:%hu => ?",
- pif_name(f->pif[INISIDE]),
- inany_ntop(&ini->eaddr, estr0, sizeof(estr0)),
- ini->eport,
- inany_ntop(&ini->oaddr, fstr0, sizeof(fstr0)),
- ini->oport);
+ if (perror)
+ logmsg(true, true, pri, ": %s", strerror_(errno_));
+
+ if (details) {
+ char estr0[INANY_ADDRSTRLEN], fstr0[INANY_ADDRSTRLEN];
+ char estr1[INANY_ADDRSTRLEN], fstr1[INANY_ADDRSTRLEN];
+ const struct flowside *ini = &f->side[INISIDE];
+ const struct flowside *tgt = &f->side[TGTSIDE];
+
+ if (state >= FLOW_STATE_TGT) {
+ flow_log__(f, pri, false, false, state,
+"%s [%s]:%hu -> [%s]:%hu => %s [%s]:%hu -> [%s]:%hu",
+ pif_name(f->pif[INISIDE]),
+ inany_ntop(&ini->eaddr, estr0, sizeof(estr0)),
+ ini->eport,
+ inany_ntop(&ini->oaddr, fstr0, sizeof(fstr0)),
+ ini->oport,
+ pif_name(f->pif[TGTSIDE]),
+ inany_ntop(&tgt->oaddr, fstr1, sizeof(fstr1)),
+ tgt->oport,
+ inany_ntop(&tgt->eaddr, estr1, sizeof(estr1)),
+ tgt->eport);
+ } else if (state >= FLOW_STATE_INI) {
+ flow_log__(f, pri, false, false, state,
+ "%s [%s]:%hu -> [%s]:%hu => ?",
+ pif_name(f->pif[INISIDE]),
+ inany_ntop(&ini->eaddr, estr0, sizeof(estr0)),
+ ini->eport,
+ inany_ntop(&ini->oaddr, fstr0, sizeof(fstr0)),
+ ini->oport);
+ }
+ }
}
/**
@@ -348,10 +347,9 @@ static void flow_set_state(struct flow_common *f, enum flow_state state)
assert(oldstate < FLOW_NUM_STATES);
f->state = state;
- flow_log_(f, true, LOG_DEBUG, "%s -> %s", flow_state_str[oldstate],
+ flow_log__(f, LOG_DEBUG, false, true, MAX(state, oldstate),
+ "%s -> %s", flow_state_str[oldstate],
FLOW_STATE(f));
-
- flow_log_details_(f, LOG_DEBUG, MAX(state, oldstate));
}
/**
@@ -552,8 +550,7 @@ norule:
/* This shouldn't happen, because if there's no rule for it we should
* have no listening socket that would let us get here
*/
- flow_dbg(flow, "Missing forward rule");
- flow_log_details_(f, LOG_DEBUG, f->state);
+ flow_log(flow, LOG_DEBUG, false, true, "Missing forward rule");
nofwd:
flow_err(flow, "No rules to forward %s %s [%s]:%hu -> [%s]:%hu",
diff --git a/flow.h b/flow.h
index 6c6a9260..d168a35a 100644
--- a/flow.h
+++ b/flow.h
@@ -280,42 +280,46 @@ int flow_migrate_source(struct ctx *c, const struct migrate_stage *stage,
int flow_migrate_target(struct ctx *c, const struct migrate_stage *stage,
int fd);
-void flow_log_(const struct flow_common *f, bool newline, int pri,
- const char *fmt, ...)
- __attribute__((format(printf, 4, 5)));
-
-#define flow_log(f_, pri, ...) flow_log_(&(f_)->f, true, (pri), __VA_ARGS__)
-#define flow_dbg(f, ...) flow_log((f), LOG_DEBUG, __VA_ARGS__)
-#define flow_err(f, ...) flow_log((f), LOG_ERR, __VA_ARGS__)
-
-#define flow_trace(f, ...) \
+void flow_log__(const struct flow_common *f, int pri, bool perror, bool details,
+ enum flow_state state, const char *fmt, ...);
+
+#define flow_log_(f_, pri_, perror_, details_, ...) \
+ flow_log__((f_), (pri_), (perror_), (details_), (f_)->state, \
+ __VA_ARGS__)
+
+#define flow_log(flow_, pri_, perror_, details_, ...) \
+ flow_log_(&(flow_)->f, (pri_), (perror_), (details_), __VA_ARGS__)
+
+#define flow_dbg(flow_, ...) \
+ flow_log((flow_), LOG_DEBUG, false, false, __VA_ARGS__)
+#define flow_warn(flow_, ...) \
+ flow_log((flow_), LOG_WARNING, false, false, __VA_ARGS__)
+#define flow_err(flow_, ...) \
+ flow_log((flow_), LOG_ERR, false, false, __VA_ARGS__)
+#define flow_trace(flow_, ...) \
do { \
if (log_trace) \
- flow_dbg((f), __VA_ARGS__); \
- } while (0)
-
-#define flow_log_perror_(f, pri, ...) \
- do { \
- int errno_ = errno; \
- flow_log_((f), false, (pri), __VA_ARGS__); \
- logmsg(true, true, (pri), ": %s", strerror_(errno_)); \
+ flow_dbg((flow_), __VA_ARGS__); \
} while (0)
-#define flow_dbg_perror(f_, ...) flow_log_perror_(&(f_)->f, LOG_DEBUG, __VA_ARGS__)
-#define flow_perror(f_, ...) flow_log_perror_(&(f_)->f, LOG_ERR, __VA_ARGS__)
-
-void flow_log_details_(const struct flow_common *f, int pri,
- enum flow_state state);
-#define flow_log_details(f_, pri) \
- flow_log_details_(&((f_)->f), (pri), (f_)->f.state)
-#define flow_dbg_details(f_) flow_log_details((f_), LOG_DEBUG)
-#define flow_err_details(f_) flow_log_details((f_), LOG_ERR)
-
-#define flow_dbg_ratelimit(f, now, ...) \
- logmsg_ratelimit(flow_dbg, debug, now, f, __VA_ARGS__)
-#define flow_err_ratelimit(f, now, ...) \
- logmsg_ratelimit(flow_err, err, now, f, __VA_ARGS__)
-#define flow_perror_ratelimit(f, now, ...) \
- logmsg_ratelimit(flow_perror, err, now, f, __VA_ARGS__)
+#define flow_dbg_perror(flow_, ...) \
+ flow_log((flow_), LOG_DEBUG, true, false, __VA_ARGS__)
+#define flow_warn_perror(flow_, ...) \
+ flow_log((flow_), LOG_WARNING, true, false, __VA_ARGS__)
+#define flow_perror(flow_, ...) \
+ flow_log((flow_), LOG_ERR, true, false, __VA_ARGS__)
+
+#define flow_dbg_ratelimit(flow_, now_, ...) \
+ logmsg_ratelimit(flow_dbg, debug, (now_), (flow_), __VA_ARGS__)
+#define flow_dbg_perror_ratelimit(flow_, now_, ...) \
+ logmsg_ratelimit(flow_dbg_perror, debug, (now_), (flow_), __VA_ARGS__)
+#define flow_warn_ratelimit(flow_, now_, ...) \
+ logmsg_ratelimit(flow_warn, warn, (now_), (flow_), __VA_ARGS__)
+#define flow_warn_perror_ratelimit(flow_, now_, ...) \
+ logmsg_ratelimit(flow_warn_perror, warn, (now_), (flow_), __VA_ARGS__)
+#define flow_err_ratelimit(flow_, now_, ...) \
+ logmsg_ratelimit(flow_err, err, (now_), (flow_), __VA_ARGS__)
+#define flow_perror_ratelimit(flow_, now_, ...) \
+ logmsg_ratelimit(flow_perror, err, (now_), (flow_), __VA_ARGS__)
#endif /* FLOW_H */
diff --git a/tcp.c b/tcp.c
index c4000754..6fba865f 100644
--- a/tcp.c
+++ b/tcp.c
@@ -1404,8 +1404,8 @@ void tcp_linger0_(const struct flow_common *f, int s)
*/
if (setsockopt(s, SOL_SOCKET, SO_LINGER,
&linger0, sizeof(linger0)) < 0) {
- flow_log_perror_(f, LOG_DEBUG,
- "SO_LINGER failed, may not send RST to peer");
+ flow_log_(f, LOG_DEBUG, true, false,
+ "SO_LINGER failed, may not send RST to peer");
}
}
diff --git a/udp.c b/udp.c
index c28d6ee2..f29ca3da 100644
--- a/udp.c
+++ b/udp.c
@@ -943,7 +943,8 @@ void udp_sock_handler(const struct ctx *c, union epoll_ref ref,
if (events & EPOLLERR) {
if (udp_sock_errs(c, ref.fd, ref.flowside, PIF_NONE, 0) < 0) {
- flow_err(uflow, "Unrecoverable error on flow socket");
+ flow_log(uflow, LOG_ERR, false, true,
+ "Unrecoverable error on flow socket");
goto fail;
}
}
@@ -974,7 +975,7 @@ void udp_sock_handler(const struct ctx *c, union epoll_ref ref,
udp_buf_sock_to_tap(c, s, n, tosidx);
}
} else {
- flow_err(uflow,
+ flow_log(uflow, LOG_ERR, false, true,
"No support for forwarding UDP from %s to %s",
pif_name(pif_at_sidx(ref.flowside)),
pif_name(topif));
@@ -984,7 +985,6 @@ void udp_sock_handler(const struct ctx *c, union epoll_ref ref,
return;
fail:
- flow_err_details(uflow);
udp_flow_close(c, uflow);
}
--
2.54.0