recover from panic log including stacktrace to help finding the origin (#5392)

core/dnsserver/config.go

@@ -28,6 +28,9 @@ type Config struct {
 	// Debug controls the panic/recover mechanism that is enabled by default.
 	Debug bool
 
+	// Stacktrace controls including stacktrace as part of log from recover mechanism, it is disabled by default.
+	Stacktrace bool
+
 	// The transport we implement, normally just "dns" over TCP/UDP, but could be
 	// DNS-over-TLS or DNS-over-gRPC.
 	Transport string

core/dnsserver/register.go

@@ -154,6 +154,7 @@ func (h *dnsContext) MakeServers() ([]caddy.Server, error) {
 		c.Plugin = c.firstConfigInBlock.Plugin
 		c.ListenHosts = c.firstConfigInBlock.ListenHosts
 		c.Debug = c.firstConfigInBlock.Debug
+		c.Stacktrace = c.firstConfigInBlock.Stacktrace
 		c.TLSConfig = c.firstConfigInBlock.TLSConfig
 	}
 

core/dnsserver/server.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"net"
 	"runtime"
+	"runtime/debug"
 	"strings"
 	"sync"
 	"time"
@@ -41,6 +42,7 @@ type Server struct {
 	graceTimeout time.Duration      // the maximum duration of a graceful shutdown
 	trace        trace.Trace        // the trace plugin for the server
 	debug        bool               // disable recover()
+	stacktrace   bool               // enable stacktrace in recover error log
 	classChaos   bool               // allow non-INET class queries
 }
 
@@ -67,6 +69,7 @@ func NewServer(addr string, group []*Config) (*Server, error) {
 			s.debug = true
 			log.D.Set()
 		}
+		s.stacktrace = site.Stacktrace
 		// set the config per zone
 		s.zones[site.Zone] = site
 
@@ -213,7 +216,11 @@ func (s *Server) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg)
 			// In case the user doesn't enable error plugin, we still
 			// need to make sure that we stay alive up here
 			if rec := recover(); rec != nil {
-				log.Errorf("Recovered from panic in server: %q %v", s.Addr, rec)
+				if s.stacktrace {
+					log.Errorf("Recovered from panic in server: %q %v\n%s", s.Addr, rec, string(debug.Stack()))
+				} else {
+					log.Errorf("Recovered from panic in server: %q %v", s.Addr, rec)
+				}
 				vars.Panic.Inc()
 				errorAndMetricsFunc(s.Addr, w, r, dns.RcodeServerFailure)
 			}

core/dnsserver/server_test.go

@@ -26,6 +26,7 @@ func testConfig(transport string, p plugin.Handler) *Config {
 		ListenHosts: []string{"127.0.0.1"},
 		Port:        "53",
 		Debug:       false,
+		Stacktrace:  false,
 	}
 
 	c.AddPlugin(func(next plugin.Handler) plugin.Handler { return p })
@@ -76,6 +77,27 @@ func TestDebug(t *testing.T) {
 	}
 }
 
