1
0
Fork 0
mirror of https://passt.top/passt synced 2025-06-06 07:56:38 +02:00

flow: Add flow_perror() helper

Our general logging helpers include a number of _perror() variants which,
like perror(3) include the description of the current errno.  We didn't
have those for our flow specific logging helpers, though.  Fill this gap
with flow_perror() and flow_dbg_perror(), and use them where it's useful.

Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
(cherry picked from commit adb46c11d0)
This commit is contained in:
David Gibson 2025-02-18 19:59:24 +11:00
parent 8a938c5a2c
commit 4c6b69f359
6 changed files with 49 additions and 47 deletions

12
flow.c
View file

@ -289,11 +289,13 @@ int flowside_connect(const struct ctx *c, int s,
/** flow_log_ - Log flow-related message /** flow_log_ - Log flow-related message
* @f: flow the message is related to * @f: flow the message is related to
* @newline: Append newline at the end of the message, if missing
* @pri: Log priority * @pri: Log priority
* @fmt: Format string * @fmt: Format string
* @...: printf-arguments * @...: printf-arguments
*/ */
void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...) void flow_log_(const struct flow_common *f, bool newline, int pri,
const char *fmt, ...)
{ {
const char *type_or_state; const char *type_or_state;
char msg[BUFSIZ]; char msg[BUFSIZ];
@ -309,7 +311,7 @@ void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...)
else else
type_or_state = FLOW_TYPE(f); type_or_state = FLOW_TYPE(f);
logmsg(true, false, pri, logmsg(newline, false, pri,
"Flow %u (%s): %s", flow_idx(f), type_or_state, msg); "Flow %u (%s): %s", flow_idx(f), type_or_state, msg);
} }
@ -329,7 +331,7 @@ void flow_log_details_(const struct flow_common *f, int pri,
const struct flowside *tgt = &f->side[TGTSIDE]; const struct flowside *tgt = &f->side[TGTSIDE];
if (state >= FLOW_STATE_TGT) if (state >= FLOW_STATE_TGT)
flow_log_(f, pri, flow_log_(f, true, pri,
"%s [%s]:%hu -> [%s]:%hu => %s [%s]:%hu -> [%s]:%hu", "%s [%s]:%hu -> [%s]:%hu => %s [%s]:%hu -> [%s]:%hu",
pif_name(f->pif[INISIDE]), pif_name(f->pif[INISIDE]),
inany_ntop(&ini->eaddr, estr0, sizeof(estr0)), inany_ntop(&ini->eaddr, estr0, sizeof(estr0)),
@ -342,7 +344,7 @@ void flow_log_details_(const struct flow_common *f, int pri,
inany_ntop(&tgt->eaddr, estr1, sizeof(estr1)), inany_ntop(&tgt->eaddr, estr1, sizeof(estr1)),
tgt->eport); tgt->eport);
else if (state >= FLOW_STATE_INI) else if (state >= FLOW_STATE_INI)
flow_log_(f, pri, "%s [%s]:%hu -> [%s]:%hu => ?", flow_log_(f, true, pri, "%s [%s]:%hu -> [%s]:%hu => ?",
pif_name(f->pif[INISIDE]), pif_name(f->pif[INISIDE]),
inany_ntop(&ini->eaddr, estr0, sizeof(estr0)), inany_ntop(&ini->eaddr, estr0, sizeof(estr0)),
ini->eport, ini->eport,
@ -363,7 +365,7 @@ static void flow_set_state(struct flow_common *f, enum flow_state state)
ASSERT(oldstate < FLOW_NUM_STATES); ASSERT(oldstate < FLOW_NUM_STATES);
f->state = state; f->state = state;
flow_log_(f, LOG_DEBUG, "%s -> %s", flow_state_str[oldstate], flow_log_(f, true, LOG_DEBUG, "%s -> %s", flow_state_str[oldstate],
FLOW_STATE(f)); FLOW_STATE(f));
flow_log_details_(f, LOG_DEBUG, MAX(state, oldstate)); flow_log_details_(f, LOG_DEBUG, MAX(state, oldstate));

18
flow.h
View file

@ -258,11 +258,11 @@ 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 flow_migrate_target(struct ctx *c, const struct migrate_stage *stage,
int fd); int fd);
void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...) void flow_log_(const struct flow_common *f, bool newline, int pri,
__attribute__((format(printf, 3, 4))); const char *fmt, ...)
__attribute__((format(printf, 4, 5)));
#define flow_log(f_, pri, ...) flow_log_(&(f_)->f, (pri), __VA_ARGS__)
#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_dbg(f, ...) flow_log((f), LOG_DEBUG, __VA_ARGS__)
#define flow_err(f, ...) flow_log((f), LOG_ERR, __VA_ARGS__) #define flow_err(f, ...) flow_log((f), LOG_ERR, __VA_ARGS__)
@ -272,6 +272,16 @@ void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...)
flow_dbg((f), __VA_ARGS__); \ flow_dbg((f), __VA_ARGS__); \
} while (0) } 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_)); \
} 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, void flow_log_details_(const struct flow_common *f, int pri,
enum flow_state state); enum flow_state state);
#define flow_log_details(f_, pri) \ #define flow_log_details(f_, pri) \

