ubik: log important messages at default log level

Many important ubik messages (e.g., errors, warnings, sync state
changes) are logged at log level 5 (-d 5) or higher.  Many sites are
reluctant to run ubik servers at a logging level higher than the default
due to the large number of extremely noisy informational messages at log
level 5.  Therefore, many important log messages are never seen.

Instead, issue critical errors, warnings, and other important messages
at log level 0 so that they are always seen, even at the default logging
level.

In addition, disambiguate the two "I am no longer sync-site" messages by
adding a unique reason text to each.

Reviewed-on: https://gerrit.openafs.org/12617
Reviewed-by: Benjamin Kaduk <kaduk@mit.edu>
Reviewed-by: Andrew Deason <adeason@sinenomine.net>
Tested-by: BuildBot <buildbot@rampaginggeek.com>
Reviewed-by: Michael Meffie <mmeffie@sinenomine.net>
(cherry picked from commit 8b0e312d043d435f0e55c6dc14f5446ffedc7ce4)

Change-Id: I87425e78fb4f7fb1aa393b2f5b81ab34a71a38c4
Reviewed-on: https://gerrit.openafs.org/13906
Reviewed-by: Michael Meffie <mmeffie@sinenomine.net>
Reviewed-by: Andrew Deason <adeason@sinenomine.net>
Reviewed-by: Cheyenne Wills <cwills@sinenomine.net>
Reviewed-by: Mark Vitale <mvitale@sinenomine.net>
Reviewed-by: Marcio Brito Barbosa <mbarbosa@sinenomine.net>
Tested-by: BuildBot <buildbot@rampaginggeek.com>
Reviewed-by: Stephan Wiesand <stephan.wiesand@desy.de>

