Catch and log panics

CHANGELOG.asciidoc

@@ -146,6 +146,7 @@ https://github.com/elastic/beats/compare/v6.0.0-beta2...master[Check the HEAD di
 - Add the abilility for the add_docker_metadata process to enrich based on process ID. {pull}6100[6100]
 - The `add_docker_metadata` and `add_kubernetes_metadata` processors are now GA, instead of Beta. {pull}6105[6105]
 - The node name can be discovered automatically by machine-id matching when beat deployed outside kubernetes cluster. {pull}6146[6146]
+- Panics will be written to the logger before exiting. {pull}6199[6199]
 
 *Auditbeat*
 

libbeat/cmd/instance/beat.go

@@ -15,6 +15,7 @@ import (
 	"time"
 
 	"github.com/satori/go.uuid"
+	"go.uber.org/zap"
 
 	"github.com/elastic/beats/libbeat/api"
 	"github.com/elastic/beats/libbeat/beat"
@@ -128,6 +129,12 @@ func initRand() {
 // XXX Move this as a *Beat method?
 func Run(name, idxPrefix, version string, bt beat.Creator) error {
 	return handleError(func() error {
+		defer func() {
+			if r := recover(); r != nil {
+				logp.NewLogger(name).Fatalw("Failed due to panic.",
+					"panic", r, zap.Stack("stack"))
+			}
+		}()
 		b, err := NewBeat(name, idxPrefix, version)
 		if err != nil {
 			return err
@@ -248,6 +255,7 @@ func (b *Beat) createBeater(bt beat.Creator) (beat.Beater, error) {
 
 func (b *Beat) launch(bt beat.Creator) error {
 	defer logp.Sync()
+	defer logp.Info("%s stopped.", b.Info.Beat)
 
 	err := b.Init()
 	if err != nil {
@@ -299,7 +307,6 @@ func (b *Beat) launch(bt beat.Creator) error {
 	}
 
 	logp.Info("%s start running.", b.Info.Beat)
-	defer logp.Info("%s stopped.", b.Info.Beat)
 
 	if b.Config.HTTP.Enabled() {
 		api.Start(b.Config.HTTP, b.Info)

libbeat/logp/core_test.go

@@ -148,7 +148,7 @@ func TestLoggerLevel(t *testing.T) {
 }
 
 func TestRecover(t *testing.T) {
-	const recoveryExplanation = "Something went wrong."
+	const recoveryExplanation = "Something went wrong"
 	const cause = "unexpected condition"
 
 	DevelopmentSetup(ToObserverOutput())
@@ -160,8 +160,9 @@ func TestRecover(t *testing.T) {
 			assert.Equal(t, zap.ErrorLevel, log.Level)
 			assert.Equal(t, "logp/core_test.go",
 				strings.Split(log.Caller.TrimmedPath(), ":")[0])
-			assert.Contains(t, log.Message, recoveryExplanation)
-			assert.Contains(t, log.Message, cause)
+			assert.Contains(t, log.Message, recoveryExplanation+
+				". Recovering, but please report this.")
+			assert.Contains(t, log.ContextMap(), "panic")
 		}
 	}()
 

libbeat/logp/global.go

@@ -83,8 +83,8 @@ func WTF(format string, v ...interface{}) {
 // Recover stops a panicking goroutine and logs an Error.
 func Recover(msg string) {
 	if r := recover(); r != nil {
-		msg := fmt.Sprintf("%s. Recovering, but please report this: %s.", msg, r)
+		msg := fmt.Sprintf("%s. Recovering, but please report this.", msg)
 		globalLogger().WithOptions(zap.AddCallerSkip(2)).
-			Error(msg, zap.Stack("stack"))
+			Error(msg, zap.Any("panic", r), zap.Stack("stack"))
 	}
 }

libbeat/logp/logger.go

@@ -51,6 +51,11 @@ func (l *Logger) Error(args ...interface{}) {
 	l.sugar.Error(args...)
 }
 
+// Fatal uses fmt.Sprint to construct and log a message, then calls os.Exit(1).
+func (l *Logger) Fatal(args ...interface{}) {
+	l.sugar.Fatal(args...)
+}
+
 // Panic uses fmt.Sprint to construct and log a message, then panics.
 func (l *Logger) Panic(args ...interface{}) {
 	l.sugar.Panic(args...)
@@ -84,6 +89,11 @@ func (l *Logger) Errorf(format string, args ...interface{}) {
 	l.sugar.Errorf(format, args...)
 }
 
+// Fatalf uses fmt.Sprintf to log a templated message, then calls os.Exit(1).
+func (l *Logger) Fatalf(format string, args ...interface{}) {
+	l.sugar.Fatalf(format, args...)
+}
+
 // Panicf uses fmt.Sprintf to log a templated message, then panics.
 func (l *Logger) Panicf(format string, args ...interface{}) {
 	l.sugar.Panicf(format, args...)
@@ -129,6 +139,15 @@ func (l *Logger) Errorw(msg string, keysAndValues ...interface{}) {
 	l.sugar.Errorw(msg, keysAndValues...)
 }
 
+// Fatalw logs a message with some additional context, then calls os.Exit(1).
+// The additional context is added in the form of key-value pairs. The optimal
+// way to write the value to the log message will be inferred by the value's
+// type. To explicitly specify a type you can pass a Field such as
+// logp.Stringer.
+func (l *Logger) Fatalw(msg string, keysAndValues ...interface{}) {
+	l.sugar.Fatalw(msg, keysAndValues...)
+}
+
 // Panicw logs a message with some additional context, then panics. The
 // additional context is added in the form of key-value pairs. The optimal way
 // to write the value to the log message will be inferred by the value's type.