From 17c333ece527ee7551fed86504198b83c6c3289a Mon Sep 17 00:00:00 2001 From: Ben Pfaff Date: Thu, 15 Jan 2009 14:57:59 -0800 Subject: [PATCH] vlog: Add INFO level and apply it to messages for "normal" behavior. Fixes bug #246. --- lib/dhcp-client.c | 10 +++++----- lib/learning-switch.c | 2 +- lib/rconn.c | 16 ++++++++-------- lib/vconn-ssl.c | 6 +++--- lib/vlog.c | 6 +++--- lib/vlog.h | 4 ++++ lib/vlog.man | 3 ++- secchan/discovery.c | 4 ++-- secchan/executer.c | 8 ++++---- secchan/fail-open.c | 4 ++-- secchan/port-watcher.c | 4 ++-- secchan/secchan.c | 4 ++-- secchan/stp-secchan.c | 2 +- utilities/vlogconf.8.in | 2 +- utilities/vlogconf.c | 2 +- vswitchd/bridge.c | 17 ++++++++--------- vswitchd/cfg.c | 4 ++-- 17 files changed, 51 insertions(+), 47 deletions(-) diff --git a/lib/dhcp-client.c b/lib/dhcp-client.c index 4c12b4eb..5cbd2971 100644 --- a/lib/dhcp-client.c +++ b/lib/dhcp-client.c @@ -851,11 +851,11 @@ state_transition(struct dhclient *cli, enum dhclient_state state) cli->changed = true; if (am_bound) { assert(cli->binding != NULL); - VLOG_WARN("%s: obtained address "IP_FMT", netmask "IP_FMT, + VLOG_INFO("%s: obtained address "IP_FMT", netmask "IP_FMT, netdev_get_name(cli->netdev), IP_ARGS(&cli->ipaddr), IP_ARGS(&cli->netmask)); if (cli->router) { - VLOG_WARN("%s: obtained default gateway "IP_FMT, + VLOG_INFO("%s: obtained default gateway "IP_FMT, netdev_get_name(cli->netdev), IP_ARGS(&cli->router)); } } else { @@ -863,7 +863,7 @@ state_transition(struct dhclient *cli, enum dhclient_state state) free(cli->binding); cli->binding = NULL; - VLOG_WARN("%s: network address unbound", + VLOG_INFO("%s: network address unbound", netdev_get_name(cli->netdev)); } } @@ -967,7 +967,7 @@ do_receive_msg(struct dhclient *cli, struct dhcp_msg *msg) VLOG_DBG_RL(&rl, "received %s", dhcp_msg_to_string(msg, false, &cli->s)); } else { - VLOG_WARN_RL(&rl, "received %s", dhcp_type_name(msg->type)); + VLOG_INFO_RL(&rl, "received %s", dhcp_type_name(msg->type)); } ofpbuf_uninit(&b); return true; @@ -1046,7 +1046,7 @@ do_send_msg(struct dhclient *cli, const struct dhcp_msg *msg) if (VLOG_IS_DBG_ENABLED()) { VLOG_DBG("sending %s", dhcp_msg_to_string(msg, false, &cli->s)); } else { - VLOG_WARN("sending %s", dhcp_type_name(msg->type)); + VLOG_INFO("sending %s", dhcp_type_name(msg->type)); } error = netdev_send(cli->netdev, &b); if (error) { diff --git a/lib/learning-switch.c b/lib/learning-switch.c index 22838120..37788234 100644 --- a/lib/learning-switch.c +++ b/lib/learning-switch.c @@ -361,7 +361,7 @@ queue_tx(struct lswitch *sw, struct rconn *rconn, struct ofpbuf *b) int retval = rconn_send_with_limit(rconn, b, &sw->n_queued, 10); if (retval && retval != ENOTCONN) { if (retval == EAGAIN) { - VLOG_WARN_RL(&rl, "%012llx: %s: tx queue overflow", + VLOG_INFO_RL(&rl, "%012llx: %s: tx queue overflow", sw->datapath_id, rconn_get_name(rconn)); } else { VLOG_WARN_RL(&rl, "%012llx: %s: send: %s", diff --git a/lib/rconn.c b/lib/rconn.c index 910c1ced..96e41346 100644 --- a/lib/rconn.c +++ b/lib/rconn.c @@ -296,7 +296,7 @@ reconnect(struct rconn *rc) { int retval; - VLOG_WARN("%s: connecting...", rc->name); + VLOG_INFO("%s: connecting...", rc->name); rc->n_attempted_connections++; retval = vconn_open(rc->name, OFP_VERSION, &rc->vconn); if (!retval) { @@ -338,15 +338,15 @@ run_CONNECTING(struct rconn *rc) { int retval = vconn_connect(rc->vconn); if (!retval) { - VLOG_WARN("%s: connected", rc->name); + VLOG_INFO("%s: connected", rc->name); rc->n_successful_connections++; state_transition(rc, S_ACTIVE); rc->last_connected = rc->state_entered; } else if (retval != EAGAIN) { - VLOG_WARN("%s: connection failed (%s)", rc->name, strerror(retval)); + VLOG_INFO("%s: connection failed (%s)", rc->name, strerror(retval)); disconnect(rc, retval); } else if (timed_out(rc)) { - VLOG_WARN("%s: connection timed out", rc->name); + VLOG_INFO("%s: connection timed out", rc->name); rc->backoff_deadline = TIME_MAX; /* Prevent resetting backoff. */ disconnect(rc, 0); } @@ -565,7 +565,7 @@ void rconn_add_monitor(struct rconn *rc, struct vconn *vconn) { if (rc->n_monitors < ARRAY_SIZE(rc->monitors)) { - VLOG_WARN("new monitor connection from %s", vconn_get_name(vconn)); + VLOG_INFO("new monitor connection from %s", vconn_get_name(vconn)); rc->monitors[rc->n_monitors++] = vconn; } else { VLOG_DBG("too many monitor connections, discarding %s", @@ -746,10 +746,10 @@ disconnect(struct rconn *rc, int error) rc->name, strerror(error)); } else if (error == EOF) { if (rc->reliable) { - VLOG_WARN("%s: connection closed by peer", rc->name); + VLOG_INFO("%s: connection closed by peer", rc->name); } } else { - VLOG_WARN("%s: connection dropped", rc->name); + VLOG_INFO("%s: connection dropped", rc->name); } vconn_close(rc->vconn); rc->vconn = NULL; @@ -760,7 +760,7 @@ disconnect(struct rconn *rc, int error) rc->backoff = 1; } else { rc->backoff = MIN(rc->max_backoff, MAX(1, 2 * rc->backoff)); - VLOG_WARN("%s: waiting %d seconds before reconnect\n", + VLOG_INFO("%s: waiting %d seconds before reconnect\n", rc->name, rc->backoff); } rc->backoff_deadline = now + rc->backoff; diff --git a/lib/vconn-ssl.c b/lib/vconn-ssl.c index c5a16250..7f415a09 100644 --- a/lib/vconn-ssl.c +++ b/lib/vconn-ssl.c @@ -404,7 +404,7 @@ do_ca_cert_bootstrap(struct vconn *vconn) return error; } - VLOG_WARN("successfully bootstrapped CA cert to %s", ca_cert_file); + VLOG_INFO("successfully bootstrapped CA cert to %s", ca_cert_file); log_ca_cert(ca_cert_file, ca_cert); bootstrap_ca_cert = false; has_ca_cert = true; @@ -423,7 +423,7 @@ do_ca_cert_bootstrap(struct vconn *vconn) ERR_error_string(ERR_get_error(), NULL)); return EPROTO; } - VLOG_WARN("killing successful connection to retry using CA cert"); + VLOG_INFO("killing successful connection to retry using CA cert"); return EPROTO; } @@ -1155,7 +1155,7 @@ log_ca_cert(const char *file_name, X509 *cert) } } subject = X509_NAME_oneline(X509_get_subject_name(cert), NULL, 0); - VLOG_WARN("Trusting CA cert from %s (%s) (fingerprint %s)", file_name, + VLOG_INFO("Trusting CA cert from %s (%s) (fingerprint %s)", file_name, subject ? subject : "", ds_cstr(&fp)); free(subject); ds_destroy(&fp); diff --git a/lib/vlog.c b/lib/vlog.c index 0ebe890f..e23d0173 100644 --- a/lib/vlog.c +++ b/lib/vlog.c @@ -277,7 +277,7 @@ vlog_set_log_file(const char *file_name) /* Close old log file. */ if (log_file) { - VLOG_WARN("closing log file"); + VLOG_INFO("closing log file"); fclose(log_file); log_file = NULL; } @@ -304,7 +304,7 @@ vlog_set_log_file(const char *file_name) log_file_name, strerror(errno)); error = errno; } else { - VLOG_WARN("opened log file %s", log_file_name); + VLOG_INFO("opened log file %s", log_file_name); error = 0; } @@ -407,7 +407,7 @@ vlog_init(void) time_t now; openlog(program_name, LOG_NDELAY, LOG_DAEMON); - vlog_set_levels(VLM_ANY_MODULE, VLF_ANY_FACILITY, VLL_WARN); + vlog_set_levels(VLM_ANY_MODULE, VLF_ANY_FACILITY, VLL_INFO); boot_time = time_msec(); now = time_now(); diff --git a/lib/vlog.h b/lib/vlog.h index cd832a71..8785851c 100644 --- a/lib/vlog.h +++ b/lib/vlog.h @@ -45,6 +45,7 @@ VLOG_LEVEL(EMER, LOG_ALERT) \ VLOG_LEVEL(ERR, LOG_ERR) \ VLOG_LEVEL(WARN, LOG_WARNING) \ + VLOG_LEVEL(INFO, LOG_NOTICE) \ VLOG_LEVEL(DBG, LOG_DEBUG) enum vlog_level { #define VLOG_LEVEL(NAME, SYSLOG_LEVEL) VLL_##NAME, @@ -148,6 +149,7 @@ void vlog_rate_limit(enum vlog_module, enum vlog_level, #define VLOG_EMER(...) VLOG(VLL_EMER, __VA_ARGS__) #define VLOG_ERR(...) VLOG(VLL_ERR, __VA_ARGS__) #define VLOG_WARN(...) VLOG(VLL_WARN, __VA_ARGS__) +#define VLOG_INFO(...) VLOG(VLL_INFO, __VA_ARGS__) #define VLOG_DBG(...) VLOG(VLL_DBG, __VA_ARGS__) /* More convenience macros, for testing whether a given level is enabled in @@ -156,6 +158,7 @@ void vlog_rate_limit(enum vlog_module, enum vlog_level, #define VLOG_IS_EMER_ENABLED() true #define VLOG_IS_ERR_ENABLED() vlog_is_enabled(THIS_MODULE, VLL_EMER) #define VLOG_IS_WARN_ENABLED() vlog_is_enabled(THIS_MODULE, VLL_WARN) +#define VLOG_IS_INFO_ENABLED() vlog_is_enabled(THIS_MODULE, VLL_INFO) #define VLOG_IS_DBG_ENABLED() vlog_is_enabled(THIS_MODULE, VLL_DBG) /* Convenience macros. To use these, define THIS_MODULE as a macro that @@ -166,6 +169,7 @@ void vlog_rate_limit(enum vlog_module, enum vlog_level, */ #define VLOG_ERR_RL(RL, ...) VLOG_RL(RL, VLL_ERR, __VA_ARGS__) #define VLOG_WARN_RL(RL, ...) VLOG_RL(RL, VLL_WARN, __VA_ARGS__) +#define VLOG_INFO_RL(RL, ...) VLOG_RL(RL, VLL_INFO, __VA_ARGS__) #define VLOG_DBG_RL(RL, ...) VLOG_RL(RL, VLL_DBG, __VA_ARGS__) /* Command line processing. */ diff --git a/lib/vlog.man b/lib/vlog.man index f6d2acc6..0e439f86 100644 --- a/lib/vlog.man +++ b/lib/vlog.man @@ -21,7 +21,8 @@ will not take place unless \fB--log-file\fR is also specified (see below). .IP \(bu -\fIlevel\fR must be one of \fBemer\fR, \fBerr\fR, \fBwarn\fR, or +\fIlevel\fR must be one of \fBemer\fR, \fBerr\fR, \fBwarn\fR, +\fBinfo\fR, or \fBdbg\fR, designating the minimum severity of a message for it to be logged. If it is omitted, \fIlevel\fR defaults to \fBdbg\fR. .RE diff --git a/secchan/discovery.c b/secchan/discovery.c index cb39a37d..feb9c338 100644 --- a/secchan/discovery.c +++ b/secchan/discovery.c @@ -203,12 +203,12 @@ discovery_run(struct discovery *d, char **controller_name) if (dhclient_is_bound(d->dhcp)) { *controller_name = dhcp_msg_get_string(dhclient_get_config(d->dhcp), DHCP_CODE_OFP_CONTROLLER_VCONN); - VLOG_WARN("%s: discovered controller", *controller_name); + VLOG_INFO("%s: discovered controller", *controller_name); d->n_changes++; } else { *controller_name = NULL; if (d->n_changes) { - VLOG_WARN("discovered controller no longer available"); + VLOG_INFO("discovered controller no longer available"); d->n_changes++; } } diff --git a/secchan/executer.c b/secchan/executer.c index 008d2cc1..964a8b94 100644 --- a/secchan/executer.c +++ b/secchan/executer.c @@ -1,4 +1,4 @@ -/* Copyright (c) 2008 The Board of Trustees of The Leland Stanford +/* Copyright (c) 2008, 2009 The Board of Trustees of The Leland Stanford * Junior University * * We are making the OpenFlow specification and associated documentation @@ -126,7 +126,7 @@ executer_is_permitted(const char *acl_, const char *cmd) /* Check the command white/blacklisted state. */ if (allowed && !denied) { - VLOG_WARN("permitting command execution: \"%s\" is whitelisted", cmd); + VLOG_INFO("permitting command execution: \"%s\" is whitelisted", cmd); } else if (allowed && denied) { VLOG_WARN("denying command execution: \"%s\" is both blacklisted " "and whitelisted", cmd); @@ -252,7 +252,7 @@ executer_remote_packet_cb(struct relay *r, void *e_) /* Running in parent. */ struct child *child; - VLOG_WARN("started \"%s\" subprocess", argv[0]); + VLOG_INFO("started \"%s\" subprocess", argv[0]); send_child_status(r, request->header.xid, NXT_STATUS_STARTED, NULL, 0); child = &e->children[e->n_children++]; child->name = xstrdup(argv[0]); @@ -330,7 +330,7 @@ child_terminated(struct child *child, int status) if (WCOREDUMP(status)) { ds_put_cstr(&ds, " (core dumped)"); } - VLOG_WARN("child process \"%s\" with pid %ld terminated %s", + VLOG_INFO("child process \"%s\" with pid %ld terminated %s", child->name, (long int) child->pid, ds_cstr(&ds)); ds_destroy(&ds); diff --git a/secchan/fail-open.c b/secchan/fail-open.c index 06e1c31e..eb28bc38 100644 --- a/secchan/fail-open.c +++ b/secchan/fail-open.c @@ -1,4 +1,4 @@ -/* Copyright (c) 2008 The Board of Trustees of The Leland Stanford +/* Copyright (c) 2008, 2009 The Board of Trustees of The Leland Stanford * Junior University * * We are making the OpenFlow specification and associated documentation @@ -84,7 +84,7 @@ fail_open_periodic_cb(void *fail_open_) fail_open->last_disconn_secs = disconn_secs; } } else if (open && disconn_secs > fail_open->last_disconn_secs + 60) { - VLOG_WARN("Still in fail-open mode after %d seconds disconnected " + VLOG_INFO("Still in fail-open mode after %d seconds disconnected " "from controller", disconn_secs); fail_open->last_disconn_secs = disconn_secs; } diff --git a/secchan/port-watcher.c b/secchan/port-watcher.c index dcc4e31c..97e5a9ff 100644 --- a/secchan/port-watcher.c +++ b/secchan/port-watcher.c @@ -157,7 +157,7 @@ call_local_port_changed_callbacks(struct port_watcher *pw) } if (strcmp(pw->local_port_name, name)) { if (name[0]) { - VLOG_WARN("Identified data path local port as \"%s\".", name); + VLOG_INFO("Identified data path local port as \"%s\".", name); } else { VLOG_WARN("Data path has no local port."); } @@ -222,7 +222,7 @@ port_watcher_local_packet_cb(struct relay *r, void *pw_) pw->got_feature_reply = true; if (pw->datapath_id != osf->datapath_id) { pw->datapath_id = osf->datapath_id; - VLOG_WARN("Datapath id is %012"PRIx64, ntohll(pw->datapath_id)); + VLOG_INFO("Datapath id is %012"PRIx64, ntohll(pw->datapath_id)); } /* Update each port included in the message. */ diff --git a/secchan/secchan.c b/secchan/secchan.c index 03a5b791..c17d02ca 100644 --- a/secchan/secchan.c +++ b/secchan/secchan.c @@ -154,8 +154,8 @@ main(int argc, char *argv[]) ofp_fatal(retval, "Could not listen for vlog connections"); } - VLOG_WARN("OpenFlow reference implementation version %s", VERSION BUILDNR); - VLOG_WARN("OpenFlow protocol version 0x%02x", OFP_VERSION); + VLOG_INFO("OpenFlow reference implementation version %s", VERSION BUILDNR); + VLOG_INFO("OpenFlow protocol version 0x%02x", OFP_VERSION); /* Check datapath name, to try to catch command-line invocation errors. */ if (strncmp(s.dp_name, "nl:", 3) && strncmp(s.dp_name, "unix:", 5) diff --git a/secchan/stp-secchan.c b/secchan/stp-secchan.c index 917cea45..152595e9 100644 --- a/secchan/stp-secchan.c +++ b/secchan/stp-secchan.c @@ -151,7 +151,7 @@ stp_periodic_cb(void *stp_) enum stp_state s_state = stp_port_get_state(p); if (s_state != STP_DISABLED) { - VLOG_WARN("STP: Port %d entered %s state", + VLOG_INFO("STP: Port %d entered %s state", port_no, stp_state_name(s_state)); } if (!(port_watcher_get_config(stp->pw, port_no) & OFPPC_NO_STP)) { diff --git a/utilities/vlogconf.8.in b/utilities/vlogconf.8.in index b120a387..65c9857f 100644 --- a/utilities/vlogconf.8.in +++ b/utilities/vlogconf.8.in @@ -76,7 +76,7 @@ set the logging levels for all modules. The \fIfacility\fR may be system log or to the console, respectively, or \fBANY\fR to set the logging levels for both facilities. If it is omitted, \fIfacility\fR defaults to \fBANY\fR. The \fIlevel\fR must be one of -\fBemer\fR, \fBerr\fR, \fBwarn\fR, or \fBdbg\fR, designating the +\fBemer\fR, \fBerr\fR, \fBwarn\fR, \fBinfo\fR, or \fBdbg\fR, designating the minimum severity of a message for it to be logged. If it is omitted, \fIlevel\fR defaults to \fBdbg\fR. diff --git a/utilities/vlogconf.c b/utilities/vlogconf.c index 1187dcc2..5c48f724 100644 --- a/utilities/vlogconf.c +++ b/utilities/vlogconf.c @@ -62,7 +62,7 @@ usage(char *prog_name, int exit_code) " Set MODULE and FACILITY log level to LEVEL\n" " MODULE may be any valid module name or 'ANY'\n" " FACILITY may be 'syslog', 'console', 'file', or 'ANY' (default)\n" - " LEVEL may be 'emer', 'err', 'warn', or 'dbg' (default)\n" + " LEVEL may be 'emer', 'err', 'warn', 'info', or 'dbg' (default)\n" " -r, --reopen Make the program reopen its log file\n" " -h, --help Print this helpful information\n", prog_name); diff --git a/vswitchd/bridge.c b/vswitchd/bridge.c index 6d06648e..78c1f2db 100644 --- a/vswitchd/bridge.c +++ b/vswitchd/bridge.c @@ -495,7 +495,7 @@ bridge_create(const char *name) VLOG_WARN("bad dp_idx for bridge %s", br->name); } - VLOG_WARN("created bridge %s with dp_idx %d", br->name, br->dp_idx); + VLOG_INFO("created bridge %s with dp_idx %d", br->name, br->dp_idx); return br; } @@ -1214,17 +1214,17 @@ bond_link_status_update(struct iface *iface, bool carrier) /* Nothing to do. */ return; } - VLOG_WARN_RL(&rl, "interface %s: carrier %s", + VLOG_INFO_RL(&rl, "interface %s: carrier %s", iface->name, carrier ? "detected" : "dropped"); if (carrier == iface->enabled) { iface->delay_expires = LLONG_MAX; - VLOG_WARN_RL(&rl, "interface %s: will not be %s", + VLOG_INFO_RL(&rl, "interface %s: will not be %s", iface->name, carrier ? "disabled" : "enabled"); } else { int delay = carrier ? port->updelay : port->downdelay; iface->delay_expires = time_msec() + delay; if (delay) { - VLOG_WARN_RL(&rl, + VLOG_INFO_RL(&rl, "interface %s: will be %s if it stays %s for %d ms", iface->name, carrier ? "enabled" : "disabled", @@ -1242,7 +1242,7 @@ bond_choose_active_iface(struct port *port) port->active_iface = bond_choose_iface(port); port->active_iface_tag = tag_create_random(); if (port->active_iface >= 0) { - VLOG_WARN_RL(&rl, "port %s: active interface is now %s", + VLOG_INFO_RL(&rl, "port %s: active interface is now %s", port->name, port->ifaces[port->active_iface]->name); } else { VLOG_WARN_RL(&rl, "port %s: all ports disabled, no active interface", @@ -2322,7 +2322,7 @@ port_create(struct bridge *br, const char *name) } br->ports[br->n_ports++] = port; - VLOG_WARN("created port %s on bridge %s", port->name, br->name); + VLOG_INFO("created port %s on bridge %s", port->name, br->name); bridge_flush(br); } @@ -2670,7 +2670,7 @@ mirror_create(struct bridge *br, const char *name) } } - VLOG_WARN("created port mirror %s on bridge %s", name, br->name); + VLOG_INFO("created port mirror %s on bridge %s", name, br->name); bridge_flush(br); br->mirrors[i] = m = xcalloc(1, sizeof *m); @@ -3033,14 +3033,13 @@ brstp_update_port_state(struct port *p) /* Update state. */ if (p->stp_state != state) { static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(10, 10); - VLOG_WARN_RL(&rl, "port %s: STP state changed from %s to %s", + VLOG_INFO_RL(&rl, "port %s: STP state changed from %s to %s", p->name, stp_state_name(p->stp_state), stp_state_name(state)); if (p->stp_state == STP_DISABLED) { bridge_flush(br); } else { tag_set_add(&p->bridge->revalidate_set, p->stp_state_tag); - printf("invalidate %x\n", p->stp_state_tag); } p->stp_state = state; p->stp_state_tag = (p->stp_state == STP_DISABLED ? 0 diff --git a/vswitchd/cfg.c b/vswitchd/cfg.c index 788b462b..8aa420d3 100644 --- a/vswitchd/cfg.c +++ b/vswitchd/cfg.c @@ -97,7 +97,7 @@ cfg_add_file(const char *file_name) close(fd); /* Add it to the list. */ - VLOG_WARN("using \"%s\" as a configuration file", file_name); + VLOG_INFO("using \"%s\" as a configuration file", file_name); svec_add(&cfg_files, file_name); return 0; } @@ -114,7 +114,7 @@ cfg_read(void) svec_clear(&cfg); /* Read new configuration. */ - VLOG_WARN("reading configuration..."); + VLOG_INFO("reading configuration..."); for (i = 0; i < cfg_files.n; i++) { const char *fn = cfg_files.names[i]; struct stat s; -- 2.30.2