diff --git a/src/ubik/beacon.c b/src/ubik/beacon.c
index 7e1cfb65020f04c14359c034e1debce158dc3570..e718c3f3af828aacbb8e7b713bb6eca3cb201949 100644 (file)
--- a/src/ubik/beacon.c
+++ b/src/ubik/beacon.c
@@ -115,7 +115,7 @@ amSyncSite(void)
        now = FT_ApproxTime();
        if (beacon_globals.syncSiteUntil <= now) {      /* if my votes have expired, say so */
            if (beacon_globals.ubik_amSyncSite)
-               ViceLog(5, ("Ubik: I am no longer the sync site\n"));
+               ViceLog(0, ("Ubik: I am no longer the sync site - my votes expired\n"));
            beacon_globals.ubik_amSyncSite = 0;
            beacon_globals.ubik_syncSiteAdvertised = 0;
            rcode = 0;
@@ -410,7 +410,7 @@ ubeacon_InitServerListCommon(afs_uint32 ame, struct afsconf_cell *info,
 
     if (ubik_singleServer) {
        if (!beacon_globals.ubik_amSyncSite) {
-           ViceLog(5, ("Ubik: I am the sync site - 1 server\n"));
+           ViceLog(0, ("Ubik: I am the sync site - 1 server\n"));
            DBHOLD(ubik_dbase);
            UBIK_VERSION_LOCK;
            version_globals.ubik_epochTime = FT_ApproxTime();
@@ -618,7 +618,7 @@ ubeacon_Interact(void *dummy)
        if (yesVotes > nServers) {      /* yesVotes is bumped by 2 or 3 for each site */
            UBIK_BEACON_LOCK;
            if (!beacon_globals.ubik_amSyncSite) {
-               ViceLog(5, ("Ubik: I am the sync site\n"));
+               ViceLog(0, ("Ubik: I am the sync site\n"));
                /* Defer actually changing any variables until we can take the
                 * DB lock (which is before the beacon lock in the lock order). */
                becameSyncSite = 1;
@@ -632,7 +632,7 @@ ubeacon_Interact(void *dummy)
        } else {
            UBIK_BEACON_LOCK;
            if (beacon_globals.ubik_amSyncSite)
-               ViceLog(5, ("Ubik: I am no longer the sync site\n"));
+               ViceLog(0, ("Ubik: I am no longer the sync site - I lost the election\n"));
            beacon_globals.ubik_amSyncSite = 0;
            beacon_globals.ubik_syncSiteAdvertised = 0;
            UBIK_BEACON_UNLOCK;

diff --git a/src/ubik/recovery.c b/src/ubik/recovery.c
index 7ea8e47809bfd7afe20b22b871575f7b2b445341..b351c9662952f63e7e668edbfdb6923b901f1af1 100644 (file)
--- a/src/ubik/recovery.c
+++ b/src/ubik/recovery.c
@@ -605,13 +605,13 @@ urecovery_Interact(void *dummy)
 
            code = StartDISK_GetFile(rxcall, file);
            if (code) {
-               ViceLog(5, ("StartDiskGetFile failed=%d\n", code));
+               ViceLog(0, ("StartDiskGetFile failed=%d\n", code));
                goto FetchEndCall;
            }
            nbytes = rx_Read(rxcall, (char *)&length, sizeof(afs_int32));
            length = ntohl(length);
            if (nbytes != sizeof(afs_int32)) {
-               ViceLog(5, ("Rx-read length error=%d\n", BULK_ERROR));
+               ViceLog(0, ("Rx-read length error=%d\n", BULK_ERROR));
                code = EIO;
                goto FetchEndCall;
            }
@@ -622,7 +622,7 @@ urecovery_Interact(void *dummy)
            code = (*ubik_dbase->setlabel) (ubik_dbase, file, &tversion);
            UBIK_VERSION_UNLOCK;
            if (code) {
-               ViceLog(5, ("setlabel io error=%d\n", code));
+               ViceLog(0, ("setlabel io error=%d\n", code));
                goto FetchEndCall;
            }
            snprintf(pbuffer, sizeof(pbuffer), "%s.DB%s%d.TMP",
@@ -648,7 +648,7 @@ urecovery_Interact(void *dummy)
 #endif
                nbytes = rx_Read(rxcall, tbuffer, tlen);
                if (nbytes != tlen) {
-                   ViceLog(5, ("Rx-read bulk error=%d\n", BULK_ERROR));
+                   ViceLog(0, ("Rx-read bulk error=%d\n", BULK_ERROR));
                    code = EIO;
                    close(fd);
                    goto FetchEndCall;
@@ -798,6 +798,12 @@ urecovery_Interact(void *dummy)
                UBIK_BEACON_LOCK;
                if (!ts->up) {
                    UBIK_BEACON_UNLOCK;
+                   /* It would be nice to have this message at loglevel
+                    * 0 as well, but it will log once every 4s for each
+                    * down server while in this recovery state.  This
+                    * should only be changed to loglevel 0 if it is
+                    * also rate-limited.
+                    */
                    ViceLog(5, ("recovery cannot send version to %s\n",
                                afs_inet_ntoa_r(inAddr.s_addr, hoststr)));
                    dbok = 0;
@@ -821,7 +827,7 @@ urecovery_Interact(void *dummy)
                            StartDISK_SendFile(rxcall, file, length,
                                               &ubik_dbase->version);
                        if (code) {
-                           ViceLog(5, ("StartDiskSendFile failed=%d\n",
+                           ViceLog(0, ("StartDiskSendFile failed=%d\n",
                                        code));
                            goto StoreEndCall;
                        }
@@ -834,13 +840,13 @@ urecovery_Interact(void *dummy)
                                                     tbuffer, offset, tlen);
                            if (nbytes != tlen) {
                                code = UIOERROR;
-                               ViceLog(5, ("Local disk read error=%d\n", code));
+                               ViceLog(0, ("Local disk read error=%d\n", code));
                                goto StoreEndCall;
                            }
                            nbytes = rx_Write(rxcall, tbuffer, tlen);
                            if (nbytes != tlen) {
                                code = BULK_ERROR;
-                               ViceLog(5, ("Rx-write bulk error=%d\n", code));
+                               ViceLog(0, ("Rx-write bulk error=%d\n", code));
                                goto StoreEndCall;
                            }
                            offset += tlen;

diff --git a/src/ubik/remote.c b/src/ubik/remote.c
index 65dc411b8da0c2b0bc11dd14fc9ac3d0f0b14085..c2131abced2205d49c6646d926894bce213b10e6 100644 (file)
--- a/src/ubik/remote.c
+++ b/src/ubik/remote.c
@@ -412,7 +412,7 @@ SDISK_GetFile(struct rx_call *rxcall, afs_int32 file,
     code = rx_Write(rxcall, (char *)&tlen, sizeof(afs_int32));
     if (code != sizeof(afs_int32)) {
        DBRELE(dbase);
-       ViceLog(5, ("Rx-write length error=%d\n", code));
+       ViceLog(0, ("Rx-write length error=%d\n", code));
        return BULK_ERROR;
     }
     offset = 0;
@@ -421,13 +421,13 @@ SDISK_GetFile(struct rx_call *rxcall, afs_int32 file,
        code = (*dbase->read) (dbase, file, tbuffer, offset, tlen);
        if (code != tlen) {
            DBRELE(dbase);
-           ViceLog(5, ("read failed error=%d\n", code));
+           ViceLog(0, ("read failed error=%d\n", code));
            return UIOERROR;
        }
        code = rx_Write(rxcall, tbuffer, tlen);
        if (code != tlen) {
            DBRELE(dbase);
-           ViceLog(5, ("Rx-write length error=%d\n", code));
+           ViceLog(0, ("Rx-write length error=%d\n", code));
            return BULK_ERROR;
        }
        length -= tlen;
@@ -527,7 +527,7 @@ SDISK_SendFile(struct rx_call *rxcall, afs_int32 file,
 #endif
        code = rx_Read(rxcall, tbuffer, tlen);
        if (code != tlen) {
-           ViceLog(5, ("Rx-read length error=%d\n", code));
+           ViceLog(0, ("Rx-read length error=%d\n", code));
            code = BULK_ERROR;
            close(fd);
            goto failed;
@@ -535,7 +535,7 @@ SDISK_SendFile(struct rx_call *rxcall, afs_int32 file,
        code = write(fd, tbuffer, tlen);
        pass++;
        if (code != tlen) {
-           ViceLog(5, ("write failed error=%d\n", code));
+           ViceLog(0, ("write failed tlen=%d, error=%d\n", tlen, code));
            code = UIOERROR;
            close(fd);
            goto failed;

diff --git a/src/ubik/ubik.c b/src/ubik/ubik.c
index af919b36930d76cfa35b7055db3a7d988e10009e..4061d058ccca088bec3360ceae76c7cc1501bf81 100644 (file)
--- a/src/ubik/ubik.c
+++ b/src/ubik/ubik.c
@@ -481,7 +481,7 @@ ubik_ServerInitCommon(afs_uint32 myHost, short myPort,
        rx_NewService(0, VOTE_SERVICE_ID, "VOTE", ubik_sc, numClasses,
                      VOTE_ExecuteRequest);
     if (tservice == (struct rx_service *)0) {
-       ViceLog(5, ("Could not create VOTE rx service!\n"));
+       ViceLog(0, ("Could not create VOTE rx service!\n"));
        return -1;
     }
     rx_SetMinProcs(tservice, 2);
@@ -491,7 +491,7 @@ ubik_ServerInitCommon(afs_uint32 myHost, short myPort,
        rx_NewService(0, DISK_SERVICE_ID, "DISK", ubik_sc, numClasses,
                      DISK_ExecuteRequest);
     if (tservice == (struct rx_service *)0) {
-       ViceLog(5, ("Could not create DISK rx service!\n"));
+       ViceLog(0, ("Could not create DISK rx service!\n"));
        return -1;
     }
     rx_SetMinProcs(tservice, 2);

diff --git a/src/ubik/vote.c b/src/ubik/vote.c
index 3a8374e88fc57766ea1356b15a5222530a25f365..1ae74564359fd8904dc3b0e4fdcf5e7b710c79d9 100644 (file)
--- a/src/ubik/vote.c
+++ b/src/ubik/vote.c
@@ -210,7 +210,7 @@ SVOTE_Beacon(struct rx_call * rxcall, afs_int32 astate,
                break;
        }
        if (!ts)
-           ViceLog(5, ("Unknown host %x has sent a beacon\n", otherHost));
+           ViceLog(0, ("Unknown host %x has sent a beacon\n", otherHost));
        if (ts && ts->isClone)
            isClone = 1;
     } else {
@@ -269,7 +269,7 @@ SVOTE_Beacon(struct rx_call * rxcall, afs_int32 astate,
        vote_globals.syncTime = now;
     } else if (vote_globals.syncTime + BIGTIME < now) {
        if (vote_globals.syncHost) {
-           ViceLog(5, ("Ubik: Lost contact with sync-site %s (NOT in quorum)\n",
+           ViceLog(0, ("Ubik: Lost contact with sync-site %s (NOT in quorum)\n",
                 afs_inet_ntoa_r(vote_globals.syncHost, hoststr)));
        }
        vote_globals.syncHost = 0;
@@ -315,6 +315,9 @@ SVOTE_Beacon(struct rx_call * rxcall, afs_int32 astate,
        if ((vote_globals.ubik_lastYesTime + BIGTIME < now) || (otherHost != vote_globals.lastYesHost)
            || (vote_globals.lastYesState != astate)) {
            /* A new vote or a change in the vote or changed quorum */
+           /* XXX This should be at loglevel 0, but the conditionals
+            * ought to be reworked first to prevent excessive logging.
+            */
            ViceLog(5, ("Ubik: vote 'yes' for %s %s\n",
                        afs_inet_ntoa_r(otherHost, hoststr),
                        (astate ? "(in quorum)" : "(NOT in quorum)")));