From 13e356c4a4a296edea4245fb8850aeba49ae1851 Mon Sep 17 00:00:00 2001 From: Robin Jarry Date: Sun, 4 Jun 2023 21:52:51 +0200 Subject: imap: use named logger Use the worker's logging functions to have all imap related messages prefixed by the account name. Signed-off-by: Robin Jarry Tested-by: Inwit --- worker/imap/cache.go | 42 ++++++++++++++++++++++-------------------- worker/imap/checkmail.go | 5 ++--- worker/imap/connect.go | 4 ++-- worker/imap/fetch.go | 8 ++++---- worker/imap/idler.go | 2 +- worker/imap/list.go | 4 ++-- worker/imap/observer.go | 2 +- worker/imap/open.go | 15 +++++++-------- worker/imap/worker.go | 13 ++++++------- 9 files changed, 47 insertions(+), 48 deletions(-) (limited to 'worker/imap') diff --git a/worker/imap/cache.go b/worker/imap/cache.go index cf372154..449a0d7e 100644 --- a/worker/imap/cache.go +++ b/worker/imap/cache.go @@ -54,35 +54,35 @@ func (w *IMAPWorker) initCacheDb(acct string) { cd, err := cacheDir() if err != nil { w.cache = nil - log.Errorf("unable to find cache directory: %v", err) + w.worker.Errorf("unable to find cache directory: %v", err) return } p := path.Join(cd, acct) db, err := leveldb.OpenFile(p, nil) if err != nil { w.cache = nil - log.Errorf("failed opening cache db: %v", err) + w.worker.Errorf("failed opening cache db: %v", err) return } w.cache = db - log.Debugf("cache db opened: %s", p) + w.worker.Debugf("cache db opened: %s", p) tag, err := w.cache.Get(cacheTagKey, nil) clearCache := errors.Is(err, leveldb.ErrNotFound) || !bytes.Equal(tag, cacheTag) switch { case clearCache: - log.Infof("current cache tag is '%s' but found '%s'", + w.worker.Infof("current cache tag is '%s' but found '%s'", cacheTag, tag) - log.Warnf("tag mismatch: clear cache") + w.worker.Warnf("tag mismatch: clear cache") w.clearCache() if err = w.cache.Put(cacheTagKey, cacheTag, nil); err != nil { - log.Errorf("could not set the current cache tag") + w.worker.Errorf("could not set the current cache tag") } case err != nil: - log.Errorf("could not get the cache tag from db") + w.worker.Errorf("could not get the cache tag from db") default: - log.Tracef("cache version match") + w.worker.Tracef("cache version match") if w.config.cacheMaxAge.Hours() > 0 { go w.cleanCache(p) } @@ -92,11 +92,11 @@ func (w *IMAPWorker) initCacheDb(acct string) { func (w *IMAPWorker) cacheHeader(mi *models.MessageInfo) { uv := fmt.Sprintf("%d", w.selected.UidValidity) uid := fmt.Sprintf("%d", mi.Uid) - log.Debugf("caching header for message %s.%s", uv, uid) + w.worker.Debugf("caching header for message %s.%s", uv, uid) hdr := bytes.NewBuffer(nil) err := textproto.WriteHeader(hdr, mi.RFC822Headers.Header.Header) if err != nil { - log.Errorf("cannot write header %s.%s: %v", uv, uid, err) + w.worker.Errorf("cannot write header %s.%s: %v", uv, uid, err) return } h := &CachedHeader{ @@ -112,18 +112,18 @@ func (w *IMAPWorker) cacheHeader(mi *models.MessageInfo) { enc := gob.NewEncoder(data) err = enc.Encode(h) if err != nil { - log.Errorf("cannot encode message %s.%s: %v", uv, uid, err) + w.worker.Errorf("cannot encode message %s.%s: %v", uv, uid, err) return } err = w.cache.Put([]byte("header."+uv+"."+uid), data.Bytes(), nil) if err != nil { - log.Errorf("cannot write header for message %s.%s: %v", uv, uid, err) + w.worker.Errorf("cannot write header for message %s.%s: %v", uv, uid, err) return } } func (w *IMAPWorker) getCachedHeaders(msg *types.FetchMessageHeaders) []uint32 { - log.Tracef("Retrieving headers from cache: %v", msg.Uids) + w.worker.Tracef("Retrieving headers from cache: %v", msg.Uids) var need []uint32 uv := fmt.Sprintf("%d", w.selected.UidValidity) for _, uid := range msg.Uids { @@ -137,14 +137,14 @@ func (w *IMAPWorker) getCachedHeaders(msg *types.FetchMessageHeaders) []uint32 { dec := gob.NewDecoder(bytes.NewReader(data)) err = dec.Decode(ch) if err != nil { - log.Errorf("cannot decode cached header %s.%s: %v", uv, u, err) + w.worker.Errorf("cannot decode cached header %s.%s: %v", uv, u, err) need = append(need, uid) continue } hr := bytes.NewReader(ch.Header) textprotoHeader, err := textproto.ReadHeader(bufio.NewReader(hr)) if err != nil { - log.Errorf("cannot read cached header %s.%s: %v", uv, u, err) + w.worker.Errorf("cannot read cached header %s.%s: %v", uv, u, err) need = append(need, uid) continue } @@ -159,7 +159,7 @@ func (w *IMAPWorker) getCachedHeaders(msg *types.FetchMessageHeaders) []uint32 { Refs: parse.MsgIDList(hdr, "references"), Size: ch.Size, } - log.Tracef("located cached header %s.%s", uv, u) + w.worker.Tracef("located cached header %s.%s", uv, u) w.worker.PostMessage(&types.MessageInfo{ Message: types.RespondTo(msg), Info: mi, @@ -195,14 +195,16 @@ func (w *IMAPWorker) cleanCache(path string) { dec := gob.NewDecoder(bytes.NewReader(data)) err := dec.Decode(ch) if err != nil { - log.Errorf("cannot clean database %d: %v", w.selected.UidValidity, err) + w.worker.Errorf("cannot clean database %d: %v", + w.selected.UidValidity, err) continue } exp := ch.Created.Add(w.config.cacheMaxAge) if exp.Before(time.Now()) { err = w.cache.Delete(iter.Key(), nil) if err != nil { - log.Errorf("cannot clean database %d: %v", w.selected.UidValidity, err) + w.worker.Errorf("cannot clean database %d: %v", + w.selected.UidValidity, err) continue } removed++ @@ -211,7 +213,7 @@ func (w *IMAPWorker) cleanCache(path string) { } iter.Release() elapsed := time.Since(start) - log.Debugf("%s: removed %d/%d expired entries in %s", + w.worker.Debugf("%s: removed %d/%d expired entries in %s", path, removed, scanned, elapsed) } @@ -220,7 +222,7 @@ func (w *IMAPWorker) clearCache() { iter := w.cache.NewIterator(nil, nil) for iter.Next() { if err := w.cache.Delete(iter.Key(), nil); err != nil { - log.Errorf("error clearing cache: %v", err) + w.worker.Errorf("error clearing cache: %v", err) } } iter.Release() diff --git a/worker/imap/checkmail.go b/worker/imap/checkmail.go index 76da58ad..b457dc4c 100644 --- a/worker/imap/checkmail.go +++ b/worker/imap/checkmail.go @@ -1,7 +1,6 @@ package imap import ( - "git.sr.ht/~rjarry/aerc/log" "git.sr.ht/~rjarry/aerc/models" "git.sr.ht/~rjarry/aerc/worker/types" "github.com/emersion/go-imap" @@ -21,7 +20,7 @@ func (w *IMAPWorker) handleCheckMailMessage(msg *types.CheckMail) { ) switch { case w.liststatus: - log.Tracef("Checking mail with LIST-STATUS") + w.worker.Tracef("Checking mail with LIST-STATUS") statuses, err = w.client.liststatus.ListStatus("", "*", items, nil) if err != nil { w.worker.PostMessage(&types.Error{ @@ -36,7 +35,7 @@ func (w *IMAPWorker) handleCheckMailMessage(msg *types.CheckMail) { remaining = append(remaining, dir) continue } - log.Tracef("Getting status of directory %s", dir) + w.worker.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/connect.go b/worker/imap/connect.go index f0ed8043..84d69fe5 100644 --- a/worker/imap/connect.go +++ b/worker/imap/connect.go @@ -178,12 +178,12 @@ func (w *IMAPWorker) setKeepaliveParameters(conn *net.TCPConn) error { // Max number of probes before failure err := lib.SetTcpKeepaliveProbes(fd, w.config.keepalive_probes) if err != nil { - log.Errorf("cannot set tcp keepalive probes: %v", err) + w.worker.Errorf("cannot set tcp keepalive probes: %v", err) } // Wait time after an unsuccessful probe err = lib.SetTcpKeepaliveInterval(fd, w.config.keepalive_interval) if err != nil { - log.Errorf("cannot set tcp keepalive interval: %v", err) + w.worker.Errorf("cannot set tcp keepalive interval: %v", err) } }) return err diff --git a/worker/imap/fetch.go b/worker/imap/fetch.go index 8189e6aa..74108135 100644 --- a/worker/imap/fetch.go +++ b/worker/imap/fetch.go @@ -28,7 +28,7 @@ func (imapw *IMAPWorker) handleFetchMessageHeaders( nil) return } - log.Tracef("Fetching message headers: %v", toFetch) + imapw.worker.Tracef("Fetching message headers: %v", toFetch) hdrBodyPart := imap.BodyPartName{ Specifier: imap.HeaderSpecifier, } @@ -92,7 +92,7 @@ func (imapw *IMAPWorker) handleFetchMessageHeaders( func (imapw *IMAPWorker) handleFetchMessageBodyPart( msg *types.FetchMessageBodyPart, ) { - log.Tracef("Fetching message %d part: %v", msg.Uid, msg.Part) + imapw.worker.Tracef("Fetching message %d part: %v", msg.Uid, msg.Part) var partHeaderSection imap.BodySectionName partHeaderSection.Peek = true @@ -138,7 +138,7 @@ func (imapw *IMAPWorker) handleFetchMessageBodyPart( part, err := message.New(message.Header{Header: h}, _msg.GetBody(&partBodySection)) if message.IsUnknownCharset(err) { - log.Warnf("unknown charset encountered "+ + imapw.worker.Warnf("unknown charset encountered "+ "for uid %d", _msg.Uid) } else if err != nil { return fmt.Errorf("failed to create message reader: %w", err) @@ -166,7 +166,7 @@ func (imapw *IMAPWorker) handleFetchMessageBodyPart( func (imapw *IMAPWorker) handleFetchFullMessages( msg *types.FetchFullMessages, ) { - log.Tracef("Fetching full messages: %v", msg.Uids) + imapw.worker.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 d099ee88..e58cc6b9 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...) - log.Tracef("idler (%p) [idle:%t,wait:%t] %s", i, i.isIdleing(), i.isWaiting(), msg) + i.worker.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 7a8fc17c..a3469c72 100644 --- a/worker/imap/list.go +++ b/worker/imap/list.go @@ -12,7 +12,7 @@ import ( func (imapw *IMAPWorker) handleListDirectories(msg *types.ListDirectories) { mailboxes := make(chan *imap.MailboxInfo) - log.Tracef("Listing mailboxes") + imapw.worker.Tracef("Listing mailboxes") done := make(chan interface{}) go func() { @@ -114,7 +114,7 @@ func (imapw *IMAPWorker) handleSearchDirectory(msg *types.SearchDirectory) { }, nil) } - log.Tracef("Executing search") + imapw.worker.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 9ad311dd..8bc07c93 100644 --- a/worker/imap/observer.go +++ b/worker/imap/observer.go @@ -152,5 +152,5 @@ func (o *observer) emit(errMsg string) { func (o *observer) log(format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - log.Tracef("observer (%p) [running:%t] %s", o, o.running, msg) + o.worker.Tracef("observer (%p) [running:%t] %s", o, o.running, msg) } diff --git a/worker/imap/open.go b/worker/imap/open.go index ced307be..21953932 100644 --- a/worker/imap/open.go +++ b/worker/imap/open.go @@ -5,12 +5,11 @@ import ( sortthread "github.com/emersion/go-imap-sortthread" - "git.sr.ht/~rjarry/aerc/log" "git.sr.ht/~rjarry/aerc/worker/types" ) func (imapw *IMAPWorker) handleOpenDirectory(msg *types.OpenDirectory) { - log.Debugf("Opening %s", msg.Directory) + imapw.worker.Debugf("Opening %s", msg.Directory) sel, err := imapw.client.Select(msg.Directory, false) if err != nil { @@ -27,7 +26,7 @@ func (imapw *IMAPWorker) handleOpenDirectory(msg *types.OpenDirectory) { func (imapw *IMAPWorker) handleFetchDirectoryContents( msg *types.FetchDirectoryContents, ) { - log.Tracef("Fetching UID list") + imapw.worker.Tracef("Fetching UID list") searchCriteria, err := parseSearch(msg.FilterCriteria) if err != nil { @@ -52,9 +51,9 @@ func (imapw *IMAPWorker) handleFetchDirectoryContents( } else { if err != nil { // Non fatal, but we do want to print to get some debug info - log.Errorf("can't check for SORT support: %v", err) + imapw.worker.Errorf("can't check for SORT support: %v", err) } else if len(sortCriteria) > 0 { - log.Warnf("SORT is not supported but requested: list messages by UID") + imapw.worker.Warnf("SORT is not supported but requested: list messages by UID") } uids, err = imapw.client.UidSearch(searchCriteria) } @@ -64,7 +63,7 @@ func (imapw *IMAPWorker) handleFetchDirectoryContents( Error: err, }, nil) } else { - log.Tracef("Found %d UIDs", len(uids)) + imapw.worker.Tracef("Found %d UIDs", len(uids)) if len(msg.FilterCriteria) == 1 { // Only initialize if we are not filtering imapw.seqMap.Initialize(uids) @@ -105,7 +104,7 @@ func translateSortCriterions( func (imapw *IMAPWorker) handleDirectoryThreaded( msg *types.FetchDirectoryThreaded, ) { - log.Tracef("Fetching threaded UID list") + imapw.worker.Tracef("Fetching threaded UID list") searchCriteria, err := parseSearch(msg.FilterCriteria) if err != nil { @@ -125,7 +124,7 @@ func (imapw *IMAPWorker) handleDirectoryThreaded( } else { aercThreads, count := convertThreads(threads, nil) sort.Sort(types.ByUID(aercThreads)) - log.Tracef("Found %d threaded messages", count) + imapw.worker.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 f46f39d6..dc1891ca 100644 --- a/worker/imap/worker.go +++ b/worker/imap/worker.go @@ -12,7 +12,6 @@ import ( "github.com/syndtr/goleveldb/leveldb" "git.sr.ht/~rjarry/aerc/lib" - "git.sr.ht/~rjarry/aerc/log" "git.sr.ht/~rjarry/aerc/models" "git.sr.ht/~rjarry/aerc/worker/handlers" "git.sr.ht/~rjarry/aerc/worker/imap/extensions" @@ -104,21 +103,21 @@ func (w *IMAPWorker) newClient(c *client.Client) { sort, err := w.client.sort.SupportSort() if err == nil && sort { w.caps.Sort = true - log.Debugf("Server Capability found: Sort") + w.worker.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 - log.Debugf("Server Capability found: Thread (algorithm: %s)", string(alg)) + w.worker.Debugf("Server Capability found: Thread (algorithm: %s)", string(alg)) break } } lStatus, err := w.client.liststatus.SupportListStatus() if err == nil && lStatus { w.liststatus = true - log.Debugf("Server Capability found: LIST-STATUS") + w.worker.Debugf("Server Capability found: LIST-STATUS") } } @@ -249,7 +248,7 @@ func (w *IMAPWorker) handleMessage(msg types.WorkerMessage) error { } func (w *IMAPWorker) handleImapUpdate(update client.Update) { - log.Tracef("(= %T", update) + w.worker.Tracef("(= %T", update) switch update := update.(type) { case *client.MailboxUpdate: w.worker.PostAction(&types.CheckMail{ @@ -259,7 +258,7 @@ func (w *IMAPWorker) handleImapUpdate(update client.Update) { msg := update.Message if msg.Uid == 0 { if uid, found := w.seqMap.Get(msg.SeqNum); !found { - log.Errorf("MessageUpdate unknown seqnum: %d", msg.SeqNum) + w.worker.Errorf("MessageUpdate unknown seqnum: %d", msg.SeqNum) return } else { msg.Uid = uid @@ -279,7 +278,7 @@ func (w *IMAPWorker) handleImapUpdate(update client.Update) { }, nil) case *client.ExpungeUpdate: if uid, found := w.seqMap.Pop(update.SeqNum); !found { - log.Errorf("ExpungeUpdate unknown seqnum: %d", update.SeqNum) + w.worker.Errorf("ExpungeUpdate unknown seqnum: %d", update.SeqNum) } else { w.worker.PostMessage(&types.MessagesDeleted{ Uids: []uint32{uid}, -- cgit