From owner-svn-src-head@FreeBSD.ORG Thu Jan 22 17:09:55 2015 Return-Path: Delivered-To: svn-src-head@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 0E247FB; Thu, 22 Jan 2015 17:09:55 +0000 (UTC) Received: from svn.freebsd.org (svn.freebsd.org [IPv6:2001:1900:2254:2068::e6a:0]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id E2A8B640; Thu, 22 Jan 2015 17:09:54 +0000 (UTC) Received: from svn.freebsd.org ([127.0.1.70]) by svn.freebsd.org (8.14.9/8.14.9) with ESMTP id t0MH9sDa093006; Thu, 22 Jan 2015 17:09:54 GMT (envelope-from will@FreeBSD.org) Received: (from will@localhost) by svn.freebsd.org (8.14.9/8.14.9/Submit) id t0MH9svg093005; Thu, 22 Jan 2015 17:09:54 GMT (envelope-from will@FreeBSD.org) Message-Id: <201501221709.t0MH9svg093005@svn.freebsd.org> X-Authentication-Warning: svn.freebsd.org: will set sender to will@FreeBSD.org using -f From: Will Andrews Date: Thu, 22 Jan 2015 17:09:54 +0000 (UTC) To: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org Subject: svn commit: r277530 - head/sys/netinet X-SVN-Group: head MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-BeenThere: svn-src-head@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: SVN commit messages for the src tree for head/-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 22 Jan 2015 17:09:55 -0000 Author: will Date: Thu Jan 22 17:09:54 2015 New Revision: 277530 URL: https://svnweb.freebsd.org/changeset/base/277530 Log: Improve CARP logging so that all state transitions are logged. sys/netinet/ip_carp.c: Add a "reason" string parameter to carp_set_state() and carp_master_down_locked() allowing more specific logging information to be passed into these apis. Refactor existing state transition logging into a single log call in carp_set_state(). Update all calls to carp_set_state() and carp_master_down_locked() to pass an appropriate reason string. For state transitions that were previously logged, the output should be unchanged. Submitted by: gibbs (original), asomers (updated) MFC after: 1 week Sponsored by: Spectra Logic MFSpectraBSD: 1039697 on 2014/02/11 (original) 1049992 on 2014/03/21 (updated) Modified: head/sys/netinet/ip_carp.c Modified: head/sys/netinet/ip_carp.c ============================================================================== --- head/sys/netinet/ip_carp.c Thu Jan 22 14:49:36 2015 (r277529) +++ head/sys/netinet/ip_carp.c Thu Jan 22 17:09:54 2015 (r277530) @@ -304,11 +304,12 @@ static void carp_destroy(struct carp_sof static struct carp_if *carp_alloc_if(struct ifnet *); static void carp_free_if(struct carp_if *); -static void carp_set_state(struct carp_softc *, int); +static void carp_set_state(struct carp_softc *, int, const char* reason); static void carp_sc_state(struct carp_softc *); static void carp_setrun(struct carp_softc *, sa_family_t); static void carp_master_down(void *); -static void carp_master_down_locked(struct carp_softc *); +static void carp_master_down_locked(struct carp_softc *, + const char* reason); static void carp_send_ad(void *); static void carp_send_ad_locked(struct carp_softc *); static void carp_addroute(struct carp_softc *); @@ -654,11 +655,8 @@ carp_input_c(struct mbuf *m, struct carp if (timevalcmp(&sc_tv, &ch_tv, >) || timevalcmp(&sc_tv, &ch_tv, ==)) { callout_stop(&sc->sc_ad_tmo); - CARP_LOG("VHID %u@%s: MASTER -> BACKUP " - "(more frequent advertisement received)\n", - sc->sc_vhid, - sc->sc_carpdev->if_xname); - carp_set_state(sc, BACKUP); + carp_set_state(sc, BACKUP, + "more frequent advertisement received"); carp_setrun(sc, 0); carp_delroute(sc); } @@ -669,11 +667,8 @@ carp_input_c(struct mbuf *m, struct carp * and this one claims to be slower, treat him as down. */ if (V_carp_preempt && timevalcmp(&sc_tv, &ch_tv, <)) { - CARP_LOG("VHID %u@%s: BACKUP -> MASTER " - "(preempting a slower master)\n", - sc->sc_vhid, - sc->sc_carpdev->if_xname); - carp_master_down_locked(sc); + carp_master_down_locked(sc, + "preempting a slower master"); break; } @@ -684,11 +679,7 @@ carp_input_c(struct mbuf *m, struct carp */ sc_tv.tv_sec = sc->sc_advbase * 3; if (timevalcmp(&sc_tv, &ch_tv, <)) { - CARP_LOG("VHID %u@%s: BACKUP -> MASTER " - "(master timed out)\n", - sc->sc_vhid, - sc->sc_carpdev->if_xname); - carp_master_down_locked(sc); + carp_master_down_locked(sc, "master will time out"); break; } @@ -1153,10 +1144,7 @@ carp_master_down(void *v) CURVNET_SET(sc->sc_carpdev->if_vnet); if (sc->sc_state == BACKUP) { - CARP_LOG("VHID %u@%s: BACKUP -> MASTER (master down)\n", - sc->sc_vhid, - sc->sc_carpdev->if_xname); - carp_master_down_locked(sc); + carp_master_down_locked(sc, "master timed out"); } CURVNET_RESTORE(); @@ -1164,14 +1152,14 @@ carp_master_down(void *v) } static void -carp_master_down_locked(struct carp_softc *sc) +carp_master_down_locked(struct carp_softc *sc, const char *reason) { CARP_LOCK_ASSERT(sc); switch (sc->sc_state) { case BACKUP: - carp_set_state(sc, MASTER); + carp_set_state(sc, MASTER, reason); carp_send_ad_locked(sc); #ifdef INET carp_send_arp(sc); @@ -1212,10 +1200,7 @@ carp_setrun(struct carp_softc *sc, sa_fa switch (sc->sc_state) { case INIT: - CARP_LOG("VHID %u@%s: INIT -> BACKUP\n", - sc->sc_vhid, - sc->sc_carpdev->if_xname); - carp_set_state(sc, BACKUP); + carp_set_state(sc, BACKUP, "initialization complete"); carp_setrun(sc, 0); break; case BACKUP: @@ -1717,12 +1702,12 @@ carp_ioctl(struct ifreq *ifr, u_long cmd switch (carpr.carpr_state) { case BACKUP: callout_stop(&sc->sc_ad_tmo); - carp_set_state(sc, BACKUP); + carp_set_state(sc, BACKUP, "SIOCSVH"); carp_setrun(sc, 0); carp_delroute(sc); break; case MASTER: - carp_master_down_locked(sc); + carp_master_down_locked(sc, "SIOCSVH"); break; default: break; @@ -1964,7 +1949,7 @@ carp_detach_locked(struct ifaddr *ifa) } static void -carp_set_state(struct carp_softc *sc, int state) +carp_set_state(struct carp_softc *sc, int state, const char *reason) { CARP_LOCK_ASSERT(sc); @@ -1973,10 +1958,14 @@ carp_set_state(struct carp_softc *sc, in const char *carp_states[] = { CARP_STATES }; char subsys[IFNAMSIZ+5]; - sc->sc_state = state; - snprintf(subsys, IFNAMSIZ+5, "%u@%s", sc->sc_vhid, sc->sc_carpdev->if_xname); + + CARP_LOG("%s: %s -> %s (%s)\n", subsys, + carp_states[sc->sc_state], carp_states[state], reason); + + sc->sc_state = state; + devctl_notify("CARP", subsys, carp_states[state], NULL); } } @@ -2010,13 +1999,13 @@ carp_sc_state(struct carp_softc *sc) #ifdef INET6 callout_stop(&sc->sc_md6_tmo); #endif - carp_set_state(sc, INIT); + carp_set_state(sc, INIT, "hw interface down"); carp_setrun(sc, 0); if (!sc->sc_suppress) carp_demote_adj(V_carp_ifdown_adj, "interface down"); sc->sc_suppress = 1; } else { - carp_set_state(sc, INIT); + carp_set_state(sc, INIT, "hw interface up"); carp_setrun(sc, 0); if (sc->sc_suppress) carp_demote_adj(-V_carp_ifdown_adj, "interface up");