From: Mark Vitale Date: Tue, 9 May 2017 01:11:27 +0000 (-0400) Subject: ubik: log important messages at default log level X-Git-Tag: upstream/1.8.6_pre1^2~19 X-Git-Url: https://git.michaelhowe.org/gitweb/?a=commitdiff_plain;h=584e3e5da080c185466f86d549776487d0e81559;p=packages%2Fo%2Fopenafs.git 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 Reviewed-by: Andrew Deason Tested-by: BuildBot Reviewed-by: Michael Meffie (cherry picked from commit 8b0e312d043d435f0e55c6dc14f5446ffedc7ce4) Change-Id: I87425e78fb4f7fb1aa393b2f5b81ab34a71a38c4 Reviewed-on: https://gerrit.openafs.org/13906 Reviewed-by: Michael Meffie Reviewed-by: Andrew Deason Reviewed-by: Cheyenne Wills Reviewed-by: Mark Vitale Reviewed-by: Marcio Brito Barbosa Tested-by: BuildBot Reviewed-by: Stephan Wiesand --- diff --git a/src/ubik/beacon.c b/src/ubik/beacon.c index 7e1cfb650..e718c3f3a 100644 --- 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 7ea8e4780..b351c9662 100644 --- 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 65dc411b8..c2131abce 100644 --- 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 af919b369..4061d058c 100644 --- 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 3a8374e88..1ae745643 100644 --- 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)")));