[NOD-487] Implement a mechanism to gracefully shut down after a panic (#512)

* [NOD-487] Implement a mechanism to gracefully shut down after a panic.

* [NOD-487] Fixed bad log.

* [NOD-487] Removed unused import.

* [NOD-487] Convert panic handlers from anonymous functions to methods.

addrmgr/addrmanager.go

@@ -724,7 +724,11 @@ func (a *AddrManager) Start() {
 
 	// Start the address ticker to save addresses periodically.
 	a.wg.Add(1)
-	spawn(a.addressHandler)
+	spawn(a.addressHandler, a.handlePanic)
+}
+
+func (a *AddrManager) handlePanic() {
+	atomic.AddInt32(&a.shutdown, 1)
 }
 
 // Stop gracefully shuts down the address manager by stopping the main handler.

addrmgr/log.go

@@ -10,4 +10,4 @@ import (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.ADXR)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFuncWithPanicHandler(log)

apiserver/database/log.go

@@ -5,5 +5,5 @@ import "github.com/daglabs/btcd/apiserver/logger"
 
 var (
 	log   = logger.Logger("DTBS")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

apiserver/jsonrpc/log.go

@@ -8,9 +8,9 @@ import (
 
 var (
 	log   = logger.BackendLog.Logger("RPCC")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )
 
 func init() {
-	rpcclient.UseLogger(log, logger.BackendLog)
+	rpcclient.UseLogger(log)
 }

apiserver/log.go

@@ -7,5 +7,5 @@ import (
 
 var (
 	log   = logger.Logger("APIS")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

apiserver/main.go

@@ -10,7 +10,6 @@ import (
 	"github.com/daglabs/btcd/apiserver/database"
 	"github.com/daglabs/btcd/apiserver/jsonrpc"
 	"github.com/daglabs/btcd/apiserver/server"
-	"github.com/daglabs/btcd/logger"
 	"github.com/daglabs/btcd/signal"
 	"github.com/daglabs/btcd/util/panics"
 	_ "github.com/golang-migrate/migrate/v4/database/mysql"
@@ -19,7 +18,7 @@ import (
 )
 
 func main() {
-	defer panics.HandlePanic(log, logger.BackendLog, nil)
+	defer panics.HandlePanic(log, nil, nil)
 
 	err := config.Parse()
 	if err != nil {

apiserver/mqtt/log.go

@@ -5,5 +5,5 @@ import "github.com/daglabs/btcd/apiserver/logger"
 
 var (
 	log   = logger.Logger("MQTT")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

apiserver/server/log.go

@@ -5,5 +5,5 @@ import "github.com/daglabs/btcd/apiserver/logger"
 
 var (
 	log   = logger.Logger("REST")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

blockdag/indexers/log.go

@@ -10,4 +10,4 @@ import (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.INDX)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFunc(log)

blockdag/log.go

@@ -10,4 +10,4 @@ import (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.BDAG)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFunc(log)

btcd.go

@@ -6,7 +6,6 @@ package main
 
 import (
 	"fmt"
-	"github.com/daglabs/btcd/logger"
 	"net"
 	"net/http"
 	_ "net/http/pprof"
@@ -57,7 +56,7 @@ func btcdMain(serverChan chan<- *server.Server) error {
 		return err
 	}
 	cfg = config.ActiveConfig()
-	defer panics.HandlePanic(btcdLog, logger.BackendLog, nil)
+	defer panics.HandlePanic(btcdLog, nil, nil)
 
 	// Get a channel that will be closed when a shutdown signal has been
 	// triggered either from an OS signal such as SIGINT (Ctrl+C) or from

cmd/addblock/addblock.go

@@ -72,7 +72,7 @@ func realMain() error {
 	backendLogger := logs.NewBackend()
 	defer os.Stdout.Sync()
 	log = backendLogger.Logger("MAIN")
-	spawn = panics.GoroutineWrapperFunc(log, backendLogger)
+	spawn = panics.GoroutineWrapperFunc(log)
 
 	// Load the block database.
 	db, err := loadBlockDB()

cmd/txgen/log.go

@@ -10,7 +10,7 @@ import (
 var (
 	backendLog = logs.NewBackend()
 	log        = backendLog.Logger("TXGN")
-	spawn      = panics.GoroutineWrapperFunc(log, backendLog)
+	spawn      = panics.GoroutineWrapperFunc(log)
 )
 
 func initLog(logFile, errLogFile string) {

cmd/txgen/main.go

@@ -23,7 +23,7 @@ func privateKeyToP2pkhAddress(key *btcec.PrivateKey, net *dagconfig.Params) (uti
 }
 
 func main() {
-	defer panics.HandlePanic(log, backendLog, nil)
+	defer panics.HandlePanic(log, nil, nil)
 
 	cfg, err := parseConfig()
 	if err != nil {

connmgr/connmanager.go

@@ -247,7 +247,7 @@ func (cm *ConnManager) handleFailedConn(c *ConnReq, err error) {
 				cm.NewConnReq()
 			})
 		} else {
-			spawn(cm.NewConnReq)
+			spawn(cm.NewConnReq, cm.handlePanic)
 		}
 	}
 }
@@ -584,7 +584,7 @@ func (cm *ConnManager) Start() {
 
 	log.Trace("Connection manager started")
 	cm.wg.Add(1)
-	spawn(cm.connHandler)
+	spawn(cm.connHandler, cm.handlePanic)
 
 	// Start all the listeners so long as the caller requested them and
 	// provided a callback to be invoked when connections are accepted.
@@ -596,7 +596,7 @@ func (cm *ConnManager) Start() {
 	}
 
 	for i := atomic.LoadUint64(&cm.connReqCount); i < uint64(cm.cfg.TargetOutbound); i++ {
-		spawn(cm.NewConnReq)
+		spawn(cm.NewConnReq, cm.handlePanic)
 	}
 }
 
@@ -605,6 +605,10 @@ func (cm *ConnManager) Wait() {
 	cm.wg.Wait()
 }
 
+func (cm *ConnManager) handlePanic() {
+	atomic.AddInt32(&cm.stop, 1)
+}
+
 // Stop gracefully shuts down the connection manager.
 func (cm *ConnManager) Stop() {
 	if atomic.AddInt32(&cm.stop, 1) != 1 {

connmgr/log.go

@@ -10,4 +10,4 @@ import (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.CMGR)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFuncWithPanicHandler(log)

database/cmd/dbtool/main.go

@@ -67,7 +67,7 @@ func realMain() error {
 	backendLogger := logs.NewBackend()
 	defer os.Stdout.Sync()
 	log = backendLogger.Logger("MAIN")
-	spawn = panics.GoroutineWrapperFunc(log, backendLogger)
+	spawn = panics.GoroutineWrapperFunc(log)
 	dbLog, _ := logger.Get(logger.SubsystemTags.BCDB)
 	dbLog.SetLevel(logs.LevelDebug)
 

dnsseeder/dnsseed.go

@@ -156,7 +156,7 @@ func creep() {
 }
 
 func main() {
-	defer panics.HandlePanic(log, backendLog, nil)
+	defer panics.HandlePanic(log, nil, nil)
 	cfg, err := loadConfig()
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "loadConfig: %v\n", err)

dnsseeder/log.go

@@ -10,7 +10,7 @@ import (
 var (
 	backendLog = logs.NewBackend()
 	log        = backendLog.Logger("SEED")
-	spawn      = panics.GoroutineWrapperFunc(log, backendLog)
+	spawn      = panics.GoroutineWrapperFunc(log)
 )
 
 func initLog(logFile, errLogFile string) {

faucet/database/log.go

@@ -5,5 +5,5 @@ import "github.com/daglabs/btcd/apiserver/logger"
 
 var (
 	log   = logger.BackendLog.Logger("DTBS")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

faucet/log.go

@@ -7,5 +7,5 @@ import (
 
 var (
 	log   = logger.BackendLog.Logger("FAUC")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

faucet/main.go

@@ -12,7 +12,6 @@ import (
 	"github.com/pkg/errors"
 	"os"
 
-	"github.com/daglabs/btcd/logger"
 	"github.com/daglabs/btcd/signal"
 	"github.com/daglabs/btcd/util/panics"
 	_ "github.com/golang-migrate/migrate/v4/database/mysql"
@@ -27,7 +26,7 @@ var (
 )
 
 func main() {
-	defer panics.HandlePanic(log, logger.BackendLog, nil)
+	defer panics.HandlePanic(log, nil, nil)
 
 	err := config.Parse()
 	if err != nil {

httpserverutils/log.go

@@ -5,5 +5,5 @@ import "github.com/daglabs/btcd/apiserver/logger"
 
 var (
 	log   = logger.BackendLog.Logger("UTIL")
-	spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 )

log.go

@@ -11,5 +11,5 @@ import (
 )
 
 var btcdLog, _ = logger.Get(logger.SubsystemTags.BTCD)
-var spawn = panics.GoroutineWrapperFunc(btcdLog, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFunc(btcdLog)
 var srvrLog, _ = logger.Get(logger.SubsystemTags.SRVR)

mining/cpuminer/log.go

@@ -10,4 +10,4 @@ import (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.MINR)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFunc(log)

mining/simulator/log.go

@@ -11,7 +11,7 @@ import (
 var (
 	backendLog = logs.NewBackend()
 	log        = backendLog.Logger("MNSM")
-	spawn      = panics.GoroutineWrapperFunc(log, backendLog)
+	spawn      = panics.GoroutineWrapperFunc(log)
 )
 
 func initLog(logFile, errLogFile string) {
@@ -30,5 +30,5 @@ func initLog(logFile, errLogFile string) {
 func enableRPCLogging() {
 	rpclog := backendLog.Logger("RPCC")
 	rpclog.SetLevel(logs.LevelTrace)
-	rpcclient.UseLogger(rpclog, backendLog)
+	rpcclient.UseLogger(rpclog)
 }

mining/simulator/main.go

@@ -11,7 +11,7 @@ import (
 )
 
 func main() {
-	defer panics.HandlePanic(log, backendLog, nil)
+	defer panics.HandlePanic(log, nil, nil)
 	cfg, err := parseConfig()
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Error parsing command-line arguments: %s", err)

netsync/log.go

@@ -10,4 +10,4 @@ import (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.SYNC)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFuncWithPanicHandler(log)

netsync/manager.go

@@ -622,7 +622,7 @@ func (sm *SyncManager) handleBlockMsg(bmsg *blockMsg) {
 	if delay != 0 {
 		spawn(func() {
 			sm.QueueBlock(bmsg.block, bmsg.peer, true, make(chan struct{}))
-		})
+		}, sm.handlePanic)
 	}
 
 	// Request the parents for the orphan block from the peer that sent it.
@@ -1289,7 +1289,7 @@ func (sm *SyncManager) handleBlockDAGNotification(notification *blockdag.Notific
 			if err != nil {
 				panic(fmt.Sprintf("HandleNewBlock failed to handle block %s", block.Hash()))
 			}
-		})
+		}, sm.handlePanic)
 
 		// Relay if we are current and the block was not just now unorphaned.
 		// Otherwise peers that are current should already know about it
@@ -1393,7 +1393,11 @@ func (sm *SyncManager) Start() {
 
 	log.Trace("Starting sync manager")
 	sm.wg.Add(1)
-	spawn(sm.blockHandler)
+	spawn(sm.blockHandler, sm.handlePanic)
+}
+
+func (sm *SyncManager) handlePanic() {
+	atomic.AddInt32(&sm.shutdown, 1)
 }
 
 // Stop gracefully shuts down the sync manager by stopping all asynchronous

peer/log.go

@@ -22,7 +22,7 @@ const (
 )
 
 var log, _ = logger.Get(logger.SubsystemTags.PEER)
-var spawn = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+var spawn = panics.GoroutineWrapperFunc(log)
 
 // LogClosure is a closure that can be printed with %s to be used to
 // generate expensive-to-create data for a detailed log level and avoid doing

rpcclient/log.go

@@ -24,13 +24,13 @@ func init() {
 // by default until UseLogger is called.
 func DisableLog() {
 	log = logs.Disabled
-	spawn = panics.GoroutineWrapperFunc(log, nil)
+	spawn = panics.GoroutineWrapperFunc(log)
 }
 
 // UseLogger uses a specified Logger to output package logging info.
-func UseLogger(logger logs.Logger, backendLog *logs.Backend) {
+func UseLogger(logger logs.Logger) {
 	log = logger
-	spawn = panics.GoroutineWrapperFunc(log, backendLog)
+	spawn = panics.GoroutineWrapperFunc(log)
 }
 
 // LogClosure is a closure that can be printed with %s to be used to

server/log.go

@@ -11,5 +11,5 @@ import (
 
 var (
 	log, _ = logger.Get(logger.SubsystemTags.SRVR)
-	spawn  = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn  = panics.GoroutineWrapperFunc(log)
 )

server/p2p/log.go

@@ -12,7 +12,7 @@ import (
 var (
 	srvrLog, _ = logger.Get(logger.SubsystemTags.SRVR)
 	peerLog, _ = logger.Get(logger.SubsystemTags.PEER)
-	spawn      = panics.GoroutineWrapperFunc(peerLog, logger.BackendLog)
+	spawn      = panics.GoroutineWrapperFunc(peerLog)
 
 	txmpLog, _ = logger.Get(logger.SubsystemTags.TXMP)
 	indxLog, _ = logger.Get(logger.SubsystemTags.INDX)

server/rpc/log.go

@@ -11,5 +11,5 @@ import (
 
 var (
 	log, _ = logger.Get(logger.SubsystemTags.RPCS)
-	spawn  = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn  = panics.GoroutineWrapperFunc(log)
 )

signal/signal.go

@@ -13,6 +13,10 @@ import (
 // subsystems using the same code paths as when an interrupt signal is received.
 var ShutdownRequestChannel = make(chan struct{})
 
+// PanicShutdownChannel is used to initiate shutdown when any thread
+// panics using the same code paths as when an interrupt signal is received.
+var PanicShutdownChannel = make(chan struct{})
+
 // interruptSignals defines the default signals to catch in order to do a proper
 // shutdown.  This may be modified during init depending on the platform.
 var interruptSignals = []os.Signal{os.Interrupt}
@@ -30,11 +34,14 @@ func InterruptListener() <-chan struct{} {
 		// channel to notify the caller.
 		select {
 		case sig := <-interruptChannel:
-			btcdLog.Infof("Received signal (%s).  Shutting down...",
+			btcdLog.Infof("Received signal (%s). Shutting down...",
 				sig)
 
 		case <-ShutdownRequestChannel:
-			btcdLog.Info("Shutdown requested.  Shutting down...")
+			btcdLog.Info("Shutdown requested. Shutting down...")
+
+		case <-PanicShutdownChannel:
+			btcdLog.Info("Panic occurred. Shutting down...")
 		}
 		close(c)
 
@@ -44,12 +51,17 @@ func InterruptListener() <-chan struct{} {
 		for {
 			select {
 			case sig := <-interruptChannel:
-				btcdLog.Infof("Received signal (%s).  Already "+
+				btcdLog.Infof("Received signal (%s). Already "+
 					"shutting down...", sig)
 
 			case <-ShutdownRequestChannel:
-				btcdLog.Info("Shutdown requested.  Already " +
+				btcdLog.Info("Shutdown requested. Already " +
 					"shutting down...")
+
+			case <-PanicShutdownChannel:
+				btcdLog.Info("Panic occurred while shutting down. " +
+					"Forcing shut down...")
+				os.Exit(1)
 			}
 		}
 	}()

util/locks/log.go

@@ -11,5 +11,5 @@ import (
 
 var (
 	log, _ = logger.Get(logger.SubsystemTags.UTIL)
-	spawn  = panics.GoroutineWrapperFunc(log, logger.BackendLog)
+	spawn  = panics.GoroutineWrapperFunc(log)
 )

util/panics/panics.go

@@ -2,31 +2,44 @@ package panics
 
 import (
 	"github.com/daglabs/btcd/logs"
-	"os"
+	"github.com/daglabs/btcd/signal"
 	"runtime/debug"
 )
 
-// HandlePanic recovers panics, log them, and then exits the process.
+// HandlePanic recovers panics, log them, runs an optional panicHandler,
-func HandlePanic(log logs.Logger, backendLog *logs.Backend, goroutineStackTrace []byte) {
+// and then initiates a clean shutdown.
+func HandlePanic(log logs.Logger, goroutineStackTrace []byte, panicHandler func()) {
 	if err := recover(); err != nil {
 		log.Criticalf("Fatal error: %+v", err)
 		if goroutineStackTrace != nil {
-			log.Criticalf("goroutine stack trance: %s", goroutineStackTrace)
+			log.Criticalf("goroutine stack trace: %s", goroutineStackTrace)
 		}
 		log.Criticalf("Stack trace: %s", debug.Stack())
-		if backendLog != nil {
+		if panicHandler != nil {
-			backendLog.Close()
+			panicHandler()
 		}
-		os.Exit(1)
+		signal.PanicShutdownChannel <- struct{}{}
 	}
 }
 
 // GoroutineWrapperFunc returns a goroutine wrapper function that handles panics and write them to the log.
-func GoroutineWrapperFunc(log logs.Logger, backendLog *logs.Backend) func(func()) {
+func GoroutineWrapperFunc(log logs.Logger) func(func()) {
 	return func(f func()) {
 		stackTrace := debug.Stack()
 		go func() {
-			defer HandlePanic(log, backendLog, stackTrace)
+			defer HandlePanic(log, stackTrace, nil)
+			f()
+		}()
+	}
+}
+
+// GoroutineWrapperFuncWithPanicHandler returns a goroutine wrapper function that handles panics,
+// write them to the log, and executes a handler function for panics.
+func GoroutineWrapperFuncWithPanicHandler(log logs.Logger) func(func(), func()) {
+	return func(f func(), panicHandler func()) {
+		stackTrace := debug.Stack()
+		go func() {
+			defer HandlePanic(log, stackTrace, panicHandler)
 			f()
 		}()
 	}