5
icmp.c
View file

@ -85,7 +85,7 @@ void icmp_sock_handler(const struct ctx *c, union epoll_ref ref)
n = recvfrom(ref.fd, buf, sizeof(buf), 0, &sr.sa, &sl); n = recvfrom(ref.fd, buf, sizeof(buf), 0, &sr.sa, &sl);
if (n < 0) { if (n < 0) {
flow_err(pingf, "recvfrom() error: %s", strerror_(errno)); flow_perror(pingf, "recvfrom() error");
return; return;
} }
@ -300,8 +300,7 @@ int icmp_tap_handler(const struct ctx *c, uint8_t pif, sa_family_t af,
pif_sockaddr(c, &sa, &sl, PIF_HOST, &tgt->eaddr, 0); pif_sockaddr(c, &sa, &sl, PIF_HOST, &tgt->eaddr, 0);
if (sendto(pingf->sock, pkt, l4len, MSG_NOSIGNAL, &sa.sa, sl) < 0) { if (sendto(pingf->sock, pkt, l4len, MSG_NOSIGNAL, &sa.sa, sl) < 0) {
flow_dbg(pingf, "failed to relay request to socket: %s", flow_dbg_perror(pingf, "failed to relay request to socket");
strerror_(errno));
} else { } else {
flow_dbg(pingf, flow_dbg(pingf,
"echo request to socket, ID: %"PRIu16", seq: %"PRIu16, "echo request to socket, ID: %"PRIu16", seq: %"PRIu16,

33
tcp.c
View file

@ -551,8 +551,7 @@ static void tcp_timer_ctl(const struct ctx *c, struct tcp_tap_conn *conn)
fd = timerfd_create(CLOCK_MONOTONIC, 0); fd = timerfd_create(CLOCK_MONOTONIC, 0);
if (fd == -1 || fd > FD_REF_MAX) { if (fd == -1 || fd > FD_REF_MAX) {
flow_dbg(conn, "failed to get timer: %s", flow_dbg_perror(conn, "failed to get timer");
strerror_(errno));
if (fd > -1) if (fd > -1)
close(fd); close(fd);
conn->timer = -1; conn->timer = -1;
@ -561,8 +560,7 @@ static void tcp_timer_ctl(const struct ctx *c, struct tcp_tap_conn *conn)
conn->timer = fd; conn->timer = fd;
if (epoll_ctl(c->epollfd, EPOLL_CTL_ADD, conn->timer, &ev)) { if (epoll_ctl(c->epollfd, EPOLL_CTL_ADD, conn->timer, &ev)) {
flow_dbg(conn, "failed to add timer: %s", flow_dbg_perror(conn, "failed to add timer");
strerror_(errno));
close(conn->timer); close(conn->timer);
conn->timer = -1; conn->timer = -1;
return; return;
@ -587,7 +585,7 @@ static void tcp_timer_ctl(const struct ctx *c, struct tcp_tap_conn *conn)
(unsigned long long)it.it_value.tv_nsec / 1000 / 1000); (unsigned long long)it.it_value.tv_nsec / 1000 / 1000);
if (timerfd_settime(conn->timer, 0, &it, NULL)) if (timerfd_settime(conn->timer, 0, &it, NULL))
flow_err(conn, "failed to set timer: %s", strerror_(errno)); flow_perror(conn, "failed to set timer");
} }
/** /**
@ -1384,10 +1382,10 @@ static void tcp_bind_outbound(const struct ctx *c,
if (bind(s, &bind_sa.sa, sl)) { if (bind(s, &bind_sa.sa, sl)) {
char sstr[INANY_ADDRSTRLEN]; char sstr[INANY_ADDRSTRLEN];
flow_dbg(conn, flow_dbg_perror(conn,
"Can't bind TCP outbound socket to %s:%hu: %s", "Can't bind TCP outbound socket to %s:%hu",
inany_ntop(&tgt->oaddr, sstr, sizeof(sstr)), inany_ntop(&tgt->oaddr, sstr, sizeof(sstr)),
tgt->oport, strerror_(errno)); tgt->oport);
} }
} }
@ -1396,9 +1394,9 @@ static void tcp_bind_outbound(const struct ctx *c,
if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE, if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE,
c->ip4.ifname_out, c->ip4.ifname_out,
strlen(c->ip4.ifname_out))) { strlen(c->ip4.ifname_out))) {
flow_dbg(conn, "Can't bind IPv4 TCP socket to" flow_dbg_perror(conn,
" interface %s: %s", c->ip4.ifname_out, "Can't bind IPv4 TCP socket to interface %s",
strerror_(errno)); c->ip4.ifname_out);
} }
} }
} else if (bind_sa.sa_family == AF_INET6) { } else if (bind_sa.sa_family == AF_INET6) {
@ -1406,9 +1404,9 @@ static void tcp_bind_outbound(const struct ctx *c,
if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE, if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE,
c->ip6.ifname_out, c->ip6.ifname_out,
strlen(c->ip6.ifname_out))) { strlen(c->ip6.ifname_out))) {
flow_dbg(conn, "Can't bind IPv6 TCP socket to" flow_dbg_perror(conn,
" interface %s: %s", c->ip6.ifname_out, "Can't bind IPv6 TCP socket to interface %s",
strerror_(errno)); c->ip6.ifname_out);
} }
} }
} }
@ -2263,7 +2261,7 @@ void tcp_timer_handler(const struct ctx *c, union epoll_ref ref)
* and we just set the timer to a new point in the future: discard it. * and we just set the timer to a new point in the future: discard it.
*/ */
if (timerfd_gettime(conn->timer, &check_armed)) if (timerfd_gettime(conn->timer, &check_armed))
flow_err(conn, "failed to read timer: %s", strerror_(errno)); flow_perror(conn, "failed to read timer");
if (check_armed.it_value.tv_sec || check_armed.it_value.tv_nsec) if (check_armed.it_value.tv_sec || check_armed.it_value.tv_nsec)
return; return;
@ -2305,8 +2303,7 @@ void tcp_timer_handler(const struct ctx *c, union epoll_ref ref)
* ~ACK_TO_TAP_DUE or ~ACK_FROM_TAP_DUE. * ~ACK_TO_TAP_DUE or ~ACK_FROM_TAP_DUE.
*/ */
if (timerfd_settime(conn->timer, 0, &new, &old)) if (timerfd_settime(conn->timer, 0, &new, &old))
flow_err(conn, "failed to set timer: %s", flow_perror(conn, "failed to set timer");
strerror_(errno));
if (old.it_value.tv_sec == ACT_TIMEOUT) { if (old.it_value.tv_sec == ACT_TIMEOUT) {
flow_dbg(conn, "activity timeout"); flow_dbg(conn, "activity timeout");

View file

@ -164,7 +164,7 @@ static int tcp_splice_epoll_ctl(const struct ctx *c,
if (epoll_ctl(c->epollfd, m, conn->s[0], &ev[0]) || if (epoll_ctl(c->epollfd, m, conn->s[0], &ev[0]) ||
epoll_ctl(c->epollfd, m, conn->s[1], &ev[1])) { epoll_ctl(c->epollfd, m, conn->s[1], &ev[1])) {
int ret = -errno; int ret = -errno;
flow_err(conn, "ERROR on epoll_ctl(): %s", strerror_(errno)); flow_perror(conn, "ERROR on epoll_ctl()");
return ret; return ret;
} }
@ -317,8 +317,8 @@ static int tcp_splice_connect_finish(const struct ctx *c,
if (conn->pipe[sidei][0] < 0) { if (conn->pipe[sidei][0] < 0) {
if (pipe2(conn->pipe[sidei], O_NONBLOCK | O_CLOEXEC)) { if (pipe2(conn->pipe[sidei], O_NONBLOCK | O_CLOEXEC)) {
flow_err(conn, "cannot create %d->%d pipe: %s", flow_perror(conn, "cannot create %d->%d pipe",
sidei, !sidei, strerror_(errno)); sidei, !sidei);
conn_flag(c, conn, CLOSING); conn_flag(c, conn, CLOSING);
return -EIO; return -EIO;
} }
@ -482,8 +482,7 @@ void tcp_splice_sock_handler(struct ctx *c, union epoll_ref ref,
rc = getsockopt(ref.fd, SOL_SOCKET, SO_ERROR, &err, &sl); rc = getsockopt(ref.fd, SOL_SOCKET, SO_ERROR, &err, &sl);
if (rc) if (rc)
flow_err(conn, "Error retrieving SO_ERROR: %s", flow_perror(conn, "Error retrieving SO_ERROR");
strerror_(errno));
else else
flow_trace(conn, "Error event on socket: %s", flow_trace(conn, "Error event on socket: %s",
strerror_(err)); strerror_(err));

View file

@ -93,9 +93,8 @@ static flow_sidx_t udp_flow_new(const struct ctx *c, union flow *flow,
*/ */
uflow->s[INISIDE] = fcntl(s_ini, F_DUPFD_CLOEXEC, 0); uflow->s[INISIDE] = fcntl(s_ini, F_DUPFD_CLOEXEC, 0);
if (uflow->s[INISIDE] < 0) { if (uflow->s[INISIDE] < 0) {
flow_err(uflow, flow_perror(uflow,
"Couldn't duplicate listening socket: %s", "Couldn't duplicate listening socket");
strerror_(errno));
goto cancel; goto cancel;
} }
} }
@ -113,16 +112,13 @@ static flow_sidx_t udp_flow_new(const struct ctx *c, union flow *flow,
uflow->s[TGTSIDE] = flowside_sock_l4(c, EPOLL_TYPE_UDP_REPLY, uflow->s[TGTSIDE] = flowside_sock_l4(c, EPOLL_TYPE_UDP_REPLY,
tgtpif, tgt, fref.data); tgtpif, tgt, fref.data);
if (uflow->s[TGTSIDE] < 0) { if (uflow->s[TGTSIDE] < 0) {
flow_dbg(uflow, flow_dbg_perror(uflow,
"Couldn't open socket for spliced flow: %s", "Couldn't open socket for spliced flow");
strerror_(errno));
goto cancel; goto cancel;
} }
if (flowside_connect(c, uflow->s[TGTSIDE], tgtpif, tgt) < 0) { if (flowside_connect(c, uflow->s[TGTSIDE], tgtpif, tgt) < 0) {
flow_dbg(uflow, flow_dbg_perror(uflow, "Couldn't connect flow socket");
"Couldn't connect flow socket: %s",
strerror_(errno));
goto cancel; goto cancel;
} }
@ -142,9 +138,8 @@ static flow_sidx_t udp_flow_new(const struct ctx *c, union flow *flow,
flow_trace(uflow, flow_trace(uflow,
"Discarded %d spurious reply datagrams", rc); "Discarded %d spurious reply datagrams", rc);
} else if (errno != EAGAIN) { } else if (errno != EAGAIN) {
flow_err(uflow, flow_perror(uflow,
"Unexpected error discarding datagrams: %s", "Unexpected error discarding datagrams");
strerror_(errno));
} }
} }