diff --git a/autotls/autotls.go b/autotls/autotls.go index e711952..940c964 100644 --- a/autotls/autotls.go +++ b/autotls/autotls.go @@ -94,7 +94,7 @@ type Manager struct { // host, or a newly generated key. // // When shutdown is closed, no new TLS connections can be created. -func Load(name, acmeDir, contactEmail, directoryURL string, eabKeyID string, eabKey []byte, getPrivateKey func(host string, keyType autocert.KeyType) (crypto.Signer, error), shutdown <-chan struct{}) (*Manager, error) { +func Load(log mlog.Log, name, acmeDir, contactEmail, directoryURL string, eabKeyID string, eabKey []byte, getPrivateKey func(host string, keyType autocert.KeyType) (crypto.Signer, error), shutdown <-chan struct{}) (*Manager, error) { if directoryURL == "" { return nil, fmt.Errorf("empty ACME directory URL") } @@ -107,7 +107,10 @@ func Load(name, acmeDir, contactEmail, directoryURL string, eabKeyID string, eab var key crypto.Signer f, err := os.Open(p) if f != nil { - defer f.Close() + defer func() { + err := f.Close() + log.Check(err, "closing identify key file") + }() } if err != nil && os.IsNotExist(err) { key, err = ecdsa.GenerateKey(elliptic.P256(), cryptorand.Reader) diff --git a/autotls/autotls_test.go b/autotls/autotls_test.go index 8bb8431..b18f99d 100644 --- a/autotls/autotls_test.go +++ b/autotls/autotls_test.go @@ -25,7 +25,7 @@ func TestAutotls(t *testing.T) { getPrivateKey := func(host string, keyType autocert.KeyType) (crypto.Signer, error) { return nil, fmt.Errorf("not used") } - m, err := Load("test", "../testdata/autotls", "mox@localhost", "https://localhost/", "", nil, getPrivateKey, shutdown) + m, err := Load(log, "test", "../testdata/autotls", "mox@localhost", "https://localhost/", "", nil, getPrivateKey, shutdown) if err != nil { t.Fatalf("load manager: %v", err) } @@ -82,7 +82,7 @@ func TestAutotls(t *testing.T) { key0 := m.Manager.Client.Key - m, err = Load("test", "../testdata/autotls", "mox@localhost", "https://localhost/", "", nil, getPrivateKey, shutdown) + m, err = Load(log, "test", "../testdata/autotls", "mox@localhost", "https://localhost/", "", nil, getPrivateKey, shutdown) if err != nil { t.Fatalf("load manager again: %v", err) } @@ -95,7 +95,7 @@ func TestAutotls(t *testing.T) { t.Fatalf("hostpolicy, got err %v, expected no error", err) } - m2, err := Load("test2", "../testdata/autotls", "mox@localhost", "https://localhost/", "", nil, nil, shutdown) + m2, err := Load(log, "test2", "../testdata/autotls", "mox@localhost", "https://localhost/", "", nil, nil, shutdown) if err != nil { t.Fatalf("load another manager: %v", err) } diff --git a/backup.go b/backup.go index f5e669e..3f2ebfe 100644 --- a/backup.go +++ b/backup.go @@ -211,7 +211,10 @@ func backupctl(ctx context.Context, ctl *ctl) { xerrx("open source file (not backed up)", err, slog.String("srcpath", srcpath), slog.String("dstpath", dstpath)) return } - defer sf.Close() + defer func() { + err := sf.Close() + ctl.log.Check(err, "closing source file") + }() ensureDestDir(dstpath) df, err := os.OpenFile(dstpath, os.O_WRONLY|os.O_CREATE|os.O_EXCL, 0660) @@ -221,7 +224,8 @@ func backupctl(ctx context.Context, ctl *ctl) { } defer func() { if df != nil { - df.Close() + err := df.Close() + ctl.log.Check(err, "closing destination file") } }() if _, err := io.Copy(df, sf); err != nil { @@ -263,18 +267,9 @@ func backupctl(ctx context.Context, ctl *ctl) { xvlog("backed up directory", slog.String("dir", dir), slog.Duration("duration", time.Since(tmDir))) } - // Backup a database by copying it in a readonly transaction. - // Always logs on error, so caller doesn't have to, but also returns the error so - // callers can see result. - backupDB := func(db *bstore.DB, path string) (rerr error) { - defer func() { - if rerr != nil { - xerrx("backing up database", rerr, slog.String("path", path)) - } - }() - - tmDB := time.Now() - + // Backup a database by copying it in a readonly transaction. Wrapped by backupDB + // which logs and returns just a bool. + backupDB0 := func(db *bstore.DB, path string) error { dstpath := filepath.Join(dstDataDir, path) ensureDestDir(dstpath) df, err := os.OpenFile(dstpath, os.O_WRONLY|os.O_CREATE|os.O_EXCL, 0660) @@ -283,7 +278,8 @@ func backupctl(ctx context.Context, ctl *ctl) { } defer func() { if df != nil { - df.Close() + err := df.Close() + ctl.log.Check(err, "closing destination database file") } }() err = db.Read(ctx, func(tx *bstore.Tx) error { @@ -308,10 +304,20 @@ func backupctl(ctx context.Context, ctl *ctl) { if err != nil { return fmt.Errorf("closing destination database after copy: %v", err) } - xvlog("backed up database file", slog.String("path", path), slog.Duration("duration", time.Since(tmDB))) return nil } + backupDB := func(db *bstore.DB, path string) bool { + start := time.Now() + err := backupDB0(db, path) + if err != nil { + xerrx("backing up database", err, slog.String("path", path), slog.Duration("duration", time.Since(start))) + return false + } + xvlog("backed up database file", slog.String("path", path), slog.Duration("duration", time.Since(start))) + return true + } + // Try to create a hardlink. Fall back to copying the file (e.g. when on different file system). warnedHardlink := false // We warn once about failing to hardlink. linkOrCopy := func(srcpath, dstpath string) (bool, error) { @@ -394,8 +400,7 @@ func backupctl(ctx context.Context, ctl *ctl) { backupQueue := func(path string) { tmQueue := time.Now() - if err := backupDB(queue.DB, path); err != nil { - xerrx("queue not backed up", err, slog.String("path", path), slog.Duration("duration", time.Since(tmQueue))) + if !backupDB(queue.DB, path) { return } @@ -488,16 +493,16 @@ func backupctl(ctx context.Context, ctl *ctl) { backupQueue(filepath.FromSlash("queue/index.db")) backupAccount := func(acc *store.Account) { - defer acc.Close() + defer func() { + err := acc.Close() + ctl.log.Check(err, "closing account") + }() tmAccount := time.Now() // Copy database file. dbpath := filepath.Join("accounts", acc.Name, "index.db") - err := backupDB(acc.DB, dbpath) - if err != nil { - xerrx("copying account database", err, slog.String("path", dbpath), slog.Duration("duration", time.Since(tmAccount))) - } + backupDB(acc.DB, dbpath) // todo: should document/check not taking a rlock on account. diff --git a/ctl.go b/ctl.go index c128938..ac23e1b 100644 --- a/ctl.go +++ b/ctl.go @@ -290,7 +290,10 @@ func servectl(ctx context.Context, cid int64, log mlog.Log, conn net.Conn, shutd metrics.PanicInc(metrics.Ctl) }() - defer conn.Close() + defer func() { + err := conn.Close() + log.Check(err, "close ctl connection") + }() ctl.xwrite("ctlv0") for { diff --git a/dane/dane.go b/dane/dane.go index d72be27..739f438 100644 --- a/dane/dane.go +++ b/dane/dane.go @@ -261,7 +261,8 @@ func Dial(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, network config := TLSClientConfig(log.Logger, records, baseDom, moreAllowedHosts, &verifiedRecord, pkixRoots) tlsConn := tls.Client(conn, &config) if err := tlsConn.HandshakeContext(ctx); err != nil { - conn.Close() + xerr := conn.Close() + log.Check(xerr, "closing connection") return nil, adns.TLSA{}, err } return tlsConn, verifiedRecord, nil diff --git a/dmarcrpt/parse.go b/dmarcrpt/parse.go index 504e610..b1e3016 100644 --- a/dmarcrpt/parse.go +++ b/dmarcrpt/parse.go @@ -52,7 +52,7 @@ func parseMessageReport(log mlog.Log, p message.Part) (*Feedback, error) { // content of the message. if p.MediaType != "MULTIPART" { - return parseReport(p) + return parseReport(log, p) } for { @@ -72,7 +72,7 @@ func parseMessageReport(log mlog.Log, p message.Part) (*Feedback, error) { } } -func parseReport(p message.Part) (*Feedback, error) { +func parseReport(log mlog.Log, p message.Part) (*Feedback, error) { ct := strings.ToLower(p.MediaType + "/" + p.MediaSubType) r := p.Reader() @@ -93,7 +93,7 @@ func parseReport(p message.Part) (*Feedback, error) { switch ct { case "application/zip": // Google sends messages with direct application/zip content-type. - return parseZip(r) + return parseZip(log, r) case "application/gzip", "application/x-gzip": gzr, err := gzip.NewReader(r) if err != nil { @@ -106,7 +106,7 @@ func parseReport(p message.Part) (*Feedback, error) { return nil, ErrNoReport } -func parseZip(r io.Reader) (*Feedback, error) { +func parseZip(log mlog.Log, r io.Reader) (*Feedback, error) { buf, err := io.ReadAll(r) if err != nil { return nil, fmt.Errorf("reading feedback: %s", err) @@ -122,6 +122,9 @@ func parseZip(r io.Reader) (*Feedback, error) { if err != nil { return nil, fmt.Errorf("opening file in zip: %s", err) } - defer f.Close() + defer func() { + err := f.Close() + log.Check(err, "closing report file in zip file") + }() return ParseReport(f) } diff --git a/http/autoconf.go b/http/autoconf.go index 83c4e70..3a28c52 100644 --- a/http/autoconf.go +++ b/http/autoconf.go @@ -175,9 +175,8 @@ func autoconfHandle(w http.ResponseWriter, r *http.Request) { enc := xml.NewEncoder(w) enc.Indent("", "\t") fmt.Fprint(w, xml.Header) - if err := enc.Encode(resp); err != nil { - log.Errorx("marshal autoconfig response", err) - } + err = enc.Encode(resp) + log.Check(err, "write autoconfig xml response") } // Autodiscover from Microsoft, also used by Thunderbird. @@ -292,9 +291,8 @@ func autodiscoverHandle(w http.ResponseWriter, r *http.Request) { enc := xml.NewEncoder(w) enc.Indent("", "\t") fmt.Fprint(w, xml.Header) - if err := enc.Encode(resp); err != nil { - log.Errorx("marshal autodiscover response", err) - } + err = enc.Encode(resp) + log.Check(err, "marshal autodiscover xml response") } // Thunderbird requests these URLs for autoconfig/autodiscover: @@ -375,6 +373,8 @@ type autodiscoverProtocol struct { // Serve a .mobileconfig file. This endpoint is not a standard place where Apple // devices look. We point to it from the account page. func mobileconfigHandle(w http.ResponseWriter, r *http.Request) { + log := pkglog.WithContext(r.Context()) + if r.Method != "GET" { http.Error(w, "405 - method not allowed - get required", http.StatusMethodNotAllowed) return @@ -400,12 +400,15 @@ func mobileconfigHandle(w http.ResponseWriter, r *http.Request) { filename = strings.ReplaceAll(filename, "@", "-at-") filename = "email-account-" + filename + ".mobileconfig" h.Set("Content-Disposition", fmt.Sprintf(`attachment; filename="%s"`, filename)) - w.Write(buf) + _, err = w.Write(buf) + log.Check(err, "writing mobileconfig response") } // Serve a png file with qrcode with the link to the .mobileconfig file, should be // helpful for mobile devices. func mobileconfigQRCodeHandle(w http.ResponseWriter, r *http.Request) { + log := pkglog.WithContext(r.Context()) + if r.Method != "GET" { http.Error(w, "405 - method not allowed - get required", http.StatusMethodNotAllowed) return @@ -432,5 +435,6 @@ func mobileconfigQRCodeHandle(w http.ResponseWriter, r *http.Request) { } h := w.Header() h.Set("Content-Type", "image/png") - w.Write(code.PNG()) + _, err = w.Write(code.PNG()) + log.Check(err, "writing mobileconfig qr code") } diff --git a/http/webserver.go b/http/webserver.go index 71c4f17..ab2c58e 100644 --- a/http/webserver.go +++ b/http/webserver.go @@ -30,7 +30,6 @@ import ( "github.com/mjl-/mox/dns" "github.com/mjl-/mox/mlog" "github.com/mjl-/mox/mox-" - "github.com/mjl-/mox/moxio" ) func recvid(r *http.Request) string { @@ -222,27 +221,34 @@ func HandleStatic(h *config.WebStatic, compress bool, w http.ResponseWriter, r * // If we tried opening a directory, we may not have permission to read it, but // still access files inside it (execute bit), such as index.html. So try to serve it. index, err := os.Open(filepath.Join(fspath, "index.html")) - if err == nil { - defer index.Close() - var ifi os.FileInfo - ifi, err = index.Stat() - if err != nil { - log().Errorx("stat index.html in directory we cannot list", err, slog.Any("url", r.URL), slog.String("fspath", fspath)) - http.Error(w, "500 - internal server error"+recvid(r), http.StatusInternalServerError) - return true - } - w.Header().Set("Content-Type", "text/html; charset=utf-8") - serveFile("index.html", ifi, index) + if err != nil { + http.Error(w, "403 - permission denied", http.StatusForbidden) return true } - http.Error(w, "403 - permission denied", http.StatusForbidden) + defer func() { + err := index.Close() + log().Check(err, "closing index file for serving") + }() + var ifi os.FileInfo + ifi, err = index.Stat() + if err != nil { + log().Errorx("stat index.html in directory we cannot list", err, slog.Any("url", r.URL), slog.String("fspath", fspath)) + http.Error(w, "500 - internal server error"+recvid(r), http.StatusInternalServerError) + return true + } + w.Header().Set("Content-Type", "text/html; charset=utf-8") + serveFile("index.html", ifi, index) return true } log().Errorx("open file for static file serving", err, slog.Any("url", r.URL), slog.String("fspath", fspath)) http.Error(w, "500 - internal server error"+recvid(r), http.StatusInternalServerError) return true } - defer f.Close() + defer func() { + if err := f.Close(); err != nil { + log().Check(err, "closing file for static file serving") + } + }() fi, err := f.Stat() if err != nil { @@ -274,7 +280,12 @@ func HandleStatic(h *config.WebStatic, compress bool, w http.ResponseWriter, r * http.Error(w, "403 - permission denied", http.StatusForbidden) return true } else if err == nil { - defer index.Close() + defer func() { + if err := index.Close(); err != nil { + log().Check(err, "closing index file for serving") + } + }() + var ifi os.FileInfo ifi, err = index.Stat() if err == nil { @@ -341,8 +352,8 @@ func HandleStatic(h *config.WebStatic, compress bool, w http.ResponseWriter, r * } } err = lsTemplate.Execute(w, map[string]any{"Files": files}) - if err != nil && !moxio.IsClosed(err) { - log().Errorx("executing directory listing template", err) + if err != nil { + log().Check(err, "executing directory listing template") } return true } @@ -595,7 +606,9 @@ func forwardWebsocket(h *config.WebForward, w http.ResponseWriter, r *http.Reque } defer func() { if beconn != nil { - beconn.Close() + if err := beconn.Close(); err != nil { + log().Check(err, "closing backend websocket connection") + } } }() @@ -611,7 +624,9 @@ func forwardWebsocket(h *config.WebForward, w http.ResponseWriter, r *http.Reque } defer func() { if cconn != nil { - cconn.Close() + if err := cconn.Close(); err != nil { + log().Check(err, "closing client websocket connection") + } } }() @@ -664,8 +679,12 @@ func forwardWebsocket(h *config.WebForward, w http.ResponseWriter, r *http.Reque // connection whose closing was already announced with a websocket frame. lw.error(<-errc) // Close connections so other goroutine stops as well. - cconn.Close() - beconn.Close() + if err := cconn.Close(); err != nil { + log().Check(err, "closing client websocket connection") + } + if err := beconn.Close(); err != nil { + log().Check(err, "closing backend websocket connection") + } // Wait for goroutine so it has updated the logWriter.Size*Client fields before we // continue with logging. <-errc @@ -718,7 +737,9 @@ func websocketTransact(ctx context.Context, targetURL *url.URL, r *http.Request) } defer func() { if rerr != nil { - conn.Close() + if xerr := conn.Close(); xerr != nil { + log().Check(xerr, "cleaning up websocket connection") + } } }() @@ -745,7 +766,9 @@ func websocketTransact(ctx context.Context, targetURL *url.URL, r *http.Request) } defer func() { if rerr != nil { - resp.Body.Close() + if xerr := resp.Body.Close(); xerr != nil { + log().Check(xerr, "closing response body after error") + } } }() if err := conn.SetDeadline(time.Time{}); err != nil { diff --git a/imapclient/parse.go b/imapclient/parse.go index 709f303..ceeffe3 100644 --- a/imapclient/parse.go +++ b/imapclient/parse.go @@ -814,7 +814,8 @@ func (c *Conn) xatom() string { b, err := c.readbyte() c.xcheckf(err, "read byte for atom") if b <= ' ' || strings.IndexByte("(){%*\"\\]", b) >= 0 { - c.br.UnreadByte() + err := c.br.UnreadByte() + c.xcheckf(err, "unreadbyte") if s == "" { c.xerrorf("expected atom") } diff --git a/imapserver/server.go b/imapserver/server.go index e911988..8df9264 100644 --- a/imapserver/server.go +++ b/imapserver/server.go @@ -889,7 +889,7 @@ func serve(listenerName string, cid int64, tlsConfig *tls.Config, nc net.Conn, x // isClosed returns whether i/o failed, typically because the connection is closed. // For connection errors, we often want to generate fewer logs. func isClosed(err error) bool { - return errors.Is(err, errIO) || errors.Is(err, errProtocol) || moxio.IsClosed(err) + return errors.Is(err, errIO) || errors.Is(err, errProtocol) || mlog.IsClosed(err) } // newLoginAttempt initializes a c.loginAttempt, for adding to the store after diff --git a/junk/bloom.go b/junk/bloom.go index 273d2be..3571d53 100644 --- a/junk/bloom.go +++ b/junk/bloom.go @@ -5,6 +5,8 @@ import ( "os" "golang.org/x/crypto/blake2b" + + "github.com/mjl-/mox/mlog" ) // see https://en.wikipedia.org/wiki/Bloom_filter @@ -18,6 +20,8 @@ type Bloom struct { k int // Number of bits we store/lookup in the bloom filter per value. w int // Number of bits needed to address a single bit position. modified bool + + log mlog.Log // For cid logging. } func bloomWidth(fileSize int) int { @@ -55,7 +59,7 @@ func bloomValid(fileSize, k int) (int, error) { // For each value stored/looked up, a hash over the value is calculated. The hash // is split into "k" values that are "width" bits wide, each used to lookup a bit. // K * width must not exceed 256. -func NewBloom(data []byte, k int) (*Bloom, error) { +func NewBloom(log mlog.Log, data []byte, k int) (*Bloom, error) { w, err := bloomValid(len(data), k) if err != nil { return nil, err @@ -65,6 +69,7 @@ func NewBloom(data []byte, k int) (*Bloom, error) { data: data, k: k, w: w, + log: log, }, nil } @@ -112,7 +117,8 @@ func (b *Bloom) Write(path string) error { return err } if _, err := f.Write(b.data); err != nil { - f.Close() + xerr := f.Close() + b.log.Check(xerr, "closing bloom file after write failed") return err } if err := f.Close(); err != nil { diff --git a/junk/bloom_test.go b/junk/bloom_test.go index ebb58da..074edf4 100644 --- a/junk/bloom_test.go +++ b/junk/bloom_test.go @@ -3,6 +3,8 @@ package junk import ( "fmt" "testing" + + "github.com/mjl-/mox/mlog" ) func TestBloom(t *testing.T) { @@ -10,12 +12,13 @@ func TestBloom(t *testing.T) { t.Fatalf("missing error for invalid bloom filter size") } - _, err := NewBloom(make([]byte, 3), 10) + log := mlog.New("junk", nil) + _, err := NewBloom(log, make([]byte, 3), 10) if err == nil { t.Fatalf("missing error for invalid bloom filter size") } - b, err := NewBloom(make([]byte, 256), 5) + b, err := NewBloom(log, make([]byte, 256), 5) if err != nil { t.Fatalf("newbloom: %s", err) } diff --git a/junk/filter.go b/junk/filter.go index 7b207b4..ad4fc2d 100644 --- a/junk/filter.go +++ b/junk/filter.go @@ -80,7 +80,7 @@ func (f *Filter) ensureBloom() error { return nil } var err error - f.bloom, err = openBloom(f.bloomPath) + f.bloom, err = openBloom(f.log, f.bloomPath) return err } @@ -105,7 +105,8 @@ func (f *Filter) Close() error { err = f.Save() } if err != nil { - f.db.Close() + xerr := f.db.Close() + f.log.Check(xerr, "closing junk filter after error") } else { err = f.db.Close() } @@ -117,7 +118,7 @@ func OpenFilter(ctx context.Context, log mlog.Log, params Params, dbPath, bloomP var bloom *Bloom if loadBloom { var err error - bloom, err = openBloom(bloomPath) + bloom, err = openBloom(log, bloomPath) if err != nil { return nil, err } @@ -213,12 +214,12 @@ func NewFilter(ctx context.Context, log mlog.Log, params Params, dbPath, bloomPa const bloomK = 10 -func openBloom(path string) (*Bloom, error) { +func openBloom(log mlog.Log, path string) (*Bloom, error) { buf, err := os.ReadFile(path) if err != nil { return nil, fmt.Errorf("reading bloom file: %w", err) } - return NewBloom(buf, bloomK) + return NewBloom(log, buf, bloomK) } func newDB(ctx context.Context, log mlog.Log, path string) (db *bstore.DB, rerr error) { diff --git a/junk/parse.go b/junk/parse.go index ad5373b..f7c99c2 100644 --- a/junk/parse.go +++ b/junk/parse.go @@ -209,7 +209,9 @@ func (f *Filter) tokenizeText(r io.Reader, words map[string]struct{}) error { peekLetter := func() bool { c, _, err := br.ReadRune() - br.UnreadRune() + if err == nil { + err = br.UnreadRune() + } return err == nil && unicode.IsLetter(c) } diff --git a/main.go b/main.go index f74dc5d..3b5dfca 100644 --- a/main.go +++ b/main.go @@ -1106,7 +1106,9 @@ func ctlcmdConfigTlspubkeyGet(ctl *ctl, fingerprint string) { fmt.Printf("type: %s\nname: %s\naccount: %s\naddress: %s\nno imap preauth: %s\n", typ, name, account, address, noimappreauth) if block != nil { fmt.Printf("certificate:\n\n") - pem.Encode(os.Stdout, block) + if err := pem.Encode(os.Stdout, block); err != nil { + log.Fatalf("pem encode: %v", err) + } } } @@ -1918,7 +1920,8 @@ connection. go func() { _, err := io.Copy(os.Stdout, conn) xcheckf(err, "copy from connection to stdout") - conn.Close() + err = conn.Close() + c.log.Check(err, "closing connection") }() _, err = io.Copy(conn, os.Stdin) xcheckf(err, "copy from stdin to connection") @@ -2079,7 +2082,9 @@ sharing most of its code. sc, err := smtpclient.New(ctxbg, c.log.Logger, conn, tlsMode, tlsPKIX, ehloDomain, tlsHostnames[0], opts) if err != nil { log.Printf("setting up smtp session: %v, skipping", err) - conn.Close() + if xerr := conn.Close(); xerr != nil { + log.Printf("closing connection: %v", xerr) + } continue } @@ -2093,7 +2098,9 @@ sharing most of its code. go func() { _, err := io.Copy(os.Stdout, smtpConn) xcheckf(err, "copy from connection to stdout") - smtpConn.Close() + if err := smtpConn.Close(); err != nil { + log.Printf("closing smtp connection: %v", err) + } }() _, err = io.Copy(smtpConn, os.Stdin) xcheckf(err, "copy from stdin to connection") @@ -2524,7 +2531,11 @@ headers prepended. msgf, err := os.Open(args[0]) xcheckf(err, "open message") - defer msgf.Close() + defer func() { + if err := msgf.Close(); err != nil { + log.Printf("closing message file: %v", err) + } + }() p, err := message.Parse(c.log.Logger, true, msgf) xcheckf(err, "parsing message") @@ -3019,7 +3030,7 @@ automation. domain := xparseDomain(args[0], "domain") - registration, err := rdap.LookupLastDomainRegistration(context.Background(), domain) + registration, err := rdap.LookupLastDomainRegistration(context.Background(), c.log, domain) xcheckf(err, "looking up domain in rdap") age := time.Since(registration) @@ -3278,7 +3289,11 @@ func cmdWebapi(c *cmd) { resp, err := http.PostForm(args[1]+args[0], url.Values{"request": []string{string(request)}}) xcheckf(err, "http post") - defer resp.Body.Close() + defer func() { + if err := resp.Body.Close(); err != nil { + log.Printf("closing http response body: %v", err) + } + }() if resp.StatusCode == http.StatusBadRequest { buf, err := io.ReadAll(&moxio.LimitReader{R: resp.Body, Limit: 10 * 1024}) xcheckf(err, "reading response for 400 bad request error") @@ -3681,7 +3696,11 @@ func cmdMessageParse(c *cmd) { f, err := os.Open(args[0]) xcheckf(err, "open") - defer f.Close() + defer func() { + if err := f.Close(); err != nil { + log.Printf("closing message file: %v", err) + } + }() part, err := message.Parse(c.log.Logger, false, f) xcheckf(err, "parsing message") @@ -3892,7 +3911,11 @@ Opens database files directly, not going through a running mox instance. buf := headerbuf[:int(size)] err := func() error { mr := a.MessageReader(m) - defer mr.Close() + defer func() { + if err := mr.Close(); err != nil { + log.Printf("closing message reader: %v", err) + } + }() // ReadAt returns whole buffer or error. Single read should be fast. n, err := mr.ReadAt(buf, partialPart.HeaderOffset) diff --git a/message/part.go b/message/part.go index 0a1a0bc..b954abf 100644 --- a/message/part.go +++ b/message/part.go @@ -755,10 +755,12 @@ func (tr *textReader) Read(buf []byte) (int, error) { return o, err } if c == '\n' && !tr.prevcr { + if err := tr.r.UnreadByte(); err != nil { + return o, err + } buf[o] = '\r' o++ tr.prevcr = true - tr.r.UnreadByte() continue } buf[o] = c diff --git a/moxio/isclosed.go b/mlog/isclosed.go similarity index 98% rename from moxio/isclosed.go rename to mlog/isclosed.go index 853c1bd..ced3619 100644 --- a/moxio/isclosed.go +++ b/mlog/isclosed.go @@ -1,4 +1,4 @@ -package moxio +package mlog import ( "errors" diff --git a/mlog/log.go b/mlog/log.go index dd6a21a..52dd34e 100644 --- a/mlog/log.go +++ b/mlog/log.go @@ -16,6 +16,7 @@ import ( "bytes" "context" "encoding/base64" + "errors" "fmt" "io" "log/slog" @@ -199,11 +200,21 @@ func (l Log) WithFunc(fn func() []slog.Attr) Log { } // Check logs an error if err is not nil. Intended for logging errors that are good -// to know, but would not influence program flow. +// to know, but would not influence program flow. Context deadline/cancelation +// errors and timeouts are logged at "info" level. Closed remote connections are +// logged at "debug" level. Other errors at "error" level. func (l Log) Check(err error, msg string, attrs ...slog.Attr) { - if err != nil { - l.Errorx(msg, err, attrs...) + if err == nil { + return } + level := LevelError + if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled) || errors.Is(err, os.ErrDeadlineExceeded) { + level = LevelInfo + } else if IsClosed(err) { + level = LevelDebug + } + attrs = append([]slog.Attr{errAttr(err)}, attrs...) + l.Logger.LogAttrs(noctx, level, msg, attrs...) } func errAttr(err error) slog.Attr { diff --git a/mox-/config.go b/mox-/config.go index 461481b..6b26abe 100644 --- a/mox-/config.go +++ b/mox-/config.go @@ -717,7 +717,7 @@ func PrepareStaticConfig(ctx context.Context, log mlog.Log, configFile string, c acmeDir := dataDirPath(configFile, c.DataDir, "acme") os.MkdirAll(acmeDir, 0770) - manager, err := autotls.Load(name, acmeDir, acme.ContactEmail, acme.DirectoryURL, eabKeyID, eabKey, makeGetPrivateKey(name), Shutdown.Done()) + manager, err := autotls.Load(log, name, acmeDir, acme.ContactEmail, acme.DirectoryURL, eabKeyID, eabKey, makeGetPrivateKey(name), Shutdown.Done()) if err != nil { addAcmeErrorf("loading ACME identity: %s", err) } diff --git a/mtasts/mtasts.go b/mtasts/mtasts.go index ff8c620..e46f849 100644 --- a/mtasts/mtasts.go +++ b/mtasts/mtasts.go @@ -286,7 +286,10 @@ func FetchPolicy(ctx context.Context, elog *slog.Logger, domain dns.Domain) (pol return nil, "", fmt.Errorf("%w: http get: %w", ErrPolicyFetch, err) } HTTPClientObserve(ctx, log.Logger, "mtasts", req.Method, resp.StatusCode, err, start) - defer resp.Body.Close() + defer func() { + err := resp.Body.Close() + log.Check(err, "close body response") + }() if resp.StatusCode == http.StatusNotFound { return nil, "", ErrNoPolicy } diff --git a/queue/direct.go b/queue/direct.go index 1129b2e..082d1bf 100644 --- a/queue/direct.go +++ b/queue/direct.go @@ -647,9 +647,11 @@ func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer, sc, err := smtpclient.New(ctx, log.Logger, conn, tlsMode, tlsPKIX, ourHostname, firstHost, opts) defer func() { if sc == nil { - conn.Close() + err := conn.Close() + log.Check(err, "closing smtp tcp connection") } else { - sc.Close() + err := sc.Close() + log.Check(err, "closing smtp connection") } mox.Connections.Unregister(conn) }() diff --git a/queue/hook.go b/queue/hook.go index b162bf5..1a9d526 100644 --- a/queue/hook.go +++ b/queue/hook.go @@ -1262,7 +1262,10 @@ func HookPost(ctx context.Context, log mlog.Log, hookID int64, attempt int, url, log.Debugx("webhook http transaction", err) return 0, "", fmt.Errorf("http transact: %v", err) } - defer resp.Body.Close() + defer func() { + err := resp.Body.Close() + log.Check(err, "closing response body") + }() // Use full http status code for known codes, and a generic "xx" for others. result := fmt.Sprintf("%d", resp.StatusCode) diff --git a/queue/queue.go b/queue/queue.go index 07c5949..4289691 100644 --- a/queue/queue.go +++ b/queue/queue.go @@ -361,7 +361,8 @@ func Init() error { } if err != nil { if isNew { - os.Remove(qpath) + err := os.Remove(qpath) + log.Check(err, "removing new queue database file after error") } return fmt.Errorf("open queue database: %s", err) } diff --git a/quickstart.go b/quickstart.go index 248276f..8a0f4fc 100644 --- a/quickstart.go +++ b/quickstart.go @@ -105,12 +105,17 @@ output of "mox config describe-domains" and see the output of go func() { io.Copy(io.MultiWriter(origStdout, logfile), piper) close(pipec) + if err := piper.Close(); err != nil { + log.Printf("close pipe: %v", err) + } }() // A single pipe, so writes to stdout and stderr don't get interleaved. os.Stdout = pipew os.Stderr = pipew logClose := func() { - pipew.Close() + if err := pipew.Close(); err != nil { + log.Printf("close pipe: %v", err) + } <-pipec os.Stdout = origStdout os.Stderr = origStderr @@ -586,7 +591,9 @@ messages over SMTP. if err != nil { fmt.Printf("\n\nERROR: connecting to %s: %s\n", addr, err) } else { - conn.Close() + if err := conn.Close(); err != nil { + log.Printf("closing smtp connection: %v", err) + } fmt.Printf(" OK\n") ok = true } @@ -608,7 +615,7 @@ in mox.conf and use it in "Routes" in domains.conf. See defer rdapcancel() orgdom := publicsuffix.Lookup(rdapctx, c.log.Logger, domain) fmt.Printf("\nChecking if domain %s was registered recently...", orgdom) - registration, err := rdap.LookupLastDomainRegistration(rdapctx, orgdom) + registration, err := rdap.LookupLastDomainRegistration(rdapctx, c.log, orgdom) rdapcancel() if err != nil { fmt.Printf(" error: %s (continuing)\n\n", err) diff --git a/rdap/rdap.go b/rdap/rdap.go index 182ae44..6ce4757 100644 --- a/rdap/rdap.go +++ b/rdap/rdap.go @@ -13,6 +13,7 @@ import ( "time" "github.com/mjl-/mox/dns" + "github.com/mjl-/mox/mlog" ) var ErrNoRegistration = errors.New("registration date not found") @@ -43,7 +44,7 @@ type Bootstrap struct { // domain through RDAP. // // Not all TLDs have RDAP services yet at the time of writing. -func LookupLastDomainRegistration(ctx context.Context, dom dns.Domain) (time.Time, error) { +func LookupLastDomainRegistration(ctx context.Context, log mlog.Log, dom dns.Domain) (time.Time, error) { // ../rfc/9224:434 Against advice, we do not cache the bootstrap data. This is // currently used by the quickstart, which is run once, or run from the cli without // a place to keep state. @@ -57,7 +58,10 @@ func LookupLastDomainRegistration(ctx context.Context, dom dns.Domain) (time.Tim if err != nil { return time.Time{}, fmt.Errorf("http get of iana dns bootstrap data: %v", err) } - defer resp.Body.Close() + defer func() { + err := resp.Body.Close() + log.Check(err, "closing http response body") + }() if resp.StatusCode/100 != 2 { return time.Time{}, fmt.Errorf("http get resulted in status %q, expected 200 ok", resp.Status) } @@ -94,7 +98,7 @@ func LookupLastDomainRegistration(ctx context.Context, dom dns.Domain) (time.Tim var lastErr error for _, u := range urls { var reg time.Time - reg, lastErr = rdapDomainRequest(ctx, u, dom) + reg, lastErr = rdapDomainRequest(ctx, log, u, dom) if lastErr == nil { return reg, nil } @@ -126,7 +130,7 @@ type Event struct { // rdapDomainRequest looks up a the most recent registration time of a at an RDAP // service base URL. -func rdapDomainRequest(ctx context.Context, rdapURL string, dom dns.Domain) (time.Time, error) { +func rdapDomainRequest(ctx context.Context, log mlog.Log, rdapURL string, dom dns.Domain) (time.Time, error) { // ../rfc/9082:316 // ../rfc/9224:177 base URLs have a trailing slash. rdapURL += "domain/" + dom.ASCII @@ -141,7 +145,10 @@ func rdapDomainRequest(ctx context.Context, rdapURL string, dom dns.Domain) (tim if err != nil { return time.Time{}, fmt.Errorf("http domain rdap get request: %v", err) } - defer resp.Body.Close() + defer func() { + err := resp.Body.Close() + log.Check(err, "closing http response body") + }() switch { case resp.StatusCode == http.StatusNotFound: diff --git a/smtpserver/server.go b/smtpserver/server.go index b451bc3..ef76de7 100644 --- a/smtpserver/server.go +++ b/smtpserver/server.go @@ -398,7 +398,7 @@ type recipient struct { } func isClosed(err error) bool { - return errors.Is(err, errIO) || moxio.IsClosed(err) + return errors.Is(err, errIO) || mlog.IsClosed(err) } // Logbg returns a logger for logging in the background (in a goroutine), eg for @@ -934,8 +934,9 @@ func serve(listenerName string, cid int64, hostname dns.Domain, tlsConfig *tls.C slog.String("listener", listenerName)) defer func() { - c.origConn.Close() // Close actual TCP socket, regardless of TLS on top. - c.conn.Close() // If TLS, will try to write alert notification to already closed socket, returning error quickly. + err := c.origConn.Close() // Close actual TCP socket, regardless of TLS on top. + c.log.Check(err, "closing tcp connection") + c.conn.Close() // If TLS, will try to write alert notification to already closed socket, returning error quickly. if c.account != nil { err := c.account.Close() diff --git a/store/account.go b/store/account.go index 63cbe7f..dda05e7 100644 --- a/store/account.go +++ b/store/account.go @@ -1119,9 +1119,11 @@ func OpenAccountDB(log mlog.Log, accountDir, accountName string) (a *Account, re defer func() { if rerr != nil { - db.Close() + err := db.Close() + log.Check(err, "closing database file after error") if isNew { - os.Remove(dbpath) + err := os.Remove(dbpath) + log.Check(err, "removing new database file after error") } } }() @@ -1820,17 +1822,26 @@ func (a *Account) CheckConsistency() error { conf, _ := a.Conf() if conf.JunkFilter != nil { random := make([]byte, 16) - cryptorand.Read(random) + if _, err := cryptorand.Read(random); err != nil { + return fmt.Errorf("reading random: %v", err) + } dbpath := filepath.Join(mox.DataDirPath("tmp"), fmt.Sprintf("junkfilter-check-%x.db", random)) bloompath := filepath.Join(mox.DataDirPath("tmp"), fmt.Sprintf("junkfilter-check-%x.bloom", random)) os.MkdirAll(filepath.Dir(dbpath), 0700) - defer os.Remove(dbpath) - defer os.Remove(bloompath) + defer func() { + err := os.Remove(bloompath) + log.Check(err, "removing temp bloom file") + err = os.Remove(dbpath) + log.Check(err, "removing temp junk filter database file") + }() jf, err = junk.NewFilter(ctx, log, conf.JunkFilter.Params, dbpath, bloompath) if err != nil { return fmt.Errorf("new junk filter: %v", err) } - defer jf.Close() + defer func() { + err := jf.Close() + log.Check(err, "closing junk filter") + }() } var ntrained int @@ -1987,7 +1998,10 @@ func (a *Account) CheckConsistency() error { if err != nil { return fmt.Errorf("open account junk filter: %v", err) } - defer ajf.Close() + defer func() { + err := ajf.Close() + log.Check(err, "closing junk filter") + }() wordsGot, err := load(ajf) if err != nil { return fmt.Errorf("read account junk filter: %v", err) diff --git a/store/threads.go b/store/threads.go index 62c3a35..a377f13 100644 --- a/store/threads.go +++ b/store/threads.go @@ -423,7 +423,10 @@ func (a *Account) AssignThreads(ctx context.Context, log mlog.Log, txOpt *bstore buf := headerbuf[:int(size)] err := func() error { mr := a.MessageReader(m) - defer mr.Close() + defer func() { + err := mr.Close() + log.Check(err, "closing message reader") + }() // ReadAt returns whole buffer or error. Single read should be fast. n, err := mr.ReadAt(buf, partialPart.HeaderOffset) diff --git a/tlsrpt/report.go b/tlsrpt/report.go index a25cc37..be352c0 100644 --- a/tlsrpt/report.go +++ b/tlsrpt/report.go @@ -414,7 +414,7 @@ func TLSFailureDetails(err error) (ResultType, string) { var reasonCode string if errors.Is(err, os.ErrDeadlineExceeded) || errors.Is(err, context.DeadlineExceeded) { reasonCode = "io-timeout-during-handshake" - } else if moxio.IsClosed(err) || errors.Is(err, io.ErrClosedPipe) { + } else if mlog.IsClosed(err) || errors.Is(err, io.ErrClosedPipe) { reasonCode = "connection-closed-during-handshake" } else { // Attempt to get a local, outgoing TLS alert. diff --git a/updates.go b/updates.go index 32f9209..25307d7 100644 --- a/updates.go +++ b/updates.go @@ -14,7 +14,7 @@ import ( "os" "strings" - "github.com/mjl-/mox/moxio" + "github.com/mjl-/mox/mlog" "github.com/mjl-/mox/updates" ) @@ -29,7 +29,10 @@ func cmdUpdatesAddSigned(c *cmd) { f, err := os.Open(args[0]) xcheckf(err, "open private key file") - defer f.Close() + defer func() { + err := f.Close() + c.log.Check(err, "closing private key file") + }() seed, err := io.ReadAll(base64.NewDecoder(base64.StdEncoding, f)) xcheckf(err, "read private key file") if len(seed) != ed25519.SeedSize { @@ -179,7 +182,10 @@ func cmdUpdatesServe(c *cmd) { if err != nil { return nil, err } - defer f.Close() + defer func() { + err := f.Close() + c.log.Check(err, "closing changelog file") + }() var cl updates.Changelog if err := json.NewDecoder(f).Decode(&cl); err != nil { return nil, err @@ -261,12 +267,12 @@ func cmdUpdatesServe(c *cmd) { "FromVersion": fromVersion, "Changes": cl.Changes, }) - if err != nil && !moxio.IsClosed(err) { + if err != nil && !mlog.IsClosed(err) { log.Printf("writing changelog html: %v", err) } } else { w.Header().Set("Content-Type", "application/json; charset=utf-8") - if err := json.NewEncoder(w).Encode(cl); err != nil && !moxio.IsClosed(err) { + if err := json.NewEncoder(w).Encode(cl); err != nil && !mlog.IsClosed(err) { log.Printf("writing changelog json: %v", err) } } diff --git a/updates/updates.go b/updates/updates.go index 658fb26..afb53a5 100644 --- a/updates/updates.go +++ b/updates/updates.go @@ -150,7 +150,10 @@ func FetchChangelog(ctx context.Context, elog *slog.Logger, baseURL string, base if err != nil { return nil, fmt.Errorf("%w: making http request: %s", ErrChangelogFetch, err) } - defer resp.Body.Close() + defer func() { + err := resp.Body.Close() + log.Check(err, "closing http response body") + }() if resp.StatusCode != http.StatusOK { return nil, fmt.Errorf("%w: http status: %s", ErrChangelogFetch, resp.Status) } diff --git a/verifydata.go b/verifydata.go index 6149ea1..15c22ae 100644 --- a/verifydata.go +++ b/verifydata.go @@ -118,7 +118,9 @@ possibly making them potentially no longer readable by the previous version. return nil }) checkf(err, path, "reading bolt database") - bdb.Close() + if err := bdb.Close(); err != nil { + log.Printf("closing database file: %v", err) + } opts := bstore.Options{RegisterLogger: c.log.Logger} db, err := bstore.Open(ctxbg, path, &opts, types...) @@ -126,7 +128,11 @@ possibly making them potentially no longer readable by the previous version. if err != nil { return } - defer db.Close() + defer func() { + if err := db.Close(); err != nil { + log.Printf("closing database file: %v", err) + } + }() err = db.Read(ctxbg, func(tx *bstore.Tx) error { // Check bstore consistency, if it can export all records for all types. This is a diff --git a/webadmin/admin.go b/webadmin/admin.go index 0d9f8d8..453883f 100644 --- a/webadmin/admin.go +++ b/webadmin/admin.go @@ -521,7 +521,8 @@ func checkDomain(ctx context.Context, resolver dns.Resolver, dialer *net.Dialer, if err != nil { addf(errors, "TLS connection to hostname %q, IP %q: %s", host, ip, err) } else { - conn.Close() + err := conn.Close() + log.Check(err, "closing tcp connection") } } } @@ -749,7 +750,8 @@ EOF } defer func() { if conn != nil { - conn.Close() + err := conn.Close() + log.Check(err, "closing tcp connection") } }() @@ -799,7 +801,8 @@ EOF return fmt.Errorf("TLS handshake after SMTP STARTTLS: %s", err) } cancel() - conn.Close() + err = conn.Close() + log.Check(err, "closing smtp connection") conn = nil return nil } diff --git a/webapi/client.go b/webapi/client.go index f094544..ad93ea8 100644 --- a/webapi/client.go +++ b/webapi/client.go @@ -5,6 +5,7 @@ import ( "encoding/json" "fmt" "io" + "log/slog" "net/http" "net/url" "strings" @@ -17,6 +18,7 @@ type Client struct { Username string // Added as HTTP basic authentication if not empty. Password string HTTPClient *http.Client // Optional, defaults to http.DefaultClient. + Logger *slog.Logger // Optional, defaults to slog.Default(). } var _ Methods = Client{} @@ -28,12 +30,24 @@ func (c Client) httpClient() *http.Client { return http.DefaultClient } +func (c Client) log(ctx context.Context) *slog.Logger { + if c.Logger != nil { + return c.Logger + } + return slog.Default() +} + func transact[T any](ctx context.Context, c Client, fn string, req any) (resp T, rerr error) { hresp, err := httpDo(ctx, c, fn, req) if err != nil { return resp, err } - defer hresp.Body.Close() + defer func() { + err := hresp.Body.Close() + if err != nil { + c.log(ctx).Debug("closing http response body", slog.Any("err", err)) + } + }() if hresp.StatusCode == http.StatusOK { // Text and HTML of a message can each be 1MB. Another MB for other data would be a @@ -52,7 +66,10 @@ func transactReadCloser(ctx context.Context, c Client, fn string, req any) (resp body := hresp.Body defer func() { if body != nil { - body.Close() + err := body.Close() + if err != nil { + c.log(ctx).Debug("closing http response body", slog.Any("err", err)) + } } }() if hresp.StatusCode == http.StatusOK { diff --git a/webapisrv/server.go b/webapisrv/server.go index 6cb3c2a..5edc568 100644 --- a/webapisrv/server.go +++ b/webapisrv/server.go @@ -407,9 +407,7 @@ func (s server) ServeHTTP(w http.ResponseWriter, r *http.Request) { enc := json.NewEncoder(w) enc.SetEscapeHTML(false) werr := enc.Encode(err) - if werr != nil && !moxio.IsClosed(werr) { - log.Infox("writing error response", werr) - } + log.Check(werr, "writing error response") } // Called for all successful JSON responses, not non-JSON responses. @@ -421,9 +419,7 @@ func (s server) ServeHTTP(w http.ResponseWriter, r *http.Request) { enc := json.NewEncoder(w) enc.SetEscapeHTML(false) werr := enc.Encode(resp) - if werr != nil && !moxio.IsClosed(werr) { - log.Infox("writing error response", werr) - } + log.Check(werr, "writing error response") } la := loginAttempt(r, "webapi", "httpbasic") @@ -524,10 +520,12 @@ func (s server) ServeHTTP(w http.ResponseWriter, r *http.Request) { closeAccount() log.Debug("webapi call result", slog.String("resultcode", "ok")) metricResults.WithLabelValues(fn, "ok").Inc() - defer rc.Close() - if _, err := io.Copy(w, rc); err != nil && !moxio.IsClosed(err) { - log.Errorx("writing response to client", err) - } + defer func() { + err := rc.Close() + log.Check(err, "closing readcloser") + }() + _, err = io.Copy(w, rc) + log.Check(err, "writing response to client") } // loginAttempt initializes a store.LoginAttempt, for adding to the store after @@ -955,7 +953,8 @@ func (s server) Send(ctx context.Context, req webapi.SendRequest) (resp webapi.S } } if alternative != nil { - alternative.Close() + err := alternative.Close() + xcheckf(err, "closing alternative part") alternative = nil } @@ -967,7 +966,8 @@ func (s server) Send(ctx context.Context, req webapi.SendRequest) (resp webapi.S } } if related != nil { - related.Close() + err := related.Close() + xcheckf(err, "closing related part") related = nil } cur = mixed @@ -978,7 +978,8 @@ func (s server) Send(ctx context.Context, req webapi.SendRequest) (resp webapi.S } } if mixed != nil { - mixed.Close() + err := mixed.Close() + xcheckf(err, "closing mixed part") mixed = nil } cur = nil @@ -1222,7 +1223,8 @@ func (s server) MessageGet(ctx context.Context, req webapi.MessageGetRequest) (r }) defer func() { if err != nil { - msgr.Close() + err := msgr.Close() + log.Check(err, "cleaning up message reader") } }() @@ -1327,6 +1329,7 @@ func (s server) MessageRawGet(ctx context.Context, req webapi.MessageRawGetReque func (s server) MessagePartGet(ctx context.Context, req webapi.MessagePartGetRequest) (resp io.ReadCloser, err error) { reqInfo := ctx.Value(requestInfoCtxKey).(requestInfo) + log := reqInfo.Log acc := reqInfo.Account var m store.Message @@ -1337,7 +1340,8 @@ func (s server) MessagePartGet(ctx context.Context, req webapi.MessagePartGetReq }) defer func() { if err != nil { - msgr.Close() + err := msgr.Close() + log.Check(err, "cleaning up message reader") } }() diff --git a/webauth/webauth.go b/webauth/webauth.go index a34cdb8..f1322d1 100644 --- a/webauth/webauth.go +++ b/webauth/webauth.go @@ -121,7 +121,8 @@ func Check(ctx context.Context, log mlog.Log, sessionAuth SessionAuth, kind stri }{ sherpa.Error{Code: code, Message: msg}, } - json.NewEncoder(w).Encode(result) + err := json.NewEncoder(w).Encode(result) + log.Check(err, "writing error response") } else { http.Error(w, "403 - forbidden - "+msg, http.StatusForbidden) } diff --git a/webmail/view.go b/webmail/view.go index ada0e94..c48b86a 100644 --- a/webmail/view.go +++ b/webmail/view.go @@ -29,7 +29,6 @@ import ( "github.com/mjl-/mox/metrics" "github.com/mjl-/mox/mlog" "github.com/mjl-/mox/mox-" - "github.com/mjl-/mox/moxio" "github.com/mjl-/mox/moxvar" "github.com/mjl-/mox/smtp" "github.com/mjl-/mox/store" @@ -892,7 +891,7 @@ func serveEvents(ctx context.Context, log mlog.Log, accountPath string, w http.R continue } - state := msgState{acc: acc} + state := msgState{acc: acc, log: log} mi, err := messageItem(log, m, &state, xmoreHeaders()) state.clear() xcheckf(ctx, err, "make messageitem") @@ -1000,6 +999,9 @@ func serveEvents(ctx context.Context, log mlog.Log, accountPath string, w http.R case <-timer.C: _, err := fmt.Fprintf(out, ": keepalive\n\n") + if err == nil { + err = out.Flush() + } if err != nil { log.Errorx("write keepalive", err) // Work around go vet, it doesn't see defer cancelDrain. @@ -1008,7 +1010,6 @@ func serveEvents(ctx context.Context, log mlog.Log, accountPath string, w http.R } return } - out.Flush() writer.wrote = true case vm := <-viewMsgsc: @@ -1027,7 +1028,7 @@ func serveEvents(ctx context.Context, log mlog.Log, accountPath string, w http.R if ve.RequestID != v.Request.ID || ve.ViewID != v.Request.ViewID { panic(fmt.Sprintf("received err for view,request id %d,%d instead of %d,%d", ve.ViewID, ve.RequestID, v.Request.ViewID, v.Request.ID)) } - if errors.Is(ve.err, context.Canceled) || moxio.IsClosed(ve.err) { + if errors.Is(ve.err, context.Canceled) || mlog.IsClosed(ve.err) { // Work around go vet, it doesn't see defer cancelDrain. if reqctxcancel != nil { reqctxcancel() @@ -1221,7 +1222,7 @@ func (v view) matches(log mlog.Log, acc *store.Account, checkRange bool, message return false, rerr } - state := msgState{acc: acc} + state := msgState{acc: acc, log: log} defer func() { if rerr == nil && state.err != nil { rerr = state.err @@ -1452,7 +1453,7 @@ func queryMessages(ctx context.Context, log mlog.Log, acc *store.Account, tx *bs // implement reporting errors, or anything else, just a bool. So when making the // filter functions, we give them a place to store parsed message state, and an // error. We check the error during and after query execution. - state := msgState{acc: acc} + state := msgState{acc: acc, log: log} defer state.clear() flagfilter := query.flagFilterFn() @@ -1642,7 +1643,7 @@ func gatherThread(log mlog.Log, tx *bstore.Tx, acc *store.Account, v view, m sto var firstUnread bool for _, tm := range tml { err := func() error { - xstate := msgState{acc: acc} + xstate := msgState{acc: acc, log: log} defer xstate.clear() mi, err := messageItem(log, tm, &xstate, moreHeaders) @@ -1678,7 +1679,7 @@ func gatherThread(log mlog.Log, tx *bstore.Tx, acc *store.Account, v view, m sto // Finally, the message that caused us to gather this thread (which is likely the // most recent message in the thread) could be the only unread message. if destMessageID == 0 && first && !m.Seen && !firstUnread { - xstate := msgState{acc: acc} + xstate := msgState{acc: acc, log: log} defer xstate.clear() xpm, err := parsedMessage(log, m, &xstate, true, false, false) if err != nil && errors.Is(err, message.ErrHeader) { @@ -1704,14 +1705,16 @@ type msgState struct { m store.Message part *message.Part // Will be without Reader when msgr is nil. msgr *store.MsgReader + log mlog.Log } func (ms *msgState) clear() { if ms.msgr != nil { - ms.msgr.Close() + err := ms.msgr.Close() + ms.log.Check(err, "closing message reader from state") ms.msgr = nil } - *ms = msgState{acc: ms.acc, err: ms.err} + *ms = msgState{acc: ms.acc, err: ms.err, log: ms.log} } func (ms *msgState) ensureMsg(m store.Message) { diff --git a/webmail/webmail.go b/webmail/webmail.go index 71f70ee..a02b418 100644 --- a/webmail/webmail.go +++ b/webmail/webmail.go @@ -197,7 +197,10 @@ func serveContentFallback(log mlog.Log, w http.ResponseWriter, r *http.Request, f, err := os.Open(path) if err == nil { - defer f.Close() + defer func() { + err := f.Close() + log.Check(err, "closing serve file") + }() st, err := f.Stat() if err == nil { serve(st.ModTime(), f) @@ -841,9 +844,7 @@ func handle(apiHandler http.Handler, isForwarded bool, accountPath string, w htt } _, err := io.Copy(w, ap.Reader()) - if err != nil && !moxio.IsClosed(err) { - log.Errorx("copying attachment", err) - } + log.Check(err, "copying attachment") default: http.NotFound(w, r) }