+func TestStacktrace(t *testing.T) {
+	configNoStacktrace, configStacktrace := testConfig("dns", testPlugin{}), testConfig("dns", testPlugin{})
+	configStacktrace.Stacktrace = true
+
+	s1, err := NewServer("127.0.0.1:53", []*Config{configStacktrace, configStacktrace})
+	if err != nil {
+		t.Errorf("Expected no error for NewServer, got %s", err)
+	}
+	if !s1.stacktrace {
+		t.Errorf("Expected stacktrace mode enabled for server s1")
+	}
+
+	s2, err := NewServer("127.0.0.1:53", []*Config{configNoStacktrace})
+	if err != nil {
+		t.Errorf("Expected no error for NewServer, got %s", err)
+	}
+	if s2.stacktrace {
+		t.Errorf("Expected stacktrace disabled for server s2")
+	}
+}
+
 func BenchmarkCoreServeDNS(b *testing.B) {
 	s, err := NewServer("127.0.0.1:53", []*Config{testConfig("dns", testPlugin{})})
 	if err != nil {

plugin/errors/README.md

@@ -22,10 +22,13 @@ Extra knobs are available with an expanded syntax:
 
 ~~~
 errors {
+	stacktrace
 	consolidate DURATION REGEXP [LEVEL]
 }
 ~~~
 
+Option `stacktrace` will log a stacktrace during panic recovery.
+
 Option `consolidate` allows collecting several error messages matching the regular expression **REGEXP** during **DURATION**. After the **DURATION** since receiving the first such message, the consolidated message will be printed to standard output with
 log level, which is configurable by optional option **LEVEL**. Supported options for **LEVEL** option are `warning`,`error`,`info` and `debug`.
 ~~~

plugin/errors/setup.go

@@ -52,38 +52,41 @@ func errorsParse(c *caddy.Controller) (*errorHandler, error) {
 		}
 
 		for c.NextBlock() {
-			if err := parseBlock(c, handler); err != nil {
+			switch c.Val() {
-				return nil, err
+			case "stacktrace":
+				dnsserver.GetConfig(c).Stacktrace = true
+			case "consolidate":
+				pattern, err := parseConsolidate(c)
+				if err != nil {
+					return nil, err
+				}
+				handler.patterns = append(handler.patterns, pattern)
+			default:
+				return handler, c.SyntaxErr("Unknown field " + c.Val())
 			}
 		}
 	}
 	return handler, nil
 }
 
-func parseBlock(c *caddy.Controller, h *errorHandler) error {
+func parseConsolidate(c *caddy.Controller) (*pattern, error) {
-	if c.Val() != "consolidate" {
-		return c.SyntaxErr("consolidate")
-	}
-
 	args := c.RemainingArgs()
 	if len(args) < 2 || len(args) > 3 {
-		return c.ArgErr()
+		return nil, c.ArgErr()
 	}
 	p, err := time.ParseDuration(args[0])
 	if err != nil {
-		return c.Err(err.Error())
+		return nil, c.Err(err.Error())
 	}
 	re, err := regexp.Compile(args[1])
 	if err != nil {
-		return c.Err(err.Error())
+		return nil, c.Err(err.Error())
 	}
 	lc, err := parseLogLevel(c, args)
 	if err != nil {
-		return err
+		return nil, err
 	}
-	h.patterns = append(h.patterns, &pattern{period: p, pattern: re, logCallback: lc})
+	return &pattern{period: p, pattern: re, logCallback: lc}, nil
-
-	return nil
 }
 
 func parseLogLevel(c *caddy.Controller, args []string) (func(format string, v ...interface{}), error) {

plugin/errors/setup_test.go

@@ -7,55 +7,64 @@ import (
 	"testing"
 
 	"github.com/coredns/caddy"
+	"github.com/coredns/coredns/core/dnsserver"
 	clog "github.com/coredns/coredns/plugin/pkg/log"
 )
 
 func TestErrorsParse(t *testing.T) {
 	tests := []struct {
-		inputErrorsRules string
+		inputErrorsRules        string
-		shouldErr        bool
+		shouldErr               bool
-		optCount         int
+		optCount                int
+		stacktrace bool
 	}{
-		{`errors`, false, 0},
+		{`errors`, false, 0, false},
-		{`errors stdout`, false, 0},
+		{`errors stdout`, false, 0, false},
-		{`errors errors.txt`, true, 0},
+		{`errors errors.txt`, true, 0, false},
-		{`errors visible`, true, 0},
+		{`errors visible`, true, 0, false},
-		{`errors { log visible }`, true, 0},
+		{`errors { log visible }`, true, 0, false},
 		{`errors
-		  errors `, true, 0},
+		  errors `, true, 0, false},
-		{`errors a b`, true, 0},
+		{`errors a b`, true, 0, false},
 
 		{`errors {
 		    consolidate
-		  }`, true, 0},
+		  }`, true, 0, false},
 		{`errors {
 		    consolidate 1m
-		  }`, true, 0},
+		  }`, true, 0, false},
 		{`errors {
 		    consolidate 1m .* extra
-		  }`, true, 0},
+		  }`, true, 0, false},
 		{`errors {
 		    consolidate abc .*
-		  }`, true, 0},
+		  }`, true, 0, false},
 		{`errors {
 		    consolidate 1 .*
-		  }`, true, 0},
+		  }`, true, 0, false},
 		{`errors {
 		    consolidate 1m ())
-		  }`, true, 0},
+		  }`, true, 0, false},
+		{`errors {
+            stacktrace
+		  }`, false, 0, true},
+		{`errors {
+            stacktrace
+		    consolidate 1m ^exact$
+		  }`, false, 1, true},
 		{`errors {
 		    consolidate 1m ^exact$
-		  }`, false, 1},
+		  }`, false, 1, false},
 		{`errors {
 		    consolidate 1m error
-		  }`, false, 1},
+		  }`, false, 1, false},
 		{`errors {
 		    consolidate 1m "format error"
-		  }`, false, 1},
+		  }`, false, 1, false},
 		{`errors {
 		    consolidate 1m error1
 		    consolidate 5s error2
-		  }`, false, 2},
+		  }`, false, 2, false},
 	}
 	for i, test := range tests {
 		c := caddy.NewTestController("dns", test.inputErrorsRules)
@@ -69,6 +78,10 @@ func TestErrorsParse(t *testing.T) {
 			t.Errorf("Test %d: pattern count mismatch, expected %d, got %d",
 				i, test.optCount, len(h.patterns))
 		}
+		if dnsserver.GetConfig(c).Stacktrace != test.stacktrace {
+			t.Errorf("Test %d: stacktrace, expected %t, got %t",
+				i, test.stacktrace, dnsserver.GetConfig(c).Stacktrace)
+		}
 	}
 }