logging: added a log on panic

Since panics still regularly "destroy" the terminal, it is hard to get a
stack trace for panics you do not anticipate. This commit adds a panic
handler that automatically creates a logfile inside the current working
directory.

It has to be added to every goroutine that is started and will repair
the terminal on a panic.

Signed-off-by: Moritz Poldrack <git@moritz.sh>
Acked-by: Robin Jarry <robin@jarry.cc>

aerc.go

@@ -7,7 +7,6 @@ import (
 	"io/ioutil"
 	"log"
 	"os"
-	"runtime/debug"
 	"sort"
 	"time"
 
@@ -25,6 +24,7 @@ import (
 	"git.sr.ht/~rjarry/aerc/lib"
 	"git.sr.ht/~rjarry/aerc/lib/templates"
 	libui "git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/widgets"
 )
 
@@ -112,6 +112,7 @@ func setWindowTitle() {
 }
 
 func main() {
+	defer logging.PanicHandler()
 	opts, optind, err := getopt.Getopts(os.Args, "v")
 	if err != nil {
 		log.Print(err)
@@ -165,8 +166,6 @@ func main() {
 		ui   *libui.UI
 	)
 
-	defer PanicTermFix(ui) // recover upon panic and try restoring the pty
-
 	aerc = widgets.NewAerc(conf, logger, func(cmd []string) error {
 		return execCommand(aerc, ui, cmd)
 	}, func(cmd string) []string {
@@ -178,6 +177,9 @@ func main() {
 		panic(err)
 	}
 	defer ui.Close()
+	logging.UICleanup = func() {
+		ui.Close()
+	}
 
 	if conf.Ui.MouseEnabled {
 		ui.EnableMouse()
@@ -225,19 +227,3 @@ func main() {
 	}
 	aerc.CloseBackends()
 }
-
-//FatalTermFix prints the stacktrace upon panic and tries to recover the term
-// not doing that leaves the terminal in a broken state
-func PanicTermFix(ui *libui.UI) {
-	var err interface{}
-	if err = recover(); err == nil {
-		return
-	}
-	debug.PrintStack()
-	if ui != nil {
-		ui.Close()
-	}
-	fmt.Fprintf(os.Stderr, "aerc crashed: %v\n", err)
-	os.Exit(1)
-
-}

commands/account/compose.go

@@ -5,6 +5,7 @@ import (
 	"regexp"
 	"strings"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~sircmpwn/getopt"
@@ -52,7 +53,11 @@ func (Compose) Execute(aerc *widgets.Aerc, args []string) error {
 		}
 		tab.Content.Invalidate()
 	})
-	go composer.AppendContents(strings.NewReader(body))
+	go func() {
+		defer logging.PanicHandler()
+
+		composer.AppendContents(strings.NewReader(body))
+	}()
 	return nil
 }
 

commands/account/recover.go

@@ -8,6 +8,7 @@ import (
 	"path/filepath"
 
 	"git.sr.ht/~rjarry/aerc/commands"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~sircmpwn/getopt"
@@ -111,7 +112,11 @@ func (Recover) Execute(aerc *widgets.Aerc, args []string) error {
 		tab.Name = subject
 		tab.Content.Invalidate()
 	})
-	go composer.AppendContents(bytes.NewReader(data))
+	go func() {
+		defer logging.PanicHandler()
+
+		composer.AppendContents(bytes.NewReader(data))
+	}()
 
 	// remove file if force flag is set
 	if force {

commands/compose/postpone.go

@@ -8,6 +8,7 @@ import (
 	"github.com/miolini/datacounter"
 	"github.com/pkg/errors"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~rjarry/aerc/worker/types"
@@ -66,6 +67,8 @@ func (Postpone) Execute(aerc *widgets.Aerc, args []string) error {
 	// run this as a goroutine so we can make other progress. The message
 	// will be saved once the directory is created.
 	go func() {
+		defer logging.PanicHandler()
+
 		errStr := <-errChan
 		if errStr != "" {
 			aerc.PushError(errStr)

commands/compose/send.go

@@ -16,6 +16,7 @@ import (
 	"github.com/pkg/errors"
 
 	"git.sr.ht/~rjarry/aerc/lib"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~rjarry/aerc/worker/types"
@@ -100,6 +101,8 @@ func (Send) Execute(aerc *widgets.Aerc, args []string) error {
 	failCh := make(chan error)
 	//writer
 	go func() {
+		defer logging.PanicHandler()
+
 		var sender io.WriteCloser
 		switch ctx.scheme {
 		case "smtp":
@@ -131,6 +134,8 @@ func (Send) Execute(aerc *widgets.Aerc, args []string) error {
 
 	//cleanup + copy to sent
 	go func() {
+		defer logging.PanicHandler()
+
 		err = <-failCh
 		if err != nil {
 			aerc.PushError(strings.ReplaceAll(err.Error(), "\n", " "))

commands/exec.go

@@ -7,6 +7,7 @@ import (
 	"os/exec"
 	"time"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/widgets"
 )
 
@@ -45,6 +46,8 @@ func (ExecCmd) Execute(aerc *widgets.Aerc, args []string) error {
 	cmd.Env = env
 
 	go func() {
+		defer logging.PanicHandler()
+
 		err := cmd.Run()
 		if err != nil {
 			aerc.PushError(err.Error())

commands/msg/archive.go

@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"git.sr.ht/~rjarry/aerc/commands"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~rjarry/aerc/worker/types"
@@ -94,6 +95,8 @@ func (Archive) Execute(aerc *widgets.Aerc, args []string) error {
 	}
 	// we need to do that in the background, else we block the main thread
 	go func() {
+		defer logging.PanicHandler()
+
 		wg.Wait()
 		if success {
 			aerc.PushStatus("Messages archived.", 10*time.Second)

commands/msg/pipe.go

@@ -9,6 +9,7 @@ import (
 	"time"
 
 	"git.sr.ht/~rjarry/aerc/commands"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~rjarry/aerc/worker/types"
 
@@ -89,6 +90,8 @@ func (Pipe) Execute(aerc *widgets.Aerc, args []string) error {
 			return
 		}
 		go func() {
+			defer logging.PanicHandler()
+
 			defer pipe.Close()
 			io.Copy(pipe, reader)
 		}()
@@ -146,6 +149,8 @@ func (Pipe) Execute(aerc *widgets.Aerc, args []string) error {
 		})
 
 		go func() {
+			defer logging.PanicHandler()
+
 			select {
 			case <-done:
 				break

commands/msg/read.go

@@ -8,6 +8,7 @@ import (
 	"git.sr.ht/~sircmpwn/getopt"
 
 	"git.sr.ht/~rjarry/aerc/lib"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"git.sr.ht/~rjarry/aerc/worker/types"
@@ -169,6 +170,8 @@ func (FlagMsg) Execute(aerc *widgets.Aerc, args []string) error {
 
 	// We need to do flagging in the background, else we block the main thread
 	go func() {
+		defer logging.PanicHandler()
+
 		wg.Wait()
 		if success {
 			aerc.PushStatus(actionName+" flag '"+flagName+"' successful", 10*time.Second)

commands/msgview/open.go

@@ -9,6 +9,7 @@ import (
 	"time"
 
 	"git.sr.ht/~rjarry/aerc/lib"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/widgets"
 )
 
@@ -66,6 +67,8 @@ func (Open) Execute(aerc *widgets.Aerc, args []string) error {
 			return
 		}
 		go func() {
+			defer logging.PanicHandler()
+
 			err := xdg.Wait()
 			if err != nil {
 				aerc.PushError(err.Error())

commands/msgview/save.go

@@ -13,6 +13,7 @@ import (
 	"github.com/mitchellh/go-homedir"
 
 	"git.sr.ht/~rjarry/aerc/commands"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 )
@@ -126,6 +127,8 @@ func (Save) Execute(aerc *widgets.Aerc, args []string) error {
 
 	// we need to wait for the callback prior to displaying a result
 	go func() {
+		defer logging.PanicHandler()
+
 		err := <-ch
 		if err != nil {
 			aerc.PushError(fmt.Sprintf("Save failed: %v", err))

commands/util.go

@@ -13,6 +13,7 @@ import (
 	"github.com/lithammer/fuzzysearch/fuzzy"
 
 	"git.sr.ht/~rjarry/aerc/lib"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/widgets"
 	"github.com/gdamore/tcell/v2"
@@ -51,6 +52,8 @@ func QuickTerm(aerc *widgets.Aerc, args []string, stdin io.Reader) (*widgets.Ter
 		status := make(chan error, 1)
 
 		go func() {
+			defer logging.PanicHandler()
+
 			_, err := io.Copy(pipe, stdin)
 			defer pipe.Close()
 			status <- err

lib/open.go

@@ -3,6 +3,8 @@ package lib
 import (
 	"os/exec"
 	"runtime"
+
+	"git.sr.ht/~rjarry/aerc/logging"
 )
 
 var openBin string = "xdg-open"
@@ -49,6 +51,8 @@ func (xdg *xdgOpen) Start() error {
 		return err
 	}
 	go func() {
+		defer logging.PanicHandler()
+
 		xdg.errCh <- xdg.cmd.Wait()
 		close(xdg.errCh)
 	}()

lib/socket.go

@@ -13,6 +13,7 @@ import (
 	"sync/atomic"
 	"time"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"github.com/kyoh86/xdg"
 )
 
@@ -36,6 +37,8 @@ func StartServer(logger *log.Logger) (*AercServer, error) {
 	}
 	// TODO: stash clients and close them on exit... bleh racey
 	go func() {
+		defer logging.PanicHandler()
+
 		for {
 			conn, err := l.Accept()
 			if err != nil {
@@ -44,7 +47,11 @@ func StartServer(logger *log.Logger) (*AercServer, error) {
 				as.logger.Printf("Closing Unix server: %v", err)
 				return
 			}
-			go as.handleClient(conn)
+			go func() {
+				defer logging.PanicHandler()
+
+				as.handleClient(conn)
+			}()
 		}
 	}()
 	return as, nil

lib/ui/ui.go

@@ -3,6 +3,7 @@ package ui
 import (
 	"sync/atomic"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"github.com/gdamore/tcell/v2"
 )
 
@@ -43,6 +44,8 @@ func Initialize(content DrawableInteractive) (*UI, error) {
 
 	state.exit.Store(false)
 	go func() {
+		defer logging.PanicHandler()
+
 		for !state.ShouldExit() {
 			state.tcEvents <- screen.PollEvent()
 		}

logging/panic-logger.go

@@ -0,0 +1,56 @@
+package logging
+
+import (
+	"fmt"
+	"io"
+	"os"
+	"runtime/debug"
+	"strings"
+	"time"
+)
+
+var UICleanup = func() {}
+
+// PanicHandler tries to restore the terminal. A stack trace is written to
+// aerc-crash.log and then passed on if a panic occurs.
+func PanicHandler() {
+	r := recover()
+
+	if r == nil {
+		return
+	}
+
+	UICleanup()
+
+	filename := time.Now().Format("/tmp/aerc-crash-20060102-150405.log")
+
+	panicLog, err := os.OpenFile(filename, os.O_SYNC|os.O_APPEND|os.O_CREATE|os.O_WRONLY|os.O_EXCL, 0o600)
+	if err != nil {
+		// we tried, not possible. bye
+		panic(r)
+	}
+	defer panicLog.Close()
+
+	outputs := io.MultiWriter(panicLog, os.Stderr)
+
+	// if any error happens here, we do not care.
+	fmt.Fprintln(panicLog, strings.Repeat("#", 80))
+	fmt.Fprint(panicLog, strings.Repeat(" ", 34))
+	fmt.Fprintln(panicLog, "PANIC CAUGHT!")
+	fmt.Fprint(panicLog, strings.Repeat(" ", 24))
+	fmt.Fprintln(panicLog, time.Now().Format("2006-01-02T15:04:05.000000-0700"))
+	fmt.Fprintln(panicLog, strings.Repeat("#", 80))
+	fmt.Fprintf(outputs, "%s\n", panicMessage)
+	fmt.Fprintf(panicLog, "Error: %v\n\n", r)
+	panicLog.Write(debug.Stack())
+	fmt.Fprintf(os.Stderr, "\nThis error was also written to: %s\n", filename)
+	panic(r)
+}
+
+const panicMessage = `
+aerc has encountered a critical error and has terminated. Please help us fixing
+this by sending this log and the steps to reproduce the crash to:
+~rjarry/aerc-devel@lists.sr.ht
+
+Thank you
+`

widgets/account.go

@@ -13,6 +13,7 @@ import (
 	"git.sr.ht/~rjarry/aerc/lib/sort"
 	"git.sr.ht/~rjarry/aerc/lib/statusline"
 	"git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/worker"
 	"git.sr.ht/~rjarry/aerc/worker/types"
@@ -86,7 +87,11 @@ func NewAccountView(aerc *Aerc, conf *config.AercConfig, acct *config.AccountCon
 	view.msglist = NewMessageList(conf, logger, aerc)
 	view.grid.AddChild(view.msglist).At(0, 1)
 
-	go worker.Backend.Run()
+	go func() {
+		defer logging.PanicHandler()
+
+		worker.Backend.Run()
+	}()
 
 	worker.PostAction(&types.Configure{Config: acct}, nil)
 	worker.PostAction(&types.Connect{}, nil)

widgets/dirlist.go

@@ -16,6 +16,7 @@ import (
 	"git.sr.ht/~rjarry/aerc/lib"
 	libsort "git.sr.ht/~rjarry/aerc/lib/sort"
 	"git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/worker/types"
 )
@@ -128,6 +129,8 @@ func (dirlist *DirectoryList) Select(name string) {
 	dirlist.skipSelect = make(chan bool)
 
 	go func() {
+		defer logging.PanicHandler()
+
 		select {
 		case <-time.After(dirlist.UiConfig().DirListDelay):
 			dirlist.worker.PostAction(&types.OpenDirectory{Directory: name},

widgets/msgviewer.go

@@ -19,6 +19,7 @@ import (
 	"git.sr.ht/~rjarry/aerc/lib"
 	"git.sr.ht/~rjarry/aerc/lib/format"
 	"git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 )
 
@@ -600,6 +601,8 @@ func (pv *PartViewer) attemptCopy() {
 		pv.copyFilterOutToPager() //delayed until we write to the sink
 	}
 	go func() {
+		defer logging.PanicHandler()
+
 		pv.writeMailHeaders()
 		if strings.EqualFold(pv.part.MIMEType, "text") {
 			// if the content is plain we can strip ansi control chars
@@ -645,6 +648,8 @@ func (pv *PartViewer) copyFilterOutToPager() {
 	pv.filter.Start()
 	ch := make(chan interface{})
 	go func() {
+		defer logging.PanicHandler()
+
 		_, err := io.Copy(pv.pagerin, stdout)
 		if err != nil {
 			pv.err = err
@@ -654,6 +659,8 @@ func (pv *PartViewer) copyFilterOutToPager() {
 		ch <- nil
 	}()
 	go func() {
+		defer logging.PanicHandler()
+
 		_, err := io.Copy(pv.pagerin, stderr)
 		if err != nil {
 			pv.err = err
@@ -663,6 +670,8 @@ func (pv *PartViewer) copyFilterOutToPager() {
 		ch <- nil
 	}()
 	go func() {
+		defer logging.PanicHandler()
+
 		<-ch
 		<-ch
 		pv.filter.Wait()

widgets/spinner.go

@@ -9,6 +9,7 @@ import (
 
 	"git.sr.ht/~rjarry/aerc/config"
 	"git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 )
 
 type Spinner struct {
@@ -37,6 +38,8 @@ func (s *Spinner) Start() {
 	atomic.StoreInt64(&s.frame, 0)
 
 	go func() {
+		defer logging.PanicHandler()
+
 		for {
 			select {
 			case <-s.stop:

widgets/status.go

@@ -8,6 +8,7 @@ import (
 
 	"git.sr.ht/~rjarry/aerc/config"
 	"git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 )
 
 type StatusLine struct {
@@ -78,6 +79,8 @@ func (status *StatusLine) Push(text string, expiry time.Duration) *StatusMessage
 	}
 	status.stack = append(status.stack, msg)
 	go (func() {
+		defer logging.PanicHandler()
+
 		time.Sleep(expiry)
 		for i, m := range status.stack {
 			if m == msg {

widgets/terminal.go

@@ -7,6 +7,7 @@ import (
 	"syscall"
 
 	"git.sr.ht/~rjarry/aerc/lib/ui"
+	"git.sr.ht/~rjarry/aerc/logging"
 
 	"github.com/creack/pty"
 	vterm "github.com/ddevault/go-libvterm"
@@ -124,6 +125,8 @@ func NewTerminal(cmd *exec.Cmd) (*Terminal, error) {
 	term.start = make(chan interface{})
 	screen := term.vterm.ObtainScreen()
 	go func() {
+		defer logging.PanicHandler()
+
 		<-term.start
 		buf := make([]byte, 4096)
 		for {

worker/imap/fetch.go

@@ -10,6 +10,7 @@ import (
 	"github.com/emersion/go-message/mail"
 	"github.com/emersion/go-message/textproto"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/worker/types"
 )
@@ -169,6 +170,8 @@ func (imapw *IMAPWorker) handleFetchMessages(
 	done := make(chan error)
 
 	go func() {
+		defer logging.PanicHandler()
+
 		var reterr error
 		for _msg := range messages {
 			imapw.seqMap[_msg.SeqNum-1] = _msg.Uid

worker/imap/flags.go

@@ -4,6 +4,7 @@ import (
 	"fmt"
 	"github.com/emersion/go-imap"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/worker/types"
 )
 
@@ -22,6 +23,8 @@ func (imapw *IMAPWorker) handleDeleteMessages(msg *types.DeleteMessages) {
 	ch := make(chan uint32)
 	done := make(chan interface{})
 	go func() {
+		defer logging.PanicHandler()
+
 		for seqNum := range ch {
 			i := seqNum - 1
 			deleted = append(deleted, imapw.seqMap[i])

worker/imap/list.go

@@ -3,6 +3,7 @@ package imap
 import (
 	"github.com/emersion/go-imap"
 
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/worker/types"
 )
@@ -13,6 +14,8 @@ func (imapw *IMAPWorker) handleListDirectories(msg *types.ListDirectories) {
 	done := make(chan interface{})
 
 	go func() {
+		defer logging.PanicHandler()
+
 		for mbox := range mailboxes {
 			if !canOpen(mbox) {
 				// no need to pass this to handlers if it can't be opened

worker/imap/worker.go

@@ -17,6 +17,7 @@ import (
 	"golang.org/x/oauth2"
 
 	"git.sr.ht/~rjarry/aerc/lib"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/worker/handlers"
 	"git.sr.ht/~rjarry/aerc/worker/types"
@@ -83,6 +84,8 @@ func (w *IMAPWorker) handleMessage(msg types.WorkerMessage) error {
 		if w.client != nil && w.client.State() == imap.SelectedState {
 			w.idleStop = make(chan struct{})
 			go func() {
+				defer logging.PanicHandler()
+
 				w.idleDone <- w.client.Idle(w.idleStop, &client.IdleOptions{LogoutTimeout: 0, PollInterval: 0})
 			}()
 		}

worker/notmuch/worker.go

@@ -16,6 +16,7 @@ import (
 
 	"git.sr.ht/~rjarry/aerc/config"
 	"git.sr.ht/~rjarry/aerc/lib/uidstore"
+	"git.sr.ht/~rjarry/aerc/logging"
 	"git.sr.ht/~rjarry/aerc/models"
 	"git.sr.ht/~rjarry/aerc/worker/handlers"
 	"git.sr.ht/~rjarry/aerc/worker/lib"
@@ -180,6 +181,8 @@ func (w *worker) handleConnect(msg *types.Connect) error {
 	w.done(msg)
 	w.emitLabelList()
 	go func() {
+		defer logging.PanicHandler()
+
 		for {
 			w.nmEvents <- &updateDirCounts{}
 			time.Sleep(backgroundRefreshDelay)