logging: homogenize levels

The main goal is to ensure that by default, the log file (if configured)
does not grow out of proportions. Most of the logging messages in aerc
are actually for debugging and/or trace purposes.

Define clear rules for logging levels. Enforce these rules everywhere.

After this patch, here is what the log file looks like after starting up
with a single account:

INFO  2022/11/24 20:26:16.147164 aerc.go:176: Starting up version 0.13.0-100-g683981479c60 (go1.18.7 amd64 linux)
INFO  2022/11/24 20:26:17.546448 account.go:254: [work] connected.

Signed-off-by: Robin Jarry <robin@jarry.cc>
Tested-by: Bence Ferdinandy <bence@ferdinandy.com>
Acked-by: Tim Culverhouse <tim@timculverhouse.com>

8 files changed, 23 insertions, 22 deletions

diff --git a/worker/imap/cache.go b/worker/imap/cache.go
index c32131d3..cf92dfaa 100644
--- a/worker/imap/cache.go
+++ b/worker/imap/cache.go
@@ -45,9 +45,9 @@ func (w *IMAPWorker) initCacheDb(acct string) {
 		return
 	}
 	w.cache = db
-	logging.Infof("cache db opened: %s", p)
+	logging.Debugf("cache db opened: %s", p)
 	if w.config.cacheMaxAge.Hours() > 0 {
-		go w.cleanCache()
+		go w.cleanCache(p)
 	}
 }
 
