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 | 94 ++++++++++++++++++++++++++++++---------------------------- flow.h | 71 +++++++++++++++++++++++--------------------- tcp.c | 4 +-- udp.c | 6 ++-- 4 files changed, 91 insertions(+), 84 deletions(-) diff --git a/flow.c b/flow.c index 7a5c81c2..c6741251 100644 --- a/flow.c +++ b/flow.c @@ -269,17 +269,25 @@ 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 + * + * NOTE: This function is, technically speaking, recursive. However it recurses + * at most one layer, and as a tail call. clang-tidy doesn't like it, hence the + * suppression below. */ -void flow_log_(const struct flow_common *f, bool newline, int pri, - const char *fmt, ...) +/* NOLINTNEXTLINE(misc-no-recursion) */ +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; @@ -293,45 +301,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); + } + } } /** @@ -347,10 +351,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)); } /** @@ -551,8 +554,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 2623b3db..2b78067a 100644 --- a/flow.h +++ b/flow.h @@ -280,42 +280,47 @@ 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, ...) + __attribute__((format(printf, 6, 7))); + +#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 097ab72e..3538eec2 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 375befa7..c95bb200 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