Hi Jiri,
I'm not sure if I should split the patch or just post one directly. Please tell me if you feel the commit message are repeated and want only one patch.
Recently some users reported that they start to see debug messages in their syslogs even with daemon_verbosity_level = LOG_INFO and without -g option.
Actually this issue is there at the begining, the user would see the debug messages if they run teamd with -d option. The reason that most users did not notice this is because they are using libteam via NetworkManager, and NetworkManager run libteam in frontend.
But after commit e47d5db53873 ("teamd: add an option to force log output to stdout, stderr or syslog"), NetworkManager will set TEAM_LOG_OUTPUT=syslog in the environment. At the same time libdaemon does not filter log levels if we use syslog(see function daemon_logv in libdaemon). Then all the users would see the debug messages suddenly and feels annoying.
And here is the quote for daemon_set_verbosity() from libdaemon/dlog.h """ Allows to decide which messages to output on standard output/error streams. All messages are logged to syslog and this setting does not influence that. """
Since we should not limit how our user(NM) used libteam. And libdaemon is intend to not filter logs if use syslog. We'd better filter the debug message ourselves, like via -g option. So I would prefer to move all teamd_log_dbg to teamd_log_dbgx. After that, the user could decide whether to enable debug or not by themselves with -g option.
Hangbin Liu (6): teamd/teamd.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_runner_activebackup.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_balancer.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_runner_lacp.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_link_watch.c: move teamd_log_dbg to teamd_log_dbgx teamd: move teamd_log_dbg to teamd_log_dbgx
teamd/teamd.c | 40 ++++++++++++++-------------- teamd/teamd_balancer.c | 21 ++++++++------- teamd/teamd_dbus.c | 6 ++--- teamd/teamd_hash_func.c | 2 +- teamd/teamd_link_watch.c | 14 +++++----- teamd/teamd_lw_arp_ping.c | 12 ++++----- teamd/teamd_lw_ethtool.c | 4 +-- teamd/teamd_lw_nsna_ping.c | 2 +- teamd/teamd_lw_psr.c | 12 ++++----- teamd/teamd_lw_tipc.c | 8 +++--- teamd/teamd_per_port.c | 6 ++--- teamd/teamd_runner_activebackup.c | 18 ++++++------- teamd/teamd_runner_lacp.c | 44 +++++++++++++++---------------- teamd/teamd_usock.c | 12 ++++----- teamd/teamd_zmq.c | 10 +++---- 15 files changed, 107 insertions(+), 104 deletions(-)
As libdaemon do not filter log messages when we use syslog as output, all debug messages will be printed to the syslog even if we set daemon_verbosity_level to LOG_INFO. This would make user full confused and annoying. Since we have a -g option to enable debug message specially, let's move all teamd_log_dbg to teamd_log_dbgx so user could choose to print debug message or not.
This patch will move all teamd_log_dbg to teamd_log_dbgx for teamd.c
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd.c | 40 ++++++++++++++++++++-------------------- 1 file changed, 20 insertions(+), 20 deletions(-)
diff --git a/teamd/teamd.c b/teamd/teamd.c index 6c47312..34d4afa 100644 --- a/teamd/teamd.c +++ b/teamd/teamd.c @@ -332,8 +332,8 @@ static int teamd_run_loop_do_callbacks(struct list_item *lcb_list, fd_set *fds, if (err) { teamd_log_warn("Loop callback failed with: %s", strerror(-err)); - teamd_log_dbg("Failed loop callback: %s, %p", - lcb->name, lcb->priv); + teamd_log_dbgx(ctx, 1, "Failed loop callback: %s, %p", + lcb->name, lcb->priv); } } } @@ -519,7 +519,7 @@ static int __teamd_loop_callback_fd_add(struct teamd_context *ctx, list_add_tail(&ctx->run_loop.callback_list, &lcb->list); else list_add(&ctx->run_loop.callback_list, &lcb->list); - teamd_log_dbg("Added loop callback: %s, %p", lcb->name, lcb->priv); + teamd_log_dbgx(ctx, 1, "Added loop callback: %s, %p", lcb->name, lcb->priv); return 0;
lcb_free: @@ -636,7 +636,7 @@ void teamd_loop_callback_del(struct teamd_context *ctx, const char *cb_name, list_del(&lcb->list); if (lcb->is_period) close(lcb->fd); - teamd_log_dbg("Removed loop callback: %s, %p", + teamd_log_dbgx(ctx, 1, "Removed loop callback: %s, %p", lcb->name, lcb->priv); free(lcb->name); free(lcb); @@ -645,7 +645,7 @@ void teamd_loop_callback_del(struct teamd_context *ctx, const char *cb_name, if (found) teamd_run_loop_restart(ctx); else - teamd_log_dbg("Callback named "%s" not found.", cb_name); + teamd_log_dbgx(ctx, 1, "Callback named "%s" not found.", cb_name); }
int teamd_loop_callback_enable(struct teamd_context *ctx, const char *cb_name, @@ -820,7 +820,7 @@ static int teamd_set_hwaddr(struct teamd_context *ctx) if (err) return 0; /* addr is not defined in config, no change needed */
- teamd_log_dbg("Hwaddr string: "%s".", hwaddr_str); + teamd_log_dbgx(ctx, 1, "Hwaddr string: "%s".", hwaddr_str); err = parse_hwaddr(hwaddr_str, &hwaddr, &hwaddr_len); if (err) { teamd_log_err("Failed to parse hardware address."); @@ -953,16 +953,16 @@ static int teamd_runner_init(struct teamd_context *ctx)
err = teamd_config_string_get(ctx, &runner_name, "$.runner.name"); if (err) { - teamd_log_dbg("Failed to get team runner name from config."); + teamd_log_dbgx(ctx, 1, "Failed to get team runner name from config."); runner_name = TEAMD_DEFAULT_RUNNER_NAME; err = teamd_config_string_set(ctx, runner_name, "$.runner.name"); if (err) { teamd_log_err("Failed to set default team runner name in config."); return err; } - teamd_log_dbg("Using default team runner "%s".", runner_name); + teamd_log_dbgx(ctx, 1, "Using default team runner "%s".", runner_name); } else { - teamd_log_dbg("Using team runner "%s".", runner_name); + teamd_log_dbgx(ctx, 1, "Using team runner "%s".", runner_name); } ctx->runner = teamd_find_runner(runner_name); if (!ctx->runner) { @@ -1108,12 +1108,12 @@ static void debug_log_port_list(struct teamd_context *ctx) char buf[120]; bool trunc;
- teamd_log_dbg("<port_list>"); + teamd_log_dbgx(ctx, 1, "<port_list>"); team_for_each_port(port, ctx->th) { trunc = team_port_str(port, buf, sizeof(buf)); - teamd_log_dbg("%s %s", buf, trunc ? "<trunc>" : ""); + teamd_log_dbgx(ctx, 1, "%s %s", buf, trunc ? "<trunc>" : ""); } - teamd_log_dbg("</port_list>"); + teamd_log_dbgx(ctx, 1, "</port_list>"); }
static void debug_log_option_list(struct teamd_context *ctx) @@ -1139,12 +1139,12 @@ static void debug_log_ifinfo_list(struct teamd_context *ctx) char buf[120]; bool trunc;
- teamd_log_dbg("<ifinfo_list>"); + teamd_log_dbgx(ctx, 1, "<ifinfo_list>"); team_for_each_ifinfo(ifinfo, ctx->th) { trunc = team_ifinfo_str(ifinfo, buf, sizeof(buf)); - teamd_log_dbg("%s %s", buf, trunc ? "<trunc>" : ""); + teamd_log_dbgx(ctx, 1, "%s %s", buf, trunc ? "<trunc>" : ""); } - teamd_log_dbg("</ifinfo_list>"); + teamd_log_dbgx(ctx, 1, "</ifinfo_list>"); }
static int debug_change_handler_func(struct team_handle *th, void *priv, @@ -1573,7 +1573,7 @@ static int teamd_generate_devname(struct teamd_context *ctx) if (err) return err; } while (ifindex); - teamd_log_dbg("Generated team device name "%s".", buf); + teamd_log_dbgx(ctx, 1, "Generated team device name "%s".", buf);
ctx->team_devname = strdup(buf); if (!ctx->team_devname) @@ -1597,7 +1597,7 @@ static int teamd_get_devname(struct teamd_context *ctx, bool generate_enabled) } goto skip_set; } else { - teamd_log_dbg("Failed to get team device name from config."); + teamd_log_dbgx(ctx, 1, "Failed to get team device name from config."); if (generate_enabled) { err = teamd_generate_devname(ctx); if (err) { @@ -1617,7 +1617,7 @@ static int teamd_get_devname(struct teamd_context *ctx, bool generate_enabled) }
skip_set: - teamd_log_dbg("Using team device "%s".", ctx->team_devname); + teamd_log_dbgx(ctx, 1, "Using team device "%s".", ctx->team_devname);
err = asprintf(&ctx->ident, "%s_%s", ctx->argv0, ctx->team_devname); if (err == -1) { @@ -1835,9 +1835,9 @@ int main(int argc, char **argv) daemon_log_ident = ctx->ident; daemon_pid_file_proc = teamd_pid_file_proc;
- teamd_log_dbg("Using PID file "%s"", daemon_pid_file_proc()); + teamd_log_dbgx(ctx, 1, "Using PID file "%s"", daemon_pid_file_proc()); if (ctx->config_file) - teamd_log_dbg("Using config file "%s"", ctx->config_file); + teamd_log_dbgx(ctx, 1, "Using config file "%s"", ctx->config_file);
switch (ctx->cmd) { case DAEMON_CMD_HELP:
As libdaemon do not filter log messages when we use syslog as output, all debug messages will be printed to the syslog even if we set daemon_verbosity_level to LOG_INFO. This would make user full confused and annoying. Since we have a -g option to enable debug message specially, let's move all teamd_log_dbg to teamd_log_dbgx so user could choose to print debug message or not.
This patch will move all teamd_log_dbg to teamd_log_dbgx for teamd_runner_activebackup.c
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd_runner_activebackup.c | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-)
diff --git a/teamd/teamd_runner_activebackup.c b/teamd/teamd_runner_activebackup.c index f92d341..9414497 100644 --- a/teamd/teamd_runner_activebackup.c +++ b/teamd/teamd_runner_activebackup.c @@ -255,7 +255,7 @@ static int ab_clear_active_port(struct teamd_context *ctx, struct ab *ab, ab->active_ifindex = 0; if (!tdport || !teamd_port_present(ctx, tdport)) return 0; - teamd_log_dbg("Clearing active port "%s".", tdport->ifname); + teamd_log_dbgx(ctx, 1, "Clearing active port "%s".", tdport->ifname);
err = team_set_port_enabled(ctx->th, tdport->ifindex, false); if (err) { @@ -368,9 +368,9 @@ static int ab_link_watch_handler(struct teamd_context *ctx, struct ab *ab)
active_tdport = teamd_get_port(ctx, ab->active_ifindex); if (active_tdport) { - teamd_log_dbg("Current active port: "%s" (ifindex "%d", prio "%d").", - active_tdport->ifname, active_tdport->ifindex, - teamd_port_prio(ctx, active_tdport)); + teamd_log_dbgx(ctx, 1, "Current active port: "%s" (ifindex "%d", prio "%d").", + active_tdport->ifname, active_tdport->ifindex, + teamd_port_prio(ctx, active_tdport));
err = team_get_active_port(ctx->th, &active_ifindex); if (err) { @@ -404,8 +404,8 @@ static int ab_link_watch_handler(struct teamd_context *ctx, struct ab *ab) if (!best.tdport || best.tdport == active_tdport) return 0;
- teamd_log_dbg("Found best port: "%s" (ifindex "%d", prio "%d").", - best.tdport->ifname, best.tdport->ifindex, best.prio); + teamd_log_dbgx(ctx, 1, "Found best port: "%s" (ifindex "%d", prio "%d").", + best.tdport->ifname, best.tdport->ifindex, best.prio);
if (!active_tdport || !ab_is_port_sticky(ab, active_tdport)) { err = ab_change_active_port(ctx, ab, active_tdport, @@ -459,8 +459,8 @@ static int ab_port_load_config(struct teamd_context *ctx, "$.ports.%s.sticky", port_name); if (err) ab_port->cfg.sticky = AB_DFLT_PORT_STICKY; - teamd_log_dbg("%s: Using sticky "%d".", port_name, - ab_port->cfg.sticky); + teamd_log_dbgx(ctx, 1, "%s: Using sticky "%d".", port_name, + ab_port->cfg.sticky); return 0; }
@@ -558,7 +558,7 @@ static int ab_load_config(struct teamd_context *ctx, struct ab *ab) hwaddr_policy_name); return err; } - teamd_log_dbg("Using hwaddr_policy "%s".", ab->hwaddr_policy->name); + teamd_log_dbgx(ctx, 1, "Using hwaddr_policy "%s".", ab->hwaddr_policy->name); return 0; }
As libdaemon do not filter log messages when we use syslog as output, all debug messages will be printed to the syslog even if we set daemon_verbosity_level to LOG_INFO. This would make user full confused and annoying. Since we have a -g option to enable debug message specially, let's move all teamd_log_dbg to teamd_log_dbgx so user could choose to print debug message or not.
This patch will move all teamd_log_dbg to teamd_log_dbgx for teamd_balancer.c. I added a new parameter for function tb_hash_to_port_remap to get the ctx.
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd_balancer.c | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-)
diff --git a/teamd/teamd_balancer.c b/teamd/teamd_balancer.c index 25e8613..f9434c7 100644 --- a/teamd/teamd_balancer.c +++ b/teamd/teamd_balancer.c @@ -174,12 +174,14 @@ static void tb_clear_rebalance_data(struct teamd_balancer *tb) } }
-static int tb_hash_to_port_remap(struct team_handle *th, +static int tb_hash_to_port_remap(struct teamd_balancer *tb, + struct team_handle *th, struct tb_hash_info *tbhi, struct tb_port_info *tbpi) { struct team_option *option; struct teamd_port *new_tdport = tbpi->tdport; + struct teamd_context *ctx = tb->ctx; uint8_t hash = tbhi->hash; int err;
@@ -192,9 +194,9 @@ static int tb_hash_to_port_remap(struct team_handle *th, err = team_set_option_value_u32(th, option, new_tdport->ifindex); if (err) return err; - teamd_log_dbg("Remapped hash "%u" (delta %" PRIu64 ") to port %s.", - hash, tb_stats_get_delta(&tbhi->stats), - new_tdport->ifname); + teamd_log_dbgx(ctx, 1, "Remapped hash "%u" (delta %" PRIu64 ") to port %s.", + hash, tb_stats_get_delta(&tbhi->stats), + new_tdport->ifname); return 0; }
@@ -203,6 +205,7 @@ static int tb_rebalance(struct teamd_balancer *tb, struct team_handle *th) int err; struct tb_hash_info *tbhi; struct tb_port_info *tbpi; + struct teamd_context *ctx = tb->ctx;
if (!tb->tx_balancing_enabled) return 0; @@ -216,7 +219,7 @@ static int tb_rebalance(struct teamd_balancer *tb, struct team_handle *th) tbhi->rebalance.processed = true; continue; } - err = tb_hash_to_port_remap(th, tbhi, tbpi); + err = tb_hash_to_port_remap(tb, th, tbhi, tbpi); if (err) { tbpi->rebalance.unusable = true; continue; @@ -228,7 +231,7 @@ static int tb_rebalance(struct teamd_balancer *tb, struct team_handle *th) list_for_each_node_entry(tbpi, &tb->port_info_list, list) { if (tbpi->rebalance.unusable) continue; - teamd_log_dbg("Port %s rebalanced, delta: %" PRIu64, + teamd_log_dbgx(ctx, 1, "Port %s rebalanced, delta: %" PRIu64, tbpi->tdport->ifname, tbpi->rebalance.bytes); } return 0; @@ -303,8 +306,8 @@ static int tb_option_change_handler_func(struct team_handle *th, void *priv, array_index); return -EINVAL; } - teamd_log_dbg("stats update for hash "%u": "%" PRIu64 "".", - array_index, lb_stats->tx_bytes); + teamd_log_dbgx(ctx, 1, "stats update for hash "%u": "%" PRIu64 "".", + array_index, lb_stats->tx_bytes); tb_stats_update_hash(tb, array_index, lb_stats->tx_bytes); } @@ -319,7 +322,7 @@ static int tb_option_change_handler_func(struct team_handle *th, void *priv, port_ifindex); return -EINVAL; } - teamd_log_dbg("stats update for port %s: "%" PRIu64 "".", + teamd_log_dbgx(ctx, 1, "stats update for port %s: "%" PRIu64 "".", tdport->ifname, lb_stats->tx_bytes); tb_stats_update_port(tb, tdport, lb_stats->tx_bytes);
As libdaemon do not filter log messages when we use syslog as output, all debug messages will be printed to the syslog even if we set daemon_verbosity_level to LOG_INFO. This would make user full confused and annoying. Since we have a -g option to enable debug message specially, let's move all teamd_log_dbg to teamd_log_dbgx so user could choose to print debug message or not.
This patch will move all teamd_log_dbg to teamd_log_dbgx for teamd_runner_lacp.c
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd_runner_lacp.c | 44 +++++++++++++++++++-------------------- 1 file changed, 22 insertions(+), 22 deletions(-)
diff --git a/teamd/teamd_runner_lacp.c b/teamd/teamd_runner_lacp.c index d292d69..43b060e 100644 --- a/teamd/teamd_runner_lacp.c +++ b/teamd/teamd_runner_lacp.c @@ -254,7 +254,7 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) err = teamd_config_bool_get(ctx, &lacp->cfg.active, "$.runner.active"); if (err) lacp->cfg.active = LACP_CFG_DFLT_ACTIVE; - teamd_log_dbg("Using active "%d".", lacp->cfg.active); + teamd_log_dbgx(ctx, 1, "Using active "%d".", lacp->cfg.active);
err = teamd_config_int_get(ctx, &tmp, "$.runner.sys_prio"); if (err) { @@ -265,12 +265,12 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) } else { lacp->cfg.sys_prio = tmp; } - teamd_log_dbg("Using sys_prio "%d".", lacp->cfg.sys_prio); + teamd_log_dbgx(ctx, 1, "Using sys_prio "%d".", lacp->cfg.sys_prio);
err = teamd_config_bool_get(ctx, &lacp->cfg.fast_rate, "$.runner.fast_rate"); if (err) lacp->cfg.fast_rate = LACP_CFG_DFLT_FAST_RATE; - teamd_log_dbg("Using fast_rate "%d".", lacp->cfg.fast_rate); + teamd_log_dbgx(ctx, 1, "Using fast_rate "%d".", lacp->cfg.fast_rate);
err = teamd_config_int_get(ctx, &tmp, "$.runner.min_ports"); if (err) { @@ -281,7 +281,7 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) } else { lacp->cfg.min_ports = tmp; } - teamd_log_dbg("Using min_ports "%d".", lacp->cfg.min_ports); + teamd_log_dbgx(ctx, 1, "Using min_ports "%d".", lacp->cfg.min_ports);
err = teamd_config_string_get(ctx, &agg_select_policy_name, "$.runner.agg_select_policy"); if (err) @@ -292,7 +292,7 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) agg_select_policy_name); return err; } - teamd_log_dbg("Using agg_select_policy "%s".", + teamd_log_dbgx(ctx, 1, "Using agg_select_policy "%s".", lacp_get_agg_select_policy_name(lacp)); return 0; } @@ -634,8 +634,8 @@ static void lacp_switch_agg_lead(struct lacp_port *agg_lead, struct teamd_port *tdport; struct lacp_port *lacp_port;
- teamd_log_dbg("Renaming aggregator %u to %u", - lacp_agg_id(agg_lead), lacp_agg_id(new_agg_lead)); + teamd_log_dbgx(new_agg_lead->ctx, 1, "Renaming aggregator %u to %u", + lacp_agg_id(agg_lead), lacp_agg_id(new_agg_lead)); if (lacp->selected_agg_lead == agg_lead) lacp->selected_agg_lead = new_agg_lead; teamd_for_each_tdport(tdport, lacp->ctx) { @@ -649,13 +649,13 @@ static void lacp_port_agg_select(struct lacp_port *lacp_port) { struct lacp_port *agg_lead;
- teamd_log_dbg("%s: Selecting LACP port", lacp_port->tdport->ifname); + teamd_log_dbgx(lacp_port->ctx, 1, "%s: Selecting LACP port", lacp_port->tdport->ifname); agg_lead = lacp_get_agg_lead(lacp_port); lacp_port->agg_lead = agg_lead; if (lacp_port_better(lacp_port, agg_lead)) lacp_switch_agg_lead(agg_lead, lacp_port); - teamd_log_dbg("%s: LACP port selected into aggregator %u", - lacp_port->tdport->ifname, lacp_port_agg_id(lacp_port)); + teamd_log_dbgx(lacp_port->ctx, 1, "%s: LACP port selected into aggregator %u", + lacp_port->tdport->ifname, lacp_port_agg_id(lacp_port)); }
static struct lacp_port *lacp_find_new_agg_lead(struct lacp_port *old_agg_lead) @@ -677,9 +677,9 @@ static void lacp_port_agg_unselect(struct lacp_port *lacp_port) { struct lacp_port *agg_lead = lacp_port->agg_lead;
- teamd_log_dbg("%s: Unselecting LACP port", lacp_port->tdport->ifname); - teamd_log_dbg("%s: LACP port unselected from aggregator %u", - lacp_port->tdport->ifname, lacp_port_agg_id(lacp_port)); + teamd_log_dbgx(lacp_port->ctx, 1, "%s: Unselecting LACP port", lacp_port->tdport->ifname); + teamd_log_dbgx(lacp_port->ctx, 1, "%s: LACP port unselected from aggregator %u", + lacp_port->tdport->ifname, lacp_port_agg_id(lacp_port)); lacp_port->agg_lead = NULL; if (lacp_port == agg_lead) { /* In case currently unselected port is aggregator lead lead, @@ -715,8 +715,8 @@ static int lacp_selected_agg_update(struct lacp *lacp, if (!next_agg_lead) next_agg_lead = lacp_get_next_agg(lacp); if (lacp->selected_agg_lead != next_agg_lead) - teamd_log_dbg("Selecting aggregator %u", - lacp_agg_id(next_agg_lead)); + teamd_log_dbgx(lacp->ctx, 1, "Selecting aggregator %u", + lacp_agg_id(next_agg_lead)); lacp->selected_agg_lead = next_agg_lead;
err = lacp_ports_update_enabled(lacp); @@ -827,8 +827,8 @@ static int lacp_port_periodic_set(struct lacp_port *lacp_port) int fast_on;
fast_on = lacp_port->partner.state & INFO_STATE_LACP_TIMEOUT; - teamd_log_dbg("%s: Setting periodic timer to "%s".", - lacp_port->tdport->ifname, fast_on ? "fast": "slow"); + teamd_log_dbgx(lacp_port->ctx, 1, "%s: Setting periodic timer to "%s".", + lacp_port->tdport->ifname, fast_on ? "fast": "slow"); ms = fast_on ? LACP_PERIODIC_SHORT: LACP_PERIODIC_LONG; ms_to_timespec(&ts, ms); err = teamd_loop_callback_timer_set(lacp_port->ctx, @@ -929,8 +929,8 @@ static void lacp_port_actor_update(struct lacp_port *lacp_port) state |= INFO_STATE_DEFAULTED; if (teamd_port_count(lacp_port->ctx) > 0) state |= INFO_STATE_AGGREGATION; - teamd_log_dbg("%s: lacp info state: 0x%02X.", lacp_port->tdport->ifname, - state); + teamd_log_dbgx(lacp_port->ctx, 1, "%s: lacp info state: 0x%02X.", + lacp_port->tdport->ifname, state); lacp_port->actor.state = state; }
@@ -1198,7 +1198,7 @@ static int lacp_port_load_config(struct teamd_context *ctx, } else { lacp_port->cfg.lacp_prio = tmp; } - teamd_log_dbg("%s: Using lacp_prio "%d".", port_name, + teamd_log_dbgx(ctx, 1, "%s: Using lacp_prio "%d".", port_name, lacp_port->cfg.lacp_prio);
err = teamd_config_int_get(ctx, &tmp, @@ -1212,14 +1212,14 @@ static int lacp_port_load_config(struct teamd_context *ctx, } else { lacp_port->cfg.lacp_key = tmp; } - teamd_log_dbg("%s: Using lacp_key "%d".", port_name, + teamd_log_dbgx(ctx, 1, "%s: Using lacp_key "%d".", port_name, lacp_port->cfg.lacp_key);
err = teamd_config_bool_get(ctx, &lacp_port->cfg.sticky, "$.ports.%s.sticky", port_name); if (err) lacp_port->cfg.sticky = LACP_PORT_CFG_DFLT_STICKY; - teamd_log_dbg("%s: Using sticky "%d".", port_name, + teamd_log_dbgx(ctx, 1, "%s: Using sticky "%d".", port_name, lacp_port->cfg.sticky); return 0; }
As libdaemon do not filter log messages when we use syslog as output, all debug messages will be printed to the syslog even if we set daemon_verbosity_level to LOG_INFO. This would make user full confused and annoying. Since we have a -g option to enable debug message specially, let's move all teamd_log_dbg to teamd_log_dbgx so user could choose to print debug message or not.
This patch will move all teamd_log_dbg to teamd_log_dbgx for teamd_link_watch files.
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd_link_watch.c | 14 +++++++------- teamd/teamd_lw_arp_ping.c | 12 ++++++------ teamd/teamd_lw_ethtool.c | 4 ++-- teamd/teamd_lw_nsna_ping.c | 2 +- teamd/teamd_lw_psr.c | 12 ++++++------ teamd/teamd_lw_tipc.c | 8 ++++---- 6 files changed, 26 insertions(+), 26 deletions(-)
diff --git a/teamd/teamd_link_watch.c b/teamd/teamd_link_watch.c index 62f8267..7cf2185 100644 --- a/teamd/teamd_link_watch.c +++ b/teamd/teamd_link_watch.c @@ -281,8 +281,8 @@ static int link_watch_load_config_one(struct teamd_context *ctx,
err = team_get_port_user_linkup(ctx->th, tdport->ifindex, &linkup); if (!err) { - teamd_log_dbg("%s: Current user link state is "%s".", - tdport->ifname, linkup ? "up" : "down"); + teamd_log_dbgx(ctx, 1, "%s: Current user link state is "%s".", + tdport->ifname, linkup ? "up" : "down"); }
err = teamd_config_string_get(ctx, &link_watch_name, @@ -351,8 +351,8 @@ static int link_watch_event_watch_port_added(struct teamd_context *ctx, cpcookie = teamd_config_path_cookie_get(ctx, "$.ports.%s.link_watch", tdport->ifname); if (cpcookie) { - teamd_log_dbg("%s: Got link watch from port config.", - tdport->ifname); + teamd_log_dbgx(ctx, 1, "%s: Got link watch from port config.", + tdport->ifname); err = link_watch_load_config(ctx, tdport, cpcookie); if (err) return err; @@ -360,8 +360,8 @@ static int link_watch_event_watch_port_added(struct teamd_context *ctx,
cpcookie = teamd_config_path_cookie_get(ctx, "$.link_watch"); if (cpcookie) { - teamd_log_dbg("%s: Got link watch from global config.", - tdport->ifname); + teamd_log_dbgx(ctx, 1, "%s: Got link watch from global config.", + tdport->ifname); err = link_watch_load_config(ctx, tdport, cpcookie); if (err) return err; @@ -380,7 +380,7 @@ static int link_watch_event_watch_port_added(struct teamd_context *ctx, tdport->ifname); return err; } - teamd_log_dbg("%s: Using implicit link watch.", tdport->ifname); + teamd_log_dbgx(ctx, 1, "%s: Using implicit link watch.", tdport->ifname); return link_watch_event_watch_port_added(ctx, tdport, priv); } return 0; diff --git a/teamd/teamd_lw_arp_ping.c b/teamd/teamd_lw_arp_ping.c index 81806f0..5eb46f9 100644 --- a/teamd/teamd_lw_arp_ping.c +++ b/teamd/teamd_lw_arp_ping.c @@ -178,7 +178,7 @@ static int lw_ap_load_options(struct teamd_context *ctx, * If source_host is not provided, just use address 0.0.0.0 according * to RFC 5227 (IPv4 Address Conflict Detection). */ - teamd_log_dbg("source address "%s".", + teamd_log_dbgx(ctx, 1, "source address "%s".", str_in_addr(&ap_ppriv->src));
err = teamd_config_string_get(ctx, &host, "@.target_host", cpcookie); @@ -189,25 +189,25 @@ static int lw_ap_load_options(struct teamd_context *ctx, err = set_in_addr(&ap_ppriv->dst, host); if (err) return err; - teamd_log_dbg("target address "%s".", str_in_addr(&ap_ppriv->dst)); + teamd_log_dbgx(ctx, 1, "target address "%s".", str_in_addr(&ap_ppriv->dst));
err = teamd_config_bool_get(ctx, &ap_ppriv->validate_active, "@.validate_active", cpcookie); if (err) ap_ppriv->validate_active = false; - teamd_log_dbg("validate_active "%d".", ap_ppriv->validate_active); + teamd_log_dbgx(ctx, 1, "validate_active "%d".", ap_ppriv->validate_active);
err = teamd_config_bool_get(ctx, &ap_ppriv->validate_inactive, "@.validate_inactive", cpcookie); if (err) ap_ppriv->validate_inactive = false; - teamd_log_dbg("validate_inactive "%d".", ap_ppriv->validate_inactive); + teamd_log_dbgx(ctx, 1, "validate_inactive "%d".", ap_ppriv->validate_inactive);
err = teamd_config_bool_get(ctx, &ap_ppriv->send_always, "@.send_always", cpcookie); if (err) ap_ppriv->send_always = false; - teamd_log_dbg("send_always "%d".", ap_ppriv->send_always); + teamd_log_dbgx(ctx, 1, "send_always "%d".", ap_ppriv->send_always);
err = teamd_config_int_get(ctx, &tmp, "@.vlanid", cpcookie); if (!err) { @@ -217,7 +217,7 @@ static int lw_ap_load_options(struct teamd_context *ctx, } ap_ppriv->vlanid_in_use = true; ap_ppriv->vlanid = tmp; - teamd_log_dbg("vlan id "%u".", ap_ppriv->vlanid); + teamd_log_dbgx(ctx, 1, "vlan id "%u".", ap_ppriv->vlanid); }
return 0; diff --git a/teamd/teamd_lw_ethtool.c b/teamd/teamd_lw_ethtool.c index 2010136..0cb6437 100644 --- a/teamd/teamd_lw_ethtool.c +++ b/teamd/teamd_lw_ethtool.c @@ -115,7 +115,7 @@ static int lw_ethtool_load_options(struct teamd_context *ctx, teamd_log_err(""delay_up" must not be negative number."); return -EINVAL; } - teamd_log_dbg("delay_up "%d".", tmp); + teamd_log_dbgx(ctx, 1, "delay_up "%d".", tmp); ms_to_timespec(ðtool_ppriv->delay_up, tmp); } err = teamd_config_int_get(ctx, &tmp, "@.delay_down", cpcookie); @@ -124,7 +124,7 @@ static int lw_ethtool_load_options(struct teamd_context *ctx, teamd_log_err(""delay_down" must not be negative number."); return -EINVAL; } - teamd_log_dbg("delay_down "%d".", tmp); + teamd_log_dbgx(ctx, 1, "delay_down "%d".", tmp); ms_to_timespec(ðtool_ppriv->delay_down, tmp); } return 0; diff --git a/teamd/teamd_lw_nsna_ping.c b/teamd/teamd_lw_nsna_ping.c index 82371c4..6956f44 100644 --- a/teamd/teamd_lw_nsna_ping.c +++ b/teamd/teamd_lw_nsna_ping.c @@ -175,7 +175,7 @@ static int lw_nsnap_load_options(struct teamd_context *ctx, err = set_sockaddr_in6(&nsnap_ppriv->dst, host); if (err) return err; - teamd_log_dbg("target address "%s".", + teamd_log_dbgx(ctx, 1, "target address "%s".", str_sockaddr_in6(&nsnap_ppriv->dst));
return 0; diff --git a/teamd/teamd_lw_psr.c b/teamd/teamd_lw_psr.c index ad6e56b..88246b7 100644 --- a/teamd/teamd_lw_psr.c +++ b/teamd/teamd_lw_psr.c @@ -46,9 +46,9 @@ static int lw_psr_callback_periodic(struct teamd_context *ctx, int events, void } else { psr_ppriv->missed++; if (psr_ppriv->missed > psr_ppriv->missed_max && link_up) { - teamd_log_dbg("%s: Missed %u replies (max %u).", - tdport->ifname, psr_ppriv->missed, - psr_ppriv->missed_max); + teamd_log_dbgx(ctx, 1, "%s: Missed %u replies (max %u).", + tdport->ifname, psr_ppriv->missed, + psr_ppriv->missed_max); link_up = false; } } @@ -86,7 +86,7 @@ static int lw_psr_load_options(struct teamd_context *ctx, } else { tmp = LW_PSR_DEFAULT_INTERVAL; } - teamd_log_dbg("interval "%d".", tmp); + teamd_log_dbgx(ctx, 1, "interval "%d".", tmp); ms_to_timespec(&psr_ppriv->interval, tmp);
err = teamd_config_int_get(ctx, &tmp, "@.init_wait", cpcookie); @@ -95,7 +95,7 @@ static int lw_psr_load_options(struct teamd_context *ctx, /* if init_wait is set to 0, use default_init_wait */ if (err || !tmp) psr_ppriv->init_wait = lw_psr_default_init_wait; - teamd_log_dbg("init_wait "%d".", timespec_to_ms(&psr_ppriv->init_wait)); + teamd_log_dbgx(ctx, 1, "init_wait "%d".", timespec_to_ms(&psr_ppriv->init_wait));
err = teamd_config_int_get(ctx, &tmp, "@.missed_max", cpcookie); if (!err) { @@ -106,7 +106,7 @@ static int lw_psr_load_options(struct teamd_context *ctx, } else { tmp = LW_PSR_DEFAULT_MISSED_MAX; } - teamd_log_dbg("missed_max "%d".", tmp); + teamd_log_dbgx(ctx, 1, "missed_max "%d".", tmp); psr_ppriv->missed_max = tmp;
return 0; diff --git a/teamd/teamd_lw_tipc.c b/teamd/teamd_lw_tipc.c index 6d7277d..07b7cee 100644 --- a/teamd/teamd_lw_tipc.c +++ b/teamd/teamd_lw_tipc.c @@ -88,7 +88,7 @@ static int lw_tipc_link_state_change(struct teamd_context *ctx, if (strcmp(link->name, lnr->linkname)) continue; link->up = link_up; - teamd_log_dbg("tipc: link <%s> went %s.", + teamd_log_dbgx(ctx, 1, "tipc: link <%s> went %s.", lnr->linkname, link_up ? "up" : "down"); check: path_ok = lw_tipc_topology_check(priv, link->peer); @@ -100,7 +100,7 @@ check: lnr->linkname); return -EINVAL; } - teamd_log_dbg("tipc: established new link <%s>", lnr->linkname); + teamd_log_dbgx(ctx, 1, "tipc: established new link <%s>", lnr->linkname); link = malloc(sizeof(struct tipc_link)); if (!link) return -ENOMEM; @@ -153,7 +153,7 @@ static int lw_tipc_callback_socket(struct teamd_context *ctx, int events, void * else if (event.event == htonl(TIPC_WITHDRAWN)) return lw_tipc_link_state_change(ctx, &lnr, tipc_ppriv, false); tipc_cb_err: - teamd_log_dbg("tipc: link state event error"); + teamd_log_dbgx(ctx, 1, "tipc: link state event error"); return -EINVAL; }
@@ -234,7 +234,7 @@ static void lw_tipc_port_removed(struct teamd_context *ctx, struct lw_tipc_port_priv *tipc_ppriv = priv; struct tipc_link *link;
- teamd_log_dbg("tipc port removed\n"); + teamd_log_dbgx(ctx, 1, "tipc port removed\n"); teamd_loop_callback_del(ctx, LW_TIPC_TOPSRV_SOCKET, priv); close(tipc_ppriv->topsrv_sock); while (!LIST_EMPTY(&tipc_ppriv->links)) {
As libdaemon do not filter log messages when we use syslog as output, all debug messages will be printed to the syslog even if we set daemon_verbosity_level to LOG_INFO. This would make user full confused and annoying. Since we have a -g option to enable debug message specially, let's move all teamd_log_dbg to teamd_log_dbgx so user could choose to print debug message or not.
This patch will move all teamd_log_dbg to teamd_log_dbgx for all left files.
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd_dbus.c | 6 +++--- teamd/teamd_hash_func.c | 2 +- teamd/teamd_per_port.c | 6 +++--- teamd/teamd_usock.c | 12 ++++++------ teamd/teamd_zmq.c | 10 +++++----- 5 files changed, 18 insertions(+), 18 deletions(-)
diff --git a/teamd/teamd_dbus.c b/teamd/teamd_dbus.c index cdf21b1..48ebe5a 100644 --- a/teamd/teamd_dbus.c +++ b/teamd/teamd_dbus.c @@ -178,7 +178,7 @@ static DBusHandlerResult message_handler(DBusConnection *con, msg_interface = dbus_message_get_interface(message); if (!method || !path || !msg_interface) return DBUS_HANDLER_RESULT_NOT_YET_HANDLED; - teamd_log_dbg("dbus: %s.%s (%s)", msg_interface, method, path); + teamd_log_dbgx(ctx, 1, "dbus: %s.%s (%s)", msg_interface, method, path);
if (!strcmp(method, "Introspect") && !strcmp(msg_interface, "org.freedesktop.DBus.Introspectable")) { @@ -504,7 +504,7 @@ int teamd_dbus_init(struct teamd_context *ctx) if (err) goto iface_fini; id = dbus_connection_get_server_id(ctx->dbus.con), - teamd_log_dbg("dbus: connected to %s with name %s", id, + teamd_log_dbgx(ctx, 1, "dbus: connected to %s with name %s", id, dbus_bus_get_unique_name(ctx->dbus.con)); dbus_free(id); return 0; @@ -541,7 +541,7 @@ int teamd_dbus_expose_name(struct teamd_context *ctx) err = dbus_bus_request_name(ctx->dbus.con, service_name, 0, &error); if (err == DBUS_REQUEST_NAME_REPLY_PRIMARY_OWNER) { - teamd_log_dbg("dbus: have name %s", service_name); + teamd_log_dbgx(ctx, 1, "dbus: have name %s", service_name); err = 0; } else if (dbus_error_is_set(&error)) { teamd_log_err("dbus: Failed to acquire %s: %s: %s", diff --git a/teamd/teamd_hash_func.c b/teamd/teamd_hash_func.c index 8923849..d19692a 100644 --- a/teamd/teamd_hash_func.c +++ b/teamd/teamd_hash_func.c @@ -170,7 +170,7 @@ int teamd_hash_func_set(struct teamd_context *ctx) int err;
if (!teamd_config_path_exists(ctx, "$.runner.tx_hash")) { - teamd_log_dbg("No Tx hash recipe found in config."); + teamd_log_dbgx(ctx, 1, "No Tx hash recipe found in config."); err = teamd_hash_func_add_default_frags(ctx); if (err) return err; diff --git a/teamd/teamd_per_port.c b/teamd/teamd_per_port.c index f98a90d..a625c97 100644 --- a/teamd/teamd_per_port.c +++ b/teamd/teamd_per_port.c @@ -340,7 +340,7 @@ int teamd_port_add_ifname(struct teamd_context *ctx, const char *port_name) uint32_t ifindex;
ifindex = team_ifname2ifindex(ctx->th, port_name); - teamd_log_dbg("%s: Adding port (found ifindex "%d").", + teamd_log_dbgx(ctx, 1, "%s: Adding port (found ifindex "%d").", port_name, ifindex); return team_port_add(ctx->th, ifindex); } @@ -350,7 +350,7 @@ static int teamd_port_remove(struct teamd_context *ctx, { int err;
- teamd_log_dbg("%s: Removing port (found ifindex "%d").", + teamd_log_dbgx(ctx, 1, "%s: Removing port (found ifindex "%d").", tdport->ifname, tdport->ifindex); err = team_port_remove(ctx->th, tdport->ifindex); if (err) @@ -444,7 +444,7 @@ int teamd_port_check_enable(struct teamd_context *ctx, else return 0;
- teamd_log_dbg("%s: %s port", tdport->ifname, + teamd_log_dbgx(ctx, 1, "%s: %s port", tdport->ifname, new_enabled_state ? "Enabling": "Disabling"); err = team_set_port_enabled(ctx->th, tdport->ifindex, new_enabled_state); diff --git a/teamd/teamd_usock.c b/teamd/teamd_usock.c index c421c7a..d4769f1 100644 --- a/teamd/teamd_usock.c +++ b/teamd/teamd_usock.c @@ -171,28 +171,28 @@ static int process_rcv_msg(struct teamd_context *ctx, int sock, char *rcv_msg)
str = teamd_usock_msg_getline(&rest); if (!str) { - teamd_log_dbg("usock: Incomplete message."); + teamd_log_dbgx(ctx, 1, "usock: Incomplete message."); return 0; } if (strcmp(TEAMD_USOCK_REQUEST_PREFIX, str)) { - teamd_log_dbg("usock: Unsupported message type."); + teamd_log_dbgx(ctx, 1, "usock: Unsupported message type."); return 0; }
str = teamd_usock_msg_getline(&rest); if (!str) { - teamd_log_dbg("usock: Incomplete message."); + teamd_log_dbgx(ctx, 1, "usock: Incomplete message."); return 0; } if (!teamd_ctl_method_exists(str)) { - teamd_log_dbg("usock: Unknown method "%s".", str); + teamd_log_dbgx(ctx, 1, "usock: Unknown method "%s".", str); return 0; }
usock_ops_priv.sock = sock; usock_ops_priv.rcv_msg_args = rest;
- teamd_log_dbg("usock: calling method "%s"", str); + teamd_log_dbgx(ctx, 1, "usock: calling method "%s"", str);
return teamd_ctl_method_call(ctx, str, &teamd_usock_ctl_method_ops, &usock_ops_priv); @@ -315,7 +315,7 @@ static int teamd_usock_sock_open(struct teamd_context *ctx) teamd_usock_get_sockpath(addr.sun_path, sizeof(addr.sun_path), ctx->team_devname);
- teamd_log_dbg("usock: Using sockpath "%s"", addr.sun_path); + teamd_log_dbgx(ctx, 1, "usock: Using sockpath "%s"", addr.sun_path); err = unlink(addr.sun_path); if (err == -1 && errno != ENOENT) { teamd_log_err("usock: Failed to remove socket file."); diff --git a/teamd/teamd_zmq.c b/teamd/teamd_zmq.c index c39e38d..11dce8c 100644 --- a/teamd/teamd_zmq.c +++ b/teamd/teamd_zmq.c @@ -138,28 +138,28 @@ static int process_rcv_msg(struct teamd_context *ctx, char *rcv_msg)
str = teamd_zmq_msg_getline(&rest); if (!str) { - teamd_log_dbg("zmq: Incomplete message."); + teamd_log_dbgx(ctx, 1, "zmq: Incomplete message."); return 0; } if (strcmp(TEAMD_ZMQ_REQUEST_PREFIX, str)) { - teamd_log_dbg("zmq: Unsupported message type."); + teamd_log_dbgx(ctx, 1, "zmq: Unsupported message type."); return 0; }
str = teamd_zmq_msg_getline(&rest); if (!str) { - teamd_log_dbg("zmq: Incomplete message."); + teamd_log_dbgx(ctx, 1, "zmq: Incomplete message."); return 0; } if (!teamd_ctl_method_exists(str)) { - teamd_log_dbg("zmq: Unknown method "%s".", str); + teamd_log_dbgx(ctx, 1, "zmq: Unknown method "%s".", str); return 0; }
zmq_ops_priv.sock = ctx->zmq.sock; zmq_ops_priv.rcv_msg_args = rest;
- teamd_log_dbg("zmq: calling method "%s"", str); + teamd_log_dbgx(ctx, 1, "zmq: calling method "%s"", str);
return teamd_ctl_method_call(ctx, str, &teamd_zmq_ctl_method_ops, &zmq_ops_priv);
Hi Jiri,
Would you please help review this patch set when have time?
Thanks Hangbin On Wed, Nov 06, 2019 at 05:48:49PM +0800, Hangbin Liu wrote:
Hi Jiri,
I'm not sure if I should split the patch or just post one directly. Please tell me if you feel the commit message are repeated and want only one patch.
Recently some users reported that they start to see debug messages in their syslogs even with daemon_verbosity_level = LOG_INFO and without -g option.
Actually this issue is there at the begining, the user would see the debug messages if they run teamd with -d option. The reason that most users did not notice this is because they are using libteam via NetworkManager, and NetworkManager run libteam in frontend.
But after commit e47d5db53873 ("teamd: add an option to force log output to stdout, stderr or syslog"), NetworkManager will set TEAM_LOG_OUTPUT=syslog in the environment. At the same time libdaemon does not filter log levels if we use syslog(see function daemon_logv in libdaemon). Then all the users would see the debug messages suddenly and feels annoying.
And here is the quote for daemon_set_verbosity() from libdaemon/dlog.h """ Allows to decide which messages to output on standard output/error streams. All messages are logged to syslog and this setting does not influence that. """
Since we should not limit how our user(NM) used libteam. And libdaemon is intend to not filter logs if use syslog. We'd better filter the debug message ourselves, like via -g option. So I would prefer to move all teamd_log_dbg to teamd_log_dbgx. After that, the user could decide whether to enable debug or not by themselves with -g option.
Hangbin Liu (6): teamd/teamd.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_runner_activebackup.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_balancer.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_runner_lacp.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_link_watch.c: move teamd_log_dbg to teamd_log_dbgx teamd: move teamd_log_dbg to teamd_log_dbgx
teamd/teamd.c | 40 ++++++++++++++-------------- teamd/teamd_balancer.c | 21 ++++++++------- teamd/teamd_dbus.c | 6 ++--- teamd/teamd_hash_func.c | 2 +- teamd/teamd_link_watch.c | 14 +++++----- teamd/teamd_lw_arp_ping.c | 12 ++++----- teamd/teamd_lw_ethtool.c | 4 +-- teamd/teamd_lw_nsna_ping.c | 2 +- teamd/teamd_lw_psr.c | 12 ++++----- teamd/teamd_lw_tipc.c | 8 +++--- teamd/teamd_per_port.c | 6 ++--- teamd/teamd_runner_activebackup.c | 18 ++++++------- teamd/teamd_runner_lacp.c | 44 +++++++++++++++---------------- teamd/teamd_usock.c | 12 ++++----- teamd/teamd_zmq.c | 10 +++---- 15 files changed, 107 insertions(+), 104 deletions(-)
-- 2.19.2
Hi Jiri,
Would you please help review this patch set? Some customers are complaining about the debug messages.
Thanks Hangbin On Wed, Nov 06, 2019 at 05:48:49PM +0800, Hangbin Liu wrote:
Hi Jiri,
I'm not sure if I should split the patch or just post one directly. Please tell me if you feel the commit message are repeated and want only one patch.
Recently some users reported that they start to see debug messages in their syslogs even with daemon_verbosity_level = LOG_INFO and without -g option.
Actually this issue is there at the begining, the user would see the debug messages if they run teamd with -d option. The reason that most users did not notice this is because they are using libteam via NetworkManager, and NetworkManager run libteam in frontend.
But after commit e47d5db53873 ("teamd: add an option to force log output to stdout, stderr or syslog"), NetworkManager will set TEAM_LOG_OUTPUT=syslog in the environment. At the same time libdaemon does not filter log levels if we use syslog(see function daemon_logv in libdaemon). Then all the users would see the debug messages suddenly and feels annoying.
And here is the quote for daemon_set_verbosity() from libdaemon/dlog.h """ Allows to decide which messages to output on standard output/error streams. All messages are logged to syslog and this setting does not influence that. """
Since we should not limit how our user(NM) used libteam. And libdaemon is intend to not filter logs if use syslog. We'd better filter the debug message ourselves, like via -g option. So I would prefer to move all teamd_log_dbg to teamd_log_dbgx. After that, the user could decide whether to enable debug or not by themselves with -g option.
Hangbin Liu (6): teamd/teamd.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_runner_activebackup.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_balancer.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_runner_lacp.c: move teamd_log_dbg to teamd_log_dbgx teamd/teamd_link_watch.c: move teamd_log_dbg to teamd_log_dbgx teamd: move teamd_log_dbg to teamd_log_dbgx
teamd/teamd.c | 40 ++++++++++++++-------------- teamd/teamd_balancer.c | 21 ++++++++------- teamd/teamd_dbus.c | 6 ++--- teamd/teamd_hash_func.c | 2 +- teamd/teamd_link_watch.c | 14 +++++----- teamd/teamd_lw_arp_ping.c | 12 ++++----- teamd/teamd_lw_ethtool.c | 4 +-- teamd/teamd_lw_nsna_ping.c | 2 +- teamd/teamd_lw_psr.c | 12 ++++----- teamd/teamd_lw_tipc.c | 8 +++--- teamd/teamd_per_port.c | 6 ++--- teamd/teamd_runner_activebackup.c | 18 ++++++------- teamd/teamd_runner_lacp.c | 44 +++++++++++++++---------------- teamd/teamd_usock.c | 12 ++++----- teamd/teamd_zmq.c | 10 +++---- 15 files changed, 107 insertions(+), 104 deletions(-)
-- 2.19.2
Wed, Nov 06, 2019 at 10:48:49AM CET, liuhangbin@gmail.com wrote:
Hi Jiri,
I'm not sure if I should split the patch or just post one directly. Please tell me if you feel the commit message are repeated and want only one patch.
Recently some users reported that they start to see debug messages in their syslogs even with daemon_verbosity_level = LOG_INFO and without -g option.
Actually this issue is there at the begining, the user would see the debug messages if they run teamd with -d option. The reason that most users did not notice this is because they are using libteam via NetworkManager, and NetworkManager run libteam in frontend.
But after commit e47d5db53873 ("teamd: add an option to force log output to stdout, stderr or syslog"), NetworkManager will set TEAM_LOG_OUTPUT=syslog in the environment. At the same time libdaemon does not filter log levels if we use syslog(see function daemon_logv in libdaemon). Then all the users would see the debug messages suddenly and feels annoying.
And here is the quote for daemon_set_verbosity() from libdaemon/dlog.h """ Allows to decide which messages to output on standard output/error streams. All messages are logged to syslog and this setting does not influence that. """
Since we should not limit how our user(NM) used libteam. And libdaemon is intend to not filter logs if use syslog. We'd better filter the debug message ourselves, like via -g option. So I would prefer to move all teamd_log_dbg to teamd_log_dbgx. After that, the user could decide whether to enable debug or not by themselves with -g option.
So after this patchset, there is no user of teamd_log_dbg(), am I correct? I don't see you would remove it.
I would prefer to keep teamd_log_dbg() and only extend it with ctx arg, having it as: #define teamd_log_dbg(ctx, args...) teamd_log_dbgx(ctx, 1, ##args)
You can do it all in a single patch.
Sorry for the late reply :/
Recently some users reported that they start to see debug messages in their syslogs even with daemon_verbosity_level = LOG_INFO and without -g option.
Actually this issue is there at the begining, the user would see the debug messages if they run teamd with -d option. The reason that most users did not notice this is because they are using libteam via NetworkManager, and NetworkManager run libteam in frontend.
But after commit e47d5db53873 ("teamd: add an option to force log output to stdout, stderr or syslog"), NetworkManager will set TEAM_LOG_OUTPUT=syslog in the environment. At the same time libdaemon does not filter log levels if we use syslog(see function daemon_logv in libdaemon). Then all the users would see the debug messages suddenly and feels annoying.
And here is the quote for daemon_set_verbosity() from libdaemon/dlog.h """ Allows to decide which messages to output on standard output/error streams. All messages are logged to syslog and this setting does not influence that. """
Since we should not limit how our user(NM) used libteam. And libdaemon is intend to not filter logs if use syslog. We'd better filter the debug message ourselves, like via -g option. So I would prefer to move all teamd_log_dbg to teamd_log_dbgx. After that, the user could decide whether to enable debug or not by themselves with -g option.
v2: wapper teamd_log_dbg with teamd_log_dbgx as Jiri suggested. Move TEAMD_BUG to use daemon_log directly.
Signed-off-by: Hangbin Liu liuhangbin@gmail.com --- teamd/teamd.c | 38 +++++++++++++++---------------- teamd/teamd.h | 5 ++-- teamd/teamd_balancer.c | 15 +++++++----- teamd/teamd_dbus.c | 6 ++--- teamd/teamd_hash_func.c | 2 +- teamd/teamd_link_watch.c | 8 +++---- teamd/teamd_lw_arp_ping.c | 12 +++++----- teamd/teamd_lw_ethtool.c | 4 ++-- teamd/teamd_lw_nsna_ping.c | 2 +- teamd/teamd_lw_psr.c | 8 +++---- teamd/teamd_lw_tipc.c | 10 ++++---- teamd/teamd_per_port.c | 6 ++--- teamd/teamd_runner_activebackup.c | 10 ++++---- teamd/teamd_runner_lacp.c | 34 +++++++++++++-------------- teamd/teamd_usock.c | 12 +++++----- teamd/teamd_zmq.c | 10 ++++---- 16 files changed, 93 insertions(+), 89 deletions(-)
diff --git a/teamd/teamd.c b/teamd/teamd.c index 6c47312..9744021 100644 --- a/teamd/teamd.c +++ b/teamd/teamd.c @@ -332,7 +332,7 @@ static int teamd_run_loop_do_callbacks(struct list_item *lcb_list, fd_set *fds, if (err) { teamd_log_warn("Loop callback failed with: %s", strerror(-err)); - teamd_log_dbg("Failed loop callback: %s, %p", + teamd_log_dbg(ctx, "Failed loop callback: %s, %p", lcb->name, lcb->priv); } } @@ -519,7 +519,7 @@ static int __teamd_loop_callback_fd_add(struct teamd_context *ctx, list_add_tail(&ctx->run_loop.callback_list, &lcb->list); else list_add(&ctx->run_loop.callback_list, &lcb->list); - teamd_log_dbg("Added loop callback: %s, %p", lcb->name, lcb->priv); + teamd_log_dbg(ctx, "Added loop callback: %s, %p", lcb->name, lcb->priv); return 0;
lcb_free: @@ -636,7 +636,7 @@ void teamd_loop_callback_del(struct teamd_context *ctx, const char *cb_name, list_del(&lcb->list); if (lcb->is_period) close(lcb->fd); - teamd_log_dbg("Removed loop callback: %s, %p", + teamd_log_dbg(ctx, "Removed loop callback: %s, %p", lcb->name, lcb->priv); free(lcb->name); free(lcb); @@ -645,7 +645,7 @@ void teamd_loop_callback_del(struct teamd_context *ctx, const char *cb_name, if (found) teamd_run_loop_restart(ctx); else - teamd_log_dbg("Callback named "%s" not found.", cb_name); + teamd_log_dbg(ctx, "Callback named "%s" not found.", cb_name); }
int teamd_loop_callback_enable(struct teamd_context *ctx, const char *cb_name, @@ -820,7 +820,7 @@ static int teamd_set_hwaddr(struct teamd_context *ctx) if (err) return 0; /* addr is not defined in config, no change needed */
- teamd_log_dbg("Hwaddr string: "%s".", hwaddr_str); + teamd_log_dbg(ctx, "Hwaddr string: "%s".", hwaddr_str); err = parse_hwaddr(hwaddr_str, &hwaddr, &hwaddr_len); if (err) { teamd_log_err("Failed to parse hardware address."); @@ -953,16 +953,16 @@ static int teamd_runner_init(struct teamd_context *ctx)
err = teamd_config_string_get(ctx, &runner_name, "$.runner.name"); if (err) { - teamd_log_dbg("Failed to get team runner name from config."); + teamd_log_dbg(ctx, "Failed to get team runner name from config."); runner_name = TEAMD_DEFAULT_RUNNER_NAME; err = teamd_config_string_set(ctx, runner_name, "$.runner.name"); if (err) { teamd_log_err("Failed to set default team runner name in config."); return err; } - teamd_log_dbg("Using default team runner "%s".", runner_name); + teamd_log_dbg(ctx, "Using default team runner "%s".", runner_name); } else { - teamd_log_dbg("Using team runner "%s".", runner_name); + teamd_log_dbg(ctx, "Using team runner "%s".", runner_name); } ctx->runner = teamd_find_runner(runner_name); if (!ctx->runner) { @@ -1108,12 +1108,12 @@ static void debug_log_port_list(struct teamd_context *ctx) char buf[120]; bool trunc;
- teamd_log_dbg("<port_list>"); + teamd_log_dbg(ctx, "<port_list>"); team_for_each_port(port, ctx->th) { trunc = team_port_str(port, buf, sizeof(buf)); - teamd_log_dbg("%s %s", buf, trunc ? "<trunc>" : ""); + teamd_log_dbg(ctx, "%s %s", buf, trunc ? "<trunc>" : ""); } - teamd_log_dbg("</port_list>"); + teamd_log_dbg(ctx, "</port_list>"); }
static void debug_log_option_list(struct teamd_context *ctx) @@ -1139,12 +1139,12 @@ static void debug_log_ifinfo_list(struct teamd_context *ctx) char buf[120]; bool trunc;
- teamd_log_dbg("<ifinfo_list>"); + teamd_log_dbg(ctx, "<ifinfo_list>"); team_for_each_ifinfo(ifinfo, ctx->th) { trunc = team_ifinfo_str(ifinfo, buf, sizeof(buf)); - teamd_log_dbg("%s %s", buf, trunc ? "<trunc>" : ""); + teamd_log_dbg(ctx, "%s %s", buf, trunc ? "<trunc>" : ""); } - teamd_log_dbg("</ifinfo_list>"); + teamd_log_dbg(ctx, "</ifinfo_list>"); }
static int debug_change_handler_func(struct team_handle *th, void *priv, @@ -1573,7 +1573,7 @@ static int teamd_generate_devname(struct teamd_context *ctx) if (err) return err; } while (ifindex); - teamd_log_dbg("Generated team device name "%s".", buf); + teamd_log_dbg(ctx, "Generated team device name "%s".", buf);
ctx->team_devname = strdup(buf); if (!ctx->team_devname) @@ -1597,7 +1597,7 @@ static int teamd_get_devname(struct teamd_context *ctx, bool generate_enabled) } goto skip_set; } else { - teamd_log_dbg("Failed to get team device name from config."); + teamd_log_dbg(ctx, "Failed to get team device name from config."); if (generate_enabled) { err = teamd_generate_devname(ctx); if (err) { @@ -1617,7 +1617,7 @@ static int teamd_get_devname(struct teamd_context *ctx, bool generate_enabled) }
skip_set: - teamd_log_dbg("Using team device "%s".", ctx->team_devname); + teamd_log_dbg(ctx, "Using team device "%s".", ctx->team_devname);
err = asprintf(&ctx->ident, "%s_%s", ctx->argv0, ctx->team_devname); if (err == -1) { @@ -1835,9 +1835,9 @@ int main(int argc, char **argv) daemon_log_ident = ctx->ident; daemon_pid_file_proc = teamd_pid_file_proc;
- teamd_log_dbg("Using PID file "%s"", daemon_pid_file_proc()); + teamd_log_dbg(ctx, "Using PID file "%s"", daemon_pid_file_proc()); if (ctx->config_file) - teamd_log_dbg("Using config file "%s"", ctx->config_file); + teamd_log_dbg(ctx, "Using config file "%s"", ctx->config_file);
switch (ctx->cmd) { case DAEMON_CMD_HELP: diff --git a/teamd/teamd.h b/teamd/teamd.h index 01bd022..469b769 100644 --- a/teamd/teamd.h +++ b/teamd/teamd.h @@ -49,15 +49,16 @@ #define teamd_log_err(args...) daemon_log(LOG_ERR, ##args) #define teamd_log_warn(args...) daemon_log(LOG_WARNING, ##args) #define teamd_log_info(args...) daemon_log(LOG_INFO, ##args) -#define teamd_log_dbg(args...) daemon_log(LOG_DEBUG, ##args)
#define teamd_log_dbgx(ctx, val, args...) \ if (val <= ctx->debug) \ daemon_log(LOG_DEBUG, ##args)
+#define teamd_log_dbg(ctx, args...) teamd_log_dbgx(ctx, 1, ##args) + static inline void TEAMD_BUG(void) { - teamd_log_dbg("BUG: %s:%d\n", __FILE__, __LINE__); + daemon_log(LOG_DEBUG, "BUG: %s:%d\n", __FILE__, __LINE__); assert(0); }
diff --git a/teamd/teamd_balancer.c b/teamd/teamd_balancer.c index 25e8613..aa6389f 100644 --- a/teamd/teamd_balancer.c +++ b/teamd/teamd_balancer.c @@ -174,12 +174,14 @@ static void tb_clear_rebalance_data(struct teamd_balancer *tb) } }
-static int tb_hash_to_port_remap(struct team_handle *th, +static int tb_hash_to_port_remap(struct teamd_balancer *tb, + struct team_handle *th, struct tb_hash_info *tbhi, struct tb_port_info *tbpi) { struct team_option *option; struct teamd_port *new_tdport = tbpi->tdport; + struct teamd_context *ctx = tb->ctx; uint8_t hash = tbhi->hash; int err;
@@ -192,7 +194,7 @@ static int tb_hash_to_port_remap(struct team_handle *th, err = team_set_option_value_u32(th, option, new_tdport->ifindex); if (err) return err; - teamd_log_dbg("Remapped hash "%u" (delta %" PRIu64 ") to port %s.", + teamd_log_dbg(ctx, "Remapped hash "%u" (delta %" PRIu64 ") to port %s.", hash, tb_stats_get_delta(&tbhi->stats), new_tdport->ifname); return 0; @@ -203,6 +205,7 @@ static int tb_rebalance(struct teamd_balancer *tb, struct team_handle *th) int err; struct tb_hash_info *tbhi; struct tb_port_info *tbpi; + struct teamd_context *ctx = tb->ctx;
if (!tb->tx_balancing_enabled) return 0; @@ -216,7 +219,7 @@ static int tb_rebalance(struct teamd_balancer *tb, struct team_handle *th) tbhi->rebalance.processed = true; continue; } - err = tb_hash_to_port_remap(th, tbhi, tbpi); + err = tb_hash_to_port_remap(tb, th, tbhi, tbpi); if (err) { tbpi->rebalance.unusable = true; continue; @@ -228,7 +231,7 @@ static int tb_rebalance(struct teamd_balancer *tb, struct team_handle *th) list_for_each_node_entry(tbpi, &tb->port_info_list, list) { if (tbpi->rebalance.unusable) continue; - teamd_log_dbg("Port %s rebalanced, delta: %" PRIu64, + teamd_log_dbg(ctx, "Port %s rebalanced, delta: %" PRIu64, tbpi->tdport->ifname, tbpi->rebalance.bytes); } return 0; @@ -303,7 +306,7 @@ static int tb_option_change_handler_func(struct team_handle *th, void *priv, array_index); return -EINVAL; } - teamd_log_dbg("stats update for hash "%u": "%" PRIu64 "".", + teamd_log_dbg(ctx, "stats update for hash "%u": "%" PRIu64 "".", array_index, lb_stats->tx_bytes); tb_stats_update_hash(tb, array_index, lb_stats->tx_bytes); @@ -319,7 +322,7 @@ static int tb_option_change_handler_func(struct team_handle *th, void *priv, port_ifindex); return -EINVAL; } - teamd_log_dbg("stats update for port %s: "%" PRIu64 "".", + teamd_log_dbg(ctx, "stats update for port %s: "%" PRIu64 "".", tdport->ifname, lb_stats->tx_bytes); tb_stats_update_port(tb, tdport, lb_stats->tx_bytes); diff --git a/teamd/teamd_dbus.c b/teamd/teamd_dbus.c index cdf21b1..5e7ea69 100644 --- a/teamd/teamd_dbus.c +++ b/teamd/teamd_dbus.c @@ -178,7 +178,7 @@ static DBusHandlerResult message_handler(DBusConnection *con, msg_interface = dbus_message_get_interface(message); if (!method || !path || !msg_interface) return DBUS_HANDLER_RESULT_NOT_YET_HANDLED; - teamd_log_dbg("dbus: %s.%s (%s)", msg_interface, method, path); + teamd_log_dbg(ctx, "dbus: %s.%s (%s)", msg_interface, method, path);
if (!strcmp(method, "Introspect") && !strcmp(msg_interface, "org.freedesktop.DBus.Introspectable")) { @@ -504,7 +504,7 @@ int teamd_dbus_init(struct teamd_context *ctx) if (err) goto iface_fini; id = dbus_connection_get_server_id(ctx->dbus.con), - teamd_log_dbg("dbus: connected to %s with name %s", id, + teamd_log_dbg(ctx, "dbus: connected to %s with name %s", id, dbus_bus_get_unique_name(ctx->dbus.con)); dbus_free(id); return 0; @@ -541,7 +541,7 @@ int teamd_dbus_expose_name(struct teamd_context *ctx) err = dbus_bus_request_name(ctx->dbus.con, service_name, 0, &error); if (err == DBUS_REQUEST_NAME_REPLY_PRIMARY_OWNER) { - teamd_log_dbg("dbus: have name %s", service_name); + teamd_log_dbg(ctx, "dbus: have name %s", service_name); err = 0; } else if (dbus_error_is_set(&error)) { teamd_log_err("dbus: Failed to acquire %s: %s: %s", diff --git a/teamd/teamd_hash_func.c b/teamd/teamd_hash_func.c index 8923849..8c91639 100644 --- a/teamd/teamd_hash_func.c +++ b/teamd/teamd_hash_func.c @@ -170,7 +170,7 @@ int teamd_hash_func_set(struct teamd_context *ctx) int err;
if (!teamd_config_path_exists(ctx, "$.runner.tx_hash")) { - teamd_log_dbg("No Tx hash recipe found in config."); + teamd_log_dbg(ctx, "No Tx hash recipe found in config."); err = teamd_hash_func_add_default_frags(ctx); if (err) return err; diff --git a/teamd/teamd_link_watch.c b/teamd/teamd_link_watch.c index 62f8267..5c626eb 100644 --- a/teamd/teamd_link_watch.c +++ b/teamd/teamd_link_watch.c @@ -281,7 +281,7 @@ static int link_watch_load_config_one(struct teamd_context *ctx,
err = team_get_port_user_linkup(ctx->th, tdport->ifindex, &linkup); if (!err) { - teamd_log_dbg("%s: Current user link state is "%s".", + teamd_log_dbg(ctx, "%s: Current user link state is "%s".", tdport->ifname, linkup ? "up" : "down"); }
@@ -351,7 +351,7 @@ static int link_watch_event_watch_port_added(struct teamd_context *ctx, cpcookie = teamd_config_path_cookie_get(ctx, "$.ports.%s.link_watch", tdport->ifname); if (cpcookie) { - teamd_log_dbg("%s: Got link watch from port config.", + teamd_log_dbg(ctx, "%s: Got link watch from port config.", tdport->ifname); err = link_watch_load_config(ctx, tdport, cpcookie); if (err) @@ -360,7 +360,7 @@ static int link_watch_event_watch_port_added(struct teamd_context *ctx,
cpcookie = teamd_config_path_cookie_get(ctx, "$.link_watch"); if (cpcookie) { - teamd_log_dbg("%s: Got link watch from global config.", + teamd_log_dbg(ctx, "%s: Got link watch from global config.", tdport->ifname); err = link_watch_load_config(ctx, tdport, cpcookie); if (err) @@ -380,7 +380,7 @@ static int link_watch_event_watch_port_added(struct teamd_context *ctx, tdport->ifname); return err; } - teamd_log_dbg("%s: Using implicit link watch.", tdport->ifname); + teamd_log_dbg(ctx, "%s: Using implicit link watch.", tdport->ifname); return link_watch_event_watch_port_added(ctx, tdport, priv); } return 0; diff --git a/teamd/teamd_lw_arp_ping.c b/teamd/teamd_lw_arp_ping.c index 81806f0..c3d4710 100644 --- a/teamd/teamd_lw_arp_ping.c +++ b/teamd/teamd_lw_arp_ping.c @@ -178,7 +178,7 @@ static int lw_ap_load_options(struct teamd_context *ctx, * If source_host is not provided, just use address 0.0.0.0 according * to RFC 5227 (IPv4 Address Conflict Detection). */ - teamd_log_dbg("source address "%s".", + teamd_log_dbg(ctx, "source address "%s".", str_in_addr(&ap_ppriv->src));
err = teamd_config_string_get(ctx, &host, "@.target_host", cpcookie); @@ -189,25 +189,25 @@ static int lw_ap_load_options(struct teamd_context *ctx, err = set_in_addr(&ap_ppriv->dst, host); if (err) return err; - teamd_log_dbg("target address "%s".", str_in_addr(&ap_ppriv->dst)); + teamd_log_dbg(ctx, "target address "%s".", str_in_addr(&ap_ppriv->dst));
err = teamd_config_bool_get(ctx, &ap_ppriv->validate_active, "@.validate_active", cpcookie); if (err) ap_ppriv->validate_active = false; - teamd_log_dbg("validate_active "%d".", ap_ppriv->validate_active); + teamd_log_dbg(ctx, "validate_active "%d".", ap_ppriv->validate_active);
err = teamd_config_bool_get(ctx, &ap_ppriv->validate_inactive, "@.validate_inactive", cpcookie); if (err) ap_ppriv->validate_inactive = false; - teamd_log_dbg("validate_inactive "%d".", ap_ppriv->validate_inactive); + teamd_log_dbg(ctx, "validate_inactive "%d".", ap_ppriv->validate_inactive);
err = teamd_config_bool_get(ctx, &ap_ppriv->send_always, "@.send_always", cpcookie); if (err) ap_ppriv->send_always = false; - teamd_log_dbg("send_always "%d".", ap_ppriv->send_always); + teamd_log_dbg(ctx, "send_always "%d".", ap_ppriv->send_always);
err = teamd_config_int_get(ctx, &tmp, "@.vlanid", cpcookie); if (!err) { @@ -217,7 +217,7 @@ static int lw_ap_load_options(struct teamd_context *ctx, } ap_ppriv->vlanid_in_use = true; ap_ppriv->vlanid = tmp; - teamd_log_dbg("vlan id "%u".", ap_ppriv->vlanid); + teamd_log_dbg(ctx, "vlan id "%u".", ap_ppriv->vlanid); }
return 0; diff --git a/teamd/teamd_lw_ethtool.c b/teamd/teamd_lw_ethtool.c index 2010136..b44656e 100644 --- a/teamd/teamd_lw_ethtool.c +++ b/teamd/teamd_lw_ethtool.c @@ -115,7 +115,7 @@ static int lw_ethtool_load_options(struct teamd_context *ctx, teamd_log_err(""delay_up" must not be negative number."); return -EINVAL; } - teamd_log_dbg("delay_up "%d".", tmp); + teamd_log_dbg(ctx, "delay_up "%d".", tmp); ms_to_timespec(ðtool_ppriv->delay_up, tmp); } err = teamd_config_int_get(ctx, &tmp, "@.delay_down", cpcookie); @@ -124,7 +124,7 @@ static int lw_ethtool_load_options(struct teamd_context *ctx, teamd_log_err(""delay_down" must not be negative number."); return -EINVAL; } - teamd_log_dbg("delay_down "%d".", tmp); + teamd_log_dbg(ctx, "delay_down "%d".", tmp); ms_to_timespec(ðtool_ppriv->delay_down, tmp); } return 0; diff --git a/teamd/teamd_lw_nsna_ping.c b/teamd/teamd_lw_nsna_ping.c index 82371c4..9273462 100644 --- a/teamd/teamd_lw_nsna_ping.c +++ b/teamd/teamd_lw_nsna_ping.c @@ -175,7 +175,7 @@ static int lw_nsnap_load_options(struct teamd_context *ctx, err = set_sockaddr_in6(&nsnap_ppriv->dst, host); if (err) return err; - teamd_log_dbg("target address "%s".", + teamd_log_dbg(ctx, "target address "%s".", str_sockaddr_in6(&nsnap_ppriv->dst));
return 0; diff --git a/teamd/teamd_lw_psr.c b/teamd/teamd_lw_psr.c index ad6e56b..b0a41f4 100644 --- a/teamd/teamd_lw_psr.c +++ b/teamd/teamd_lw_psr.c @@ -46,7 +46,7 @@ static int lw_psr_callback_periodic(struct teamd_context *ctx, int events, void } else { psr_ppriv->missed++; if (psr_ppriv->missed > psr_ppriv->missed_max && link_up) { - teamd_log_dbg("%s: Missed %u replies (max %u).", + teamd_log_dbg(ctx, "%s: Missed %u replies (max %u).", tdport->ifname, psr_ppriv->missed, psr_ppriv->missed_max); link_up = false; @@ -86,7 +86,7 @@ static int lw_psr_load_options(struct teamd_context *ctx, } else { tmp = LW_PSR_DEFAULT_INTERVAL; } - teamd_log_dbg("interval "%d".", tmp); + teamd_log_dbg(ctx, "interval "%d".", tmp); ms_to_timespec(&psr_ppriv->interval, tmp);
err = teamd_config_int_get(ctx, &tmp, "@.init_wait", cpcookie); @@ -95,7 +95,7 @@ static int lw_psr_load_options(struct teamd_context *ctx, /* if init_wait is set to 0, use default_init_wait */ if (err || !tmp) psr_ppriv->init_wait = lw_psr_default_init_wait; - teamd_log_dbg("init_wait "%d".", timespec_to_ms(&psr_ppriv->init_wait)); + teamd_log_dbg(ctx, "init_wait "%d".", timespec_to_ms(&psr_ppriv->init_wait));
err = teamd_config_int_get(ctx, &tmp, "@.missed_max", cpcookie); if (!err) { @@ -106,7 +106,7 @@ static int lw_psr_load_options(struct teamd_context *ctx, } else { tmp = LW_PSR_DEFAULT_MISSED_MAX; } - teamd_log_dbg("missed_max "%d".", tmp); + teamd_log_dbg(ctx, "missed_max "%d".", tmp); psr_ppriv->missed_max = tmp;
return 0; diff --git a/teamd/teamd_lw_tipc.c b/teamd/teamd_lw_tipc.c index 6d7277d..e5b51ce 100644 --- a/teamd/teamd_lw_tipc.c +++ b/teamd/teamd_lw_tipc.c @@ -88,8 +88,8 @@ static int lw_tipc_link_state_change(struct teamd_context *ctx, if (strcmp(link->name, lnr->linkname)) continue; link->up = link_up; - teamd_log_dbg("tipc: link <%s> went %s.", - lnr->linkname, link_up ? "up" : "down"); + teamd_log_dbg(ctx, "tipc: link <%s> went %s.", + lnr->linkname, link_up ? "up" : "down"); check: path_ok = lw_tipc_topology_check(priv, link->peer); return teamd_link_watch_check_link_up(ctx, ppriv->tdport, ppriv, @@ -100,7 +100,7 @@ check: lnr->linkname); return -EINVAL; } - teamd_log_dbg("tipc: established new link <%s>", lnr->linkname); + teamd_log_dbg(ctx, "tipc: established new link <%s>", lnr->linkname); link = malloc(sizeof(struct tipc_link)); if (!link) return -ENOMEM; @@ -153,7 +153,7 @@ static int lw_tipc_callback_socket(struct teamd_context *ctx, int events, void * else if (event.event == htonl(TIPC_WITHDRAWN)) return lw_tipc_link_state_change(ctx, &lnr, tipc_ppriv, false); tipc_cb_err: - teamd_log_dbg("tipc: link state event error"); + teamd_log_dbg(ctx, "tipc: link state event error"); return -EINVAL; }
@@ -234,7 +234,7 @@ static void lw_tipc_port_removed(struct teamd_context *ctx, struct lw_tipc_port_priv *tipc_ppriv = priv; struct tipc_link *link;
- teamd_log_dbg("tipc port removed\n"); + teamd_log_dbg(ctx, "tipc port removed\n"); teamd_loop_callback_del(ctx, LW_TIPC_TOPSRV_SOCKET, priv); close(tipc_ppriv->topsrv_sock); while (!LIST_EMPTY(&tipc_ppriv->links)) { diff --git a/teamd/teamd_per_port.c b/teamd/teamd_per_port.c index f98a90d..e5cbe2b 100644 --- a/teamd/teamd_per_port.c +++ b/teamd/teamd_per_port.c @@ -340,7 +340,7 @@ int teamd_port_add_ifname(struct teamd_context *ctx, const char *port_name) uint32_t ifindex;
ifindex = team_ifname2ifindex(ctx->th, port_name); - teamd_log_dbg("%s: Adding port (found ifindex "%d").", + teamd_log_dbg(ctx, "%s: Adding port (found ifindex "%d").", port_name, ifindex); return team_port_add(ctx->th, ifindex); } @@ -350,7 +350,7 @@ static int teamd_port_remove(struct teamd_context *ctx, { int err;
- teamd_log_dbg("%s: Removing port (found ifindex "%d").", + teamd_log_dbg(ctx, "%s: Removing port (found ifindex "%d").", tdport->ifname, tdport->ifindex); err = team_port_remove(ctx->th, tdport->ifindex); if (err) @@ -444,7 +444,7 @@ int teamd_port_check_enable(struct teamd_context *ctx, else return 0;
- teamd_log_dbg("%s: %s port", tdport->ifname, + teamd_log_dbg(ctx, "%s: %s port", tdport->ifname, new_enabled_state ? "Enabling": "Disabling"); err = team_set_port_enabled(ctx->th, tdport->ifindex, new_enabled_state); diff --git a/teamd/teamd_runner_activebackup.c b/teamd/teamd_runner_activebackup.c index f92d341..35b39a3 100644 --- a/teamd/teamd_runner_activebackup.c +++ b/teamd/teamd_runner_activebackup.c @@ -255,7 +255,7 @@ static int ab_clear_active_port(struct teamd_context *ctx, struct ab *ab, ab->active_ifindex = 0; if (!tdport || !teamd_port_present(ctx, tdport)) return 0; - teamd_log_dbg("Clearing active port "%s".", tdport->ifname); + teamd_log_dbg(ctx, "Clearing active port "%s".", tdport->ifname);
err = team_set_port_enabled(ctx->th, tdport->ifindex, false); if (err) { @@ -368,7 +368,7 @@ static int ab_link_watch_handler(struct teamd_context *ctx, struct ab *ab)
active_tdport = teamd_get_port(ctx, ab->active_ifindex); if (active_tdport) { - teamd_log_dbg("Current active port: "%s" (ifindex "%d", prio "%d").", + teamd_log_dbg(ctx, "Current active port: "%s" (ifindex "%d", prio "%d").", active_tdport->ifname, active_tdport->ifindex, teamd_port_prio(ctx, active_tdport));
@@ -404,7 +404,7 @@ static int ab_link_watch_handler(struct teamd_context *ctx, struct ab *ab) if (!best.tdport || best.tdport == active_tdport) return 0;
- teamd_log_dbg("Found best port: "%s" (ifindex "%d", prio "%d").", + teamd_log_dbg(ctx, "Found best port: "%s" (ifindex "%d", prio "%d").", best.tdport->ifname, best.tdport->ifindex, best.prio);
if (!active_tdport || !ab_is_port_sticky(ab, active_tdport)) { @@ -459,7 +459,7 @@ static int ab_port_load_config(struct teamd_context *ctx, "$.ports.%s.sticky", port_name); if (err) ab_port->cfg.sticky = AB_DFLT_PORT_STICKY; - teamd_log_dbg("%s: Using sticky "%d".", port_name, + teamd_log_dbg(ctx, "%s: Using sticky "%d".", port_name, ab_port->cfg.sticky); return 0; } @@ -558,7 +558,7 @@ static int ab_load_config(struct teamd_context *ctx, struct ab *ab) hwaddr_policy_name); return err; } - teamd_log_dbg("Using hwaddr_policy "%s".", ab->hwaddr_policy->name); + teamd_log_dbg(ctx, "Using hwaddr_policy "%s".", ab->hwaddr_policy->name); return 0; }
diff --git a/teamd/teamd_runner_lacp.c b/teamd/teamd_runner_lacp.c index d292d69..7d940b3 100644 --- a/teamd/teamd_runner_lacp.c +++ b/teamd/teamd_runner_lacp.c @@ -254,7 +254,7 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) err = teamd_config_bool_get(ctx, &lacp->cfg.active, "$.runner.active"); if (err) lacp->cfg.active = LACP_CFG_DFLT_ACTIVE; - teamd_log_dbg("Using active "%d".", lacp->cfg.active); + teamd_log_dbg(ctx, "Using active "%d".", lacp->cfg.active);
err = teamd_config_int_get(ctx, &tmp, "$.runner.sys_prio"); if (err) { @@ -265,12 +265,12 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) } else { lacp->cfg.sys_prio = tmp; } - teamd_log_dbg("Using sys_prio "%d".", lacp->cfg.sys_prio); + teamd_log_dbg(ctx, "Using sys_prio "%d".", lacp->cfg.sys_prio);
err = teamd_config_bool_get(ctx, &lacp->cfg.fast_rate, "$.runner.fast_rate"); if (err) lacp->cfg.fast_rate = LACP_CFG_DFLT_FAST_RATE; - teamd_log_dbg("Using fast_rate "%d".", lacp->cfg.fast_rate); + teamd_log_dbg(ctx, "Using fast_rate "%d".", lacp->cfg.fast_rate);
err = teamd_config_int_get(ctx, &tmp, "$.runner.min_ports"); if (err) { @@ -281,7 +281,7 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) } else { lacp->cfg.min_ports = tmp; } - teamd_log_dbg("Using min_ports "%d".", lacp->cfg.min_ports); + teamd_log_dbg(ctx, "Using min_ports "%d".", lacp->cfg.min_ports);
err = teamd_config_string_get(ctx, &agg_select_policy_name, "$.runner.agg_select_policy"); if (err) @@ -292,7 +292,7 @@ static int lacp_load_config(struct teamd_context *ctx, struct lacp *lacp) agg_select_policy_name); return err; } - teamd_log_dbg("Using agg_select_policy "%s".", + teamd_log_dbg(ctx, "Using agg_select_policy "%s".", lacp_get_agg_select_policy_name(lacp)); return 0; } @@ -634,7 +634,7 @@ static void lacp_switch_agg_lead(struct lacp_port *agg_lead, struct teamd_port *tdport; struct lacp_port *lacp_port;
- teamd_log_dbg("Renaming aggregator %u to %u", + teamd_log_dbg(new_agg_lead->ctx, "Renaming aggregator %u to %u", lacp_agg_id(agg_lead), lacp_agg_id(new_agg_lead)); if (lacp->selected_agg_lead == agg_lead) lacp->selected_agg_lead = new_agg_lead; @@ -649,12 +649,12 @@ static void lacp_port_agg_select(struct lacp_port *lacp_port) { struct lacp_port *agg_lead;
- teamd_log_dbg("%s: Selecting LACP port", lacp_port->tdport->ifname); + teamd_log_dbg(lacp_port->ctx, "%s: Selecting LACP port", lacp_port->tdport->ifname); agg_lead = lacp_get_agg_lead(lacp_port); lacp_port->agg_lead = agg_lead; if (lacp_port_better(lacp_port, agg_lead)) lacp_switch_agg_lead(agg_lead, lacp_port); - teamd_log_dbg("%s: LACP port selected into aggregator %u", + teamd_log_dbg(lacp_port->ctx, "%s: LACP port selected into aggregator %u", lacp_port->tdport->ifname, lacp_port_agg_id(lacp_port)); }
@@ -677,8 +677,8 @@ static void lacp_port_agg_unselect(struct lacp_port *lacp_port) { struct lacp_port *agg_lead = lacp_port->agg_lead;
- teamd_log_dbg("%s: Unselecting LACP port", lacp_port->tdport->ifname); - teamd_log_dbg("%s: LACP port unselected from aggregator %u", + teamd_log_dbg(lacp_port->ctx, "%s: Unselecting LACP port", lacp_port->tdport->ifname); + teamd_log_dbg(lacp_port->ctx, "%s: LACP port unselected from aggregator %u", lacp_port->tdport->ifname, lacp_port_agg_id(lacp_port)); lacp_port->agg_lead = NULL; if (lacp_port == agg_lead) { @@ -715,7 +715,7 @@ static int lacp_selected_agg_update(struct lacp *lacp, if (!next_agg_lead) next_agg_lead = lacp_get_next_agg(lacp); if (lacp->selected_agg_lead != next_agg_lead) - teamd_log_dbg("Selecting aggregator %u", + teamd_log_dbg(lacp->ctx, "Selecting aggregator %u", lacp_agg_id(next_agg_lead)); lacp->selected_agg_lead = next_agg_lead;
@@ -827,7 +827,7 @@ static int lacp_port_periodic_set(struct lacp_port *lacp_port) int fast_on;
fast_on = lacp_port->partner.state & INFO_STATE_LACP_TIMEOUT; - teamd_log_dbg("%s: Setting periodic timer to "%s".", + teamd_log_dbg(lacp_port->ctx, "%s: Setting periodic timer to "%s".", lacp_port->tdport->ifname, fast_on ? "fast": "slow"); ms = fast_on ? LACP_PERIODIC_SHORT: LACP_PERIODIC_LONG; ms_to_timespec(&ts, ms); @@ -929,8 +929,8 @@ static void lacp_port_actor_update(struct lacp_port *lacp_port) state |= INFO_STATE_DEFAULTED; if (teamd_port_count(lacp_port->ctx) > 0) state |= INFO_STATE_AGGREGATION; - teamd_log_dbg("%s: lacp info state: 0x%02X.", lacp_port->tdport->ifname, - state); + teamd_log_dbg(lacp_port->ctx, "%s: lacp info state: 0x%02X.", + lacp_port->tdport->ifname, state); lacp_port->actor.state = state; }
@@ -1198,7 +1198,7 @@ static int lacp_port_load_config(struct teamd_context *ctx, } else { lacp_port->cfg.lacp_prio = tmp; } - teamd_log_dbg("%s: Using lacp_prio "%d".", port_name, + teamd_log_dbg(ctx, "%s: Using lacp_prio "%d".", port_name, lacp_port->cfg.lacp_prio);
err = teamd_config_int_get(ctx, &tmp, @@ -1212,14 +1212,14 @@ static int lacp_port_load_config(struct teamd_context *ctx, } else { lacp_port->cfg.lacp_key = tmp; } - teamd_log_dbg("%s: Using lacp_key "%d".", port_name, + teamd_log_dbg(ctx, "%s: Using lacp_key "%d".", port_name, lacp_port->cfg.lacp_key);
err = teamd_config_bool_get(ctx, &lacp_port->cfg.sticky, "$.ports.%s.sticky", port_name); if (err) lacp_port->cfg.sticky = LACP_PORT_CFG_DFLT_STICKY; - teamd_log_dbg("%s: Using sticky "%d".", port_name, + teamd_log_dbg(ctx, "%s: Using sticky "%d".", port_name, lacp_port->cfg.sticky); return 0; } diff --git a/teamd/teamd_usock.c b/teamd/teamd_usock.c index c421c7a..1adfdf8 100644 --- a/teamd/teamd_usock.c +++ b/teamd/teamd_usock.c @@ -171,28 +171,28 @@ static int process_rcv_msg(struct teamd_context *ctx, int sock, char *rcv_msg)
str = teamd_usock_msg_getline(&rest); if (!str) { - teamd_log_dbg("usock: Incomplete message."); + teamd_log_dbg(ctx, "usock: Incomplete message."); return 0; } if (strcmp(TEAMD_USOCK_REQUEST_PREFIX, str)) { - teamd_log_dbg("usock: Unsupported message type."); + teamd_log_dbg(ctx, "usock: Unsupported message type."); return 0; }
str = teamd_usock_msg_getline(&rest); if (!str) { - teamd_log_dbg("usock: Incomplete message."); + teamd_log_dbg(ctx, "usock: Incomplete message."); return 0; } if (!teamd_ctl_method_exists(str)) { - teamd_log_dbg("usock: Unknown method "%s".", str); + teamd_log_dbg(ctx, "usock: Unknown method "%s".", str); return 0; }
usock_ops_priv.sock = sock; usock_ops_priv.rcv_msg_args = rest;
- teamd_log_dbg("usock: calling method "%s"", str); + teamd_log_dbg(ctx, "usock: calling method "%s"", str);
return teamd_ctl_method_call(ctx, str, &teamd_usock_ctl_method_ops, &usock_ops_priv); @@ -315,7 +315,7 @@ static int teamd_usock_sock_open(struct teamd_context *ctx) teamd_usock_get_sockpath(addr.sun_path, sizeof(addr.sun_path), ctx->team_devname);
- teamd_log_dbg("usock: Using sockpath "%s"", addr.sun_path); + teamd_log_dbg(ctx, "usock: Using sockpath "%s"", addr.sun_path); err = unlink(addr.sun_path); if (err == -1 && errno != ENOENT) { teamd_log_err("usock: Failed to remove socket file."); diff --git a/teamd/teamd_zmq.c b/teamd/teamd_zmq.c index c39e38d..3f3c2f6 100644 --- a/teamd/teamd_zmq.c +++ b/teamd/teamd_zmq.c @@ -138,28 +138,28 @@ static int process_rcv_msg(struct teamd_context *ctx, char *rcv_msg)
str = teamd_zmq_msg_getline(&rest); if (!str) { - teamd_log_dbg("zmq: Incomplete message."); + teamd_log_dbg(ctx, "zmq: Incomplete message."); return 0; } if (strcmp(TEAMD_ZMQ_REQUEST_PREFIX, str)) { - teamd_log_dbg("zmq: Unsupported message type."); + teamd_log_dbg(ctx, "zmq: Unsupported message type."); return 0; }
str = teamd_zmq_msg_getline(&rest); if (!str) { - teamd_log_dbg("zmq: Incomplete message."); + teamd_log_dbg(ctx, "zmq: Incomplete message."); return 0; } if (!teamd_ctl_method_exists(str)) { - teamd_log_dbg("zmq: Unknown method "%s".", str); + teamd_log_dbg(ctx, "zmq: Unknown method "%s".", str); return 0; }
zmq_ops_priv.sock = ctx->zmq.sock; zmq_ops_priv.rcv_msg_args = rest;
- teamd_log_dbg("zmq: calling method "%s"", str); + teamd_log_dbg(ctx, "zmq: calling method "%s"", str);
return teamd_ctl_method_call(ctx, str, &teamd_zmq_ctl_method_ops, &zmq_ops_priv);
Mon, Dec 02, 2019 at 09:28:17AM CET, liuhangbin@gmail.com wrote:
Recently some users reported that they start to see debug messages in their syslogs even with daemon_verbosity_level = LOG_INFO and without -g option.
Actually this issue is there at the begining, the user would see the debug messages if they run teamd with -d option. The reason that most users did not notice this is because they are using libteam via NetworkManager, and NetworkManager run libteam in frontend.
But after commit e47d5db53873 ("teamd: add an option to force log output to stdout, stderr or syslog"), NetworkManager will set TEAM_LOG_OUTPUT=syslog in the environment. At the same time libdaemon does not filter log levels if we use syslog(see function daemon_logv in libdaemon). Then all the users would see the debug messages suddenly and feels annoying.
And here is the quote for daemon_set_verbosity() from libdaemon/dlog.h """ Allows to decide which messages to output on standard output/error streams. All messages are logged to syslog and this setting does not influence that. """
Since we should not limit how our user(NM) used libteam. And libdaemon is intend to not filter logs if use syslog. We'd better filter the debug message ourselves, like via -g option. So I would prefer to move all teamd_log_dbg to teamd_log_dbgx. After that, the user could decide whether to enable debug or not by themselves with -g option.
v2: wapper teamd_log_dbg with teamd_log_dbgx as Jiri suggested. Move TEAMD_BUG to use daemon_log directly.
Signed-off-by: Hangbin Liu liuhangbin@gmail.com
applied, thanks.
Next time, please put the "v2" notes under "---"
libteam@lists.fedorahosted.org