lint: enable go vet printf format arg checks for logging (algorand#4679)

* lint: enable go vet printf format arg checks for logging

* add more printf functions

* run gofmt and govet on test code

.golangci.yml

@@ -33,6 +33,41 @@ linters-settings:
     - (*github.com/algorand/go-algorand/data/transactions/logic.OpStream).error
     - (*github.com/algorand/go-algorand/data/transactions/logic.OpStream).warnf
     - (*github.com/algorand/go-algorand/data/transactions/logic.OpStream).warn
+  govet:
+    settings:
+      printf:
+        # Comma-separated list of print function names to check (in addition to default, see `go tool vet help printf`).
+        # Default: []
+        funcs:
+          - (github.com/algorand/go-algorand/logging.Logger).Debugf
+          - (github.com/algorand/go-algorand/logging.Logger).Infof
+          - (github.com/algorand/go-algorand/logging.Logger).Warnf
+          - (github.com/algorand/go-algorand/logging.Logger).Errorf
+          - (github.com/algorand/go-algorand/logging.Logger).Fatalf
+          - (github.com/algorand/go-algorand/logging.Logger).Panicf
+          - (github.com/algorand/go-algorand/logging.Logger).Debugln
+          - (github.com/algorand/go-algorand/logging.Logger).Infoln
+          - (github.com/algorand/go-algorand/logging.Logger).Warnln
+          - (github.com/algorand/go-algorand/logging.Logger).Errorln
+          - (github.com/algorand/go-algorand/logging.Logger).Fatalln
+          - (github.com/algorand/go-algorand/logging.Logger).Panicln
+          - (github.com/algorand/go-algorand/logging.Logger).Debug
+          - (github.com/algorand/go-algorand/logging.Logger).Info
+          - (github.com/algorand/go-algorand/logging.Logger).Warn
+          - (github.com/algorand/go-algorand/logging.Logger).Error
+          - (github.com/algorand/go-algorand/logging.Logger).Fatal
+          - (github.com/algorand/go-algorand/logging.Logger).Panic
+          - (github.com/algorand/go-algorand/data/transactions/logic.OpStream).warnf
+          - (github.com/algorand/go-algorand/data/transactions/logic.OpStream).errorf
+          - (github.com/algorand/go-algorand/data/transactions/logic.OpStream).lineErrorf
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportInfof
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportInfoln
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportWarnf
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportWarnln
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportWarnRawf
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportWarnRawln
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportErrorf
+          - (github.com/algorand/go-algorand/cmd/goal/main).reportErrorln
 
 issues:
   # Work our way back over time to be clean against all these
@@ -69,9 +104,9 @@ issues:
     - path: _test\.go
       linters:
         - errcheck
-        - gofmt
+        # - gofmt
         - gosimple
-        - govet
+        # - govet
         - ineffassign
         - misspell
         - nolintlint

agreement/cadaver.go

@@ -123,7 +123,7 @@ func (c *cadaver) trySetup() bool {
 	if c.out.bytesWritten >= c.fileSizeTarget {
 		err := c.out.Close()
 		if err != nil {
-			logging.Base().Warn("unable to close cadaver file : %v", err)
+			logging.Base().Warnf("unable to close cadaver file : %v", err)
 		}
 		err = os.Rename(c.filename(), c.filename()+".archive")
 		if err != nil {

daemon/algod/api/server/v2/handlers.go

@@ -362,7 +362,7 @@ func (v2 *Handlers) AccountInformation(ctx echo.Context, address string, params
 		}
 		totalResults := record.TotalAssets + record.TotalAssetParams + record.TotalAppLocalStates + record.TotalAppParams
 		if totalResults > maxResults {
-			v2.Log.Info("MaxAccountAPIResults limit %d exceeded, total results %d", maxResults, totalResults)
+			v2.Log.Infof("MaxAccountAPIResults limit %d exceeded, total results %d", maxResults, totalResults)
 			extraData := map[string]interface{}{
 				"max-results":           maxResults,
 				"total-assets-opted-in": record.TotalAssets,

data/account/participationRegistry.go

@@ -1015,7 +1015,7 @@ func (db *participationDB) Flush(timeout time.Duration) error {
 // Close attempts to flush with db.flushTimeout, then waits for the write queue for another db.flushTimeout.
 func (db *participationDB) Close() {
 	if err := db.Flush(db.flushTimeout); err != nil {
-		db.log.Warnf("participationDB unhandled error during Close/Flush: %w", err)
+		db.log.Warnf("participationDB unhandled error during Close/Flush: %v", err)
 	}
 
 	db.store.Close()

data/account/registeryDbOps.go

@@ -85,7 +85,7 @@ func (d deleteStateProofKeysOp) apply(db *participationDB) error {
 	})
 
 	if err != nil {
-		db.log.Warnf("participationDB unable to delete stateProof key: %w", err)
+		db.log.Warnf("participationDB unable to delete stateProof key: %v", err)
 	}
 	return err
 }

data/accountManager.go

@@ -67,7 +67,7 @@ func (manager *AccountManager) Keys(rnd basics.Round) (out []account.Participati
 		if part.OverlapsInterval(rnd, rnd) {
 			partRndSecrets, err := manager.registry.GetForRound(part.ParticipationID, rnd)
 			if err != nil {
-				manager.log.Warnf("error while loading round secrets from participation registry: %w", err)
+				manager.log.Warnf("error while loading round secrets from participation registry: %v", err)
 				continue
 			}
 			out = append(out, partRndSecrets)
@@ -198,7 +198,7 @@ func (manager *AccountManager) DeleteOldKeys(latestHdr bookkeeping.BlockHeader,
 
 	// Delete expired records from participation registry.
 	if err := manager.registry.DeleteExpired(latestHdr.Round, agreementProto); err != nil {
-		manager.log.Warnf("error while deleting expired records from participation registry: %w", err)
+		manager.log.Warnf("error while deleting expired records from participation registry: %v", err)
 	}
 }
 
@@ -212,6 +212,6 @@ func (manager *AccountManager) Record(account basics.Address, round basics.Round
 	// This function updates a cache in the ParticipationRegistry, we must call Flush to persist the changes.
 	err := manager.registry.Record(account, round, participationType)
 	if err != nil {
-		manager.log.Warnf("node.Record: Account %v not able to record participation (%d) on round %d: %w", account, participationType, round, err)
+		manager.log.Warnf("node.Record: Account %v not able to record participation (%d) on round %d: %v", account, participationType, round, err)
 	}
 }

data/transactions/logic/eval.go

@@ -709,7 +709,7 @@ func eval(program []byte, cx *EvalContext) (pass bool, err error) {
 				errstr += cx.Trace.String()
 			}
 			err = PanicError{x, errstr}
-			cx.EvalParams.log().Errorf("recovered panic in Eval: %w", err)
+			cx.EvalParams.log().Errorf("recovered panic in Eval: %v", err)
 		}
 	}()
 

ledger/acctonline.go

@@ -523,7 +523,7 @@ func (ao *onlineAccounts) onlineTotalsEx(rnd basics.Round) (basics.MicroAlgos, e
 
 	var roundOffsetError *RoundOffsetError
 	if !errors.As(err, &roundOffsetError) {
-		ao.log.Errorf("onlineTotalsImpl error:  %w", err)
+		ao.log.Errorf("onlineTotalsImpl error: %v", err)
 	}
 
 	totalsOnline, err = ao.accountsq.lookupOnlineTotalsHistory(rnd)

ledger/tracker.go

@@ -439,7 +439,7 @@ func (tr *trackerRegistry) commitSyncer(deferredCommits chan *deferredCommitCont
 			}
 			err := tr.commitRound(commit)
 			if err != nil {
-				tr.log.Warnf("Could not commit round: %w", err)
+				tr.log.Warnf("Could not commit round: %v", err)
 			}
 		case <-tr.ctx.Done():
 			// drain the pending commits queue:

network/wsNetwork.go

@@ -1058,7 +1058,7 @@ func (wn *WebsocketNetwork) checkIncomingConnectionVariables(response http.Respo
 		response.WriteHeader(http.StatusPreconditionFailed)
 		n, err := response.Write([]byte("mismatching genesis ID"))
 		if err != nil {
-			wn.log.Warnf("ws failed to write mismatching genesis ID response '%s' : n = %d err = %v", n, err)
+			wn.log.Warnf("ws failed to write mismatching genesis ID response '%s' : n = %d err = %v", otherGenesisID, n, err)
 		}
 		return http.StatusPreconditionFailed
 	}

network/wsPeer.go

@@ -515,7 +515,7 @@ func (wp *wsPeer) readLoop() {
 			case channel <- &Response{Topics: topics}:
 				// do nothing. writing was successful.
 			default:
-				wp.net.log.Warnf("wsPeer readLoop: channel blocked. Could not pass the response to the requester", wp.conn.RemoteAddr().String())
+				wp.net.log.Warn("wsPeer readLoop: channel blocked. Could not pass the response to the requester", wp.conn.RemoteAddr().String())
 			}
 			continue
 		case protocol.MsgDigestSkipTag:

node/node.go

@@ -941,7 +941,7 @@ func (node *AlgorandFullNode) loadParticipationKeys() error {
 				renamedFileName := filepath.Join(fullname, ".old")
 				err = os.Rename(fullname, renamedFileName)
 				if err != nil {
-					node.log.Warn("loadParticipationKeys: failed to rename unsupported participation key file '%s' to '%s': %v", fullname, renamedFileName, err)
+					node.log.Warnf("loadParticipationKeys: failed to rename unsupported participation key file '%s' to '%s': %v", fullname, renamedFileName, err)
 				}
 			} else {
 				return fmt.Errorf("AlgorandFullNode.loadParticipationKeys: cannot load account at %v: %v", info.Name(), err)
@@ -1070,7 +1070,7 @@ func (node *AlgorandFullNode) oldKeyDeletionThread(done <-chan struct{}) {
 		// Persist participation registry updates to last-used round and voting key changes.
 		err = node.accountManager.Registry().Flush(participationRegistryFlushMaxWaitDuration)
 		if err != nil {
-			node.log.Warnf("error while flushing the registry: %w", err)
+			node.log.Warnf("error while flushing the registry: %v", err)
 		}
 	}
 }

rpcs/txService.go

@@ -143,7 +143,7 @@ func (txs *TxService) ServeHTTP(response http.ResponseWriter, request *http.Requ
 	response.WriteHeader(http.StatusOK)
 	_, err = response.Write(txblob)
 	if err != nil {
-		txs.log.Warnf("http block write failed ", err)
+		txs.log.Warn("http block write failed", err)
 	}
 }
 

stateproof/builder.go

@@ -98,7 +98,7 @@ func (spw *Worker) initBuilders() {
 		return
 	})
 	if err != nil {
-		spw.log.Warnf("initBuilders: getPendingSigs: %w", err)
+		spw.log.Warnf("initBuilders: getPendingSigs: %v", err)
 		return
 	}
 
@@ -128,7 +128,7 @@ func (spw *Worker) addSigsToBuilder(sigs []pendingSig, rnd basics.Round) {
 
 		isPresent, err := builderForRound.Present(pos)
 		if err != nil {
-			spw.log.Warnf("addSigsToBuilder: failed to invoke builderForRound.Present on pos %d - %w ", pos, err)
+			spw.log.Warnf("addSigsToBuilder: failed to invoke builderForRound.Present on pos %d - %v", pos, err)
 			continue
 		}
 		if isPresent {
@@ -141,7 +141,7 @@ func (spw *Worker) addSigsToBuilder(sigs []pendingSig, rnd basics.Round) {
 			continue
 		}
 		if err := builderForRound.Add(pos, sig.sig); err != nil {
-			spw.log.Warnf("addSigsToBuilder: error while adding sig. inner error: %w", err)
+			spw.log.Warnf("addSigsToBuilder: error while adding sig. inner error: %v", err)
 			continue
 		}
 	}
@@ -407,7 +407,7 @@ func (spw *Worker) tryBroadcast() {
 
 		sp, err := b.Build()
 		if err != nil {
-			spw.log.Warnf("spw.tryBroadcast: building state proof for %d failed: %w", rnd, err)
+			spw.log.Warnf("spw.tryBroadcast: building state proof for %d failed: %v", rnd, err)
 			continue
 		}
 

test/commandandcontrol/cc_agent/main.go

@@ -120,7 +120,7 @@ func main() {
 
 	serverWs, _, err := websocket.DefaultDialer.Dial(u.String(), nil)
 	if err != nil {
-		log.Errorf("dial:", err)
+		log.Error("dial:", err)
 	}
 	serverWs.Unsafe = true
 	defer func() {
@@ -168,7 +168,7 @@ func main() {
 		case t := <-ticker.C:
 			err := serverWs.WriteMessage(websocket.TextMessage, []byte(fmt.Sprintf("heartbeat from agent %s with time %s", component.GetHostAgent().Host.Name, t.String())))
 			if err != nil {
-				log.Errorf("write:", err)
+				log.Error("write:", err)
 				return
 			}
 		case <-interrupt:
@@ -177,7 +177,7 @@ func main() {
 			// waiting (with timeout) for the server to close the connection.
 			err := serverWs.WriteMessage(websocket.CloseMessage, websocket.FormatCloseMessage(websocket.CloseNormalClosure, ""))
 			if err != nil {
-				log.Errorf("write close:", err)
+				log.Error("write close:", err)
 				return
 			}
 			select {

test/commandandcontrol/cc_client/main.go

@@ -129,7 +129,7 @@ func main() {
 func closeServiceConnection(serverWs *websocket.Conn) {
 	err := serverWs.WriteMessage(websocket.CloseMessage, websocket.FormatCloseMessage(websocket.CloseNormalClosure, ""))
 	if err != nil {
-		log.Errorf("write close:", err)
+		log.Error("write close:", err)
 		return
 	}
 }

test/commandandcontrol/cc_service/main.go

@@ -56,7 +56,7 @@ func main() {
 func handleClientConnections(w http.ResponseWriter, r *http.Request) {
 	ws, err := upgrader.Upgrade(w, r, nil)
 	if err != nil {
-		log.Errorf("upgrade:", err)
+		log.Error("upgrade:", err)
 		return
 	}
 	ws.Unsafe = true
@@ -72,7 +72,7 @@ func handleAgentConnections(w http.ResponseWriter, r *http.Request) {
 	// Upgrade initial GET request to a websocket
 	ws, err := upgrader.Upgrade(w, r, nil)
 	if err != nil {
-		log.Errorf("problem initializing agent web socket", err)
+		log.Error("problem initializing agent web socket", err)
 		return
 	}
 	ws.Unsafe = true