@@ -84,7 +84,7 @@ func (w *IMAPWorker) cacheHeader(mi *models.MessageInfo) {
 }
 
 func (w *IMAPWorker) getCachedHeaders(msg *types.FetchMessageHeaders) []uint32 {
-	logging.Debugf("Retrieving headers from cache: %v", msg.Uids)
+	logging.Tracef("Retrieving headers from cache: %v", msg.Uids)
 	var need []uint32
 	uv := fmt.Sprintf("%d", w.selected.UidValidity)
 	for _, uid := range msg.Uids {
@@ -122,7 +122,7 @@ func (w *IMAPWorker) getCachedHeaders(msg *types.FetchMessageHeaders) []uint32 {
 		if err != nil {
 			mi.Refs = refs
 		}
-		logging.Debugf("located cached header %s.%s", uv, u)
+		logging.Tracef("located cached header %s.%s", uv, u)
 		w.worker.PostMessage(&types.MessageInfo{
 			Message:    types.RespondTo(msg),
 			Info:       mi,
@@ -144,7 +144,7 @@ func cacheDir() (string, error) {
 }
 
 // cleanCache removes stale entries from the selected mailbox cachedb
-func (w *IMAPWorker) cleanCache() {
+func (w *IMAPWorker) cleanCache(path string) {
 	start := time.Now()
 	var scanned, removed int
 	iter := w.cache.NewIterator(nil, nil)
@@ -170,5 +170,6 @@ func (w *IMAPWorker) cleanCache() {
 	}
 	iter.Release()
 	elapsed := time.Since(start)
-	logging.Infof("cleaned cache, removed %d of %d entries in %s", removed, scanned, elapsed)
+	logging.Debugf("%s: removed %d/%d expired entries in %s",
+		path, removed, scanned, elapsed)
 }
diff --git a/worker/imap/checkmail.go b/worker/imap/checkmail.go
index e0aef71b..0f347e09 100644
--- a/worker/imap/checkmail.go
+++ b/worker/imap/checkmail.go
@@ -20,7 +20,7 @@ func (w *IMAPWorker) handleCheckMailMessage(msg *types.CheckMail) {
 			continue
 		}
 
-		logging.Debugf("Getting status of directory %s", dir)
+		logging.Tracef("Getting status of directory %s", dir)
 		status, err := w.client.Status(dir, items)
 		if err != nil {
 			w.worker.PostMessage(&types.Error{
diff --git a/worker/imap/fetch.go b/worker/imap/fetch.go
index f5407087..9256c6eb 100644
--- a/worker/imap/fetch.go
+++ b/worker/imap/fetch.go
@@ -27,7 +27,7 @@ func (imapw *IMAPWorker) handleFetchMessageHeaders(
 			nil)
 		return
 	}
-	logging.Infof("Fetching message headers: %v", toFetch)
+	logging.Tracef("Fetching message headers: %v", toFetch)
 	section := &imap.BodySectionName{
 		BodyPartName: imap.BodyPartName{
 			Specifier: imap.HeaderSpecifier,
@@ -84,7 +84,7 @@ func (imapw *IMAPWorker) handleFetchMessageHeaders(
 func (imapw *IMAPWorker) handleFetchMessageBodyPart(
 	msg *types.FetchMessageBodyPart,
 ) {
-	logging.Infof("Fetching message %d part: %v", msg.Uid, msg.Part)
+	logging.Tracef("Fetching message %d part: %v", msg.Uid, msg.Part)
 
 	var partHeaderSection imap.BodySectionName
 	partHeaderSection.Peek = true
@@ -158,7 +158,7 @@ func (imapw *IMAPWorker) handleFetchMessageBodyPart(
 func (imapw *IMAPWorker) handleFetchFullMessages(
 	msg *types.FetchFullMessages,
 ) {
-	logging.Infof("Fetching full messages: %v", msg.Uids)
+	logging.Tracef("Fetching full messages: %v", msg.Uids)
 	section := &imap.BodySectionName{
 		Peek: true,
 	}
diff --git a/worker/imap/idler.go b/worker/imap/idler.go
index 65ba6b9b..da018334 100644
--- a/worker/imap/idler.go
+++ b/worker/imap/idler.go
@@ -166,5 +166,5 @@ func (i *idler) waitOnIdle() {
 
 func (i *idler) log(format string, v ...interface{}) {
 	msg := fmt.Sprintf(format, v...)
-	logging.Debugf("idler (%p) [idle:%t,wait:%t] %s", i, i.isIdleing(), i.isWaiting(), msg)
+	logging.Tracef("idler (%p) [idle:%t,wait:%t] %s", i, i.isIdleing(), i.isWaiting(), msg)
 }
diff --git a/worker/imap/list.go b/worker/imap/list.go
index 67d4c33d..c3211f21 100644
--- a/worker/imap/list.go
+++ b/worker/imap/list.go
@@ -10,7 +10,7 @@ import (
 
 func (imapw *IMAPWorker) handleListDirectories(msg *types.ListDirectories) {
 	mailboxes := make(chan *imap.MailboxInfo)
-	logging.Infof("Listing mailboxes")
+	logging.Tracef("Listing mailboxes")
 	done := make(chan interface{})
 
 	go func() {
@@ -62,7 +62,7 @@ func (imapw *IMAPWorker) handleSearchDirectory(msg *types.SearchDirectory) {
 		}, nil)
 	}
 
-	logging.Infof("Executing search")
+	logging.Tracef("Executing search")
 	criteria, err := parseSearch(msg.Argv)
 	if err != nil {
 		emitError(err)
diff --git a/worker/imap/observer.go b/worker/imap/observer.go
index 866fac62..867b57d9 100644
--- a/worker/imap/observer.go
+++ b/worker/imap/observer.go
@@ -150,5 +150,5 @@ func (o *observer) emit(errMsg string) {
 
 func (o *observer) log(format string, args ...interface{}) {
 	msg := fmt.Sprintf(format, args...)
-	logging.Debugf("observer (%p) [running:%t] %s", o, o.running, msg)
+	logging.Tracef("observer (%p) [running:%t] %s", o, o.running, msg)
 }
diff --git a/worker/imap/open.go b/worker/imap/open.go
index f3f20a59..f554d524 100644
--- a/worker/imap/open.go
+++ b/worker/imap/open.go
@@ -10,7 +10,7 @@ import (
 )
 
 func (imapw *IMAPWorker) handleOpenDirectory(msg *types.OpenDirectory) {
-	logging.Infof("Opening %s", msg.Directory)
+	logging.Debugf("Opening %s", msg.Directory)
 
 	sel, err := imapw.client.Select(msg.Directory, false)
 	if err != nil {
@@ -27,7 +27,7 @@ func (imapw *IMAPWorker) handleOpenDirectory(msg *types.OpenDirectory) {
 func (imapw *IMAPWorker) handleFetchDirectoryContents(
 	msg *types.FetchDirectoryContents,
 ) {
-	logging.Infof("Fetching UID list")
+	logging.Tracef("Fetching UID list")
 
 	searchCriteria, err := parseSearch(msg.FilterCriteria)
 	if err != nil {
@@ -64,7 +64,7 @@ func (imapw *IMAPWorker) handleFetchDirectoryContents(
 			Error:   err,
 		}, nil)
 	} else {
-		logging.Infof("Found %d UIDs", len(uids))
+		logging.Tracef("Found %d UIDs", len(uids))
 		if len(msg.FilterCriteria) == 1 {
 			// Only initialize if we are not filtering
 			imapw.seqMap.Initialize(uids)
@@ -105,7 +105,7 @@ func translateSortCriterions(
 func (imapw *IMAPWorker) handleDirectoryThreaded(
 	msg *types.FetchDirectoryThreaded,
 ) {
-	logging.Infof("Fetching threaded UID list")
+	logging.Tracef("Fetching threaded UID list")
 
 	searchCriteria, err := parseSearch(msg.FilterCriteria)
 	if err != nil {
@@ -125,7 +125,7 @@ func (imapw *IMAPWorker) handleDirectoryThreaded(
 	} else {
 		aercThreads, count := convertThreads(threads, nil)
 		sort.Sort(types.ByUID(aercThreads))
-		logging.Infof("Found %d threaded messages", count)
+		logging.Tracef("Found %d threaded messages", count)
 		if len(msg.FilterCriteria) == 1 {
 			// Only initialize if we are not filtering
 			var uids []uint32
diff --git a/worker/imap/worker.go b/worker/imap/worker.go
index 506eb182..c3021f91 100644
--- a/worker/imap/worker.go
+++ b/worker/imap/worker.go
@@ -93,14 +93,14 @@ func (w *IMAPWorker) newClient(c *client.Client) {
 	sort, err := w.client.sort.SupportSort()
 	if err == nil && sort {
 		w.caps.Sort = true
-		logging.Infof("Server Capability found: Sort")
+		logging.Debugf("Server Capability found: Sort")
 	}
 	for _, alg := range []sortthread.ThreadAlgorithm{sortthread.References, sortthread.OrderedSubject} {
 		ok, err := w.client.Support(fmt.Sprintf("THREAD=%s", string(alg)))
 		if err == nil && ok {
 			w.threadAlgorithm = alg
 			w.caps.Thread = true
-			logging.Infof("Server Capability found: Thread (algorithm: %s)", string(alg))
+			logging.Debugf("Server Capability found: Thread (algorithm: %s)", string(alg))
 			break
 		}
 	}
@@ -233,7 +233,7 @@ func (w *IMAPWorker) handleMessage(msg types.WorkerMessage) error {
 }
 
 func (w *IMAPWorker) handleImapUpdate(update client.Update) {
-	logging.Debugf("(= %T", update)
+	logging.Tracef("(= %T", update)
 	switch update := update.(type) {
 	case *client.MailboxUpdate:
 		status := update.Mailbox