signal: Backtrace on SIGUSR1

main.go

@@ -27,6 +27,8 @@ const (
 // version is the shim version. This variable is populated at build time.
 var version = "unknown"
 
+var debug bool
+
 // if true, coredump when an internal error occurs or a fatal signal is received
 var crashOnError = false
 
@@ -76,7 +78,6 @@ func realMain() {
 		terminal      bool
 		proxyExitCode bool
 		showVersion   bool
-		debug         bool
 	)
 
 	flag.BoolVar(&debug, "debug", false, "enable debug mode")
@@ -96,6 +97,10 @@ func realMain() {
 		os.Exit(0)
 	}
 
+	if logLevel == "debug" {
+		debug = true
+	}
+
 	if debug {
 		crashOnError = true
 	}

shim.go

@@ -104,19 +104,20 @@ func (s *shim) forwardAllSignals() chan os.Signal {
 			sysSig, ok := sig.(syscall.Signal)
 			if !ok {
 				err := errors.New("unknown signal")
-				logger().WithError(err).WithField("signal", sig.String()).Error("")
+				logger().WithError(err).WithField("signal", sig.String()).Error()
 				continue
 			}
 
-			if fatalSignal(sysSig) {
-				logger().WithField("signal", sig).Error("received fatal signal")
-				die()
-			}
-
 			if sigIgnored[sysSig] {
 				//ignore these
 				continue
 			}
+
+			if debug && nonFatalSignal(sysSig) {
+				logger().WithField("signal", sig).Debug("handling signal")
+				backtrace()
+			}
+
 			// forward this signal to container
 			_, err := s.agent.SignalProcess(s.ctx, &pb.SignalProcessRequest{
 				ContainerId: s.containerID,
@@ -125,6 +126,11 @@ func (s *shim) forwardAllSignals() chan os.Signal {
 			if err != nil {
 				logger().WithError(err).WithField("signal", sig.String()).Error("forward signal failed")
 			}
+
+			if fatalSignal(sysSig) {
+				logger().WithField("signal", sig).Error("received fatal signal")
+				die()
+			}
 		}
 	}()
 	return sigc

shim_test.go

@@ -61,4 +61,7 @@ func TestShimOps(t *testing.T) {
 	status, err := shim.wait()
 	assert.Nil(t, err, "%s", err)
 	assert.Equal(t, status, int32(0), "process fail status %d", status)
+
+	// wait for go routines started by proxyStdio() to end
+	wg.Wait()
 }

fatal.go → signals.go

@@ -15,8 +15,10 @@ import (
 	"syscall"
 )
 
-// List of fatal signals
-var sigFatal = map[syscall.Signal]bool{
+// List of handled signals.
+//
+// The value is true if receiving the signal should be fatal.
+var handledSignalsMap = map[syscall.Signal]bool{
 	syscall.SIGABRT:   true,
 	syscall.SIGBUS:    true,
 	syscall.SIGILL:    true,
@@ -25,6 +27,7 @@ var sigFatal = map[syscall.Signal]bool{
 	syscall.SIGSTKFLT: true,
 	syscall.SIGSYS:    true,
 	syscall.SIGTRAP:   true,
+	syscall.SIGUSR1:   false,
 }
 
 func handlePanic() {
@@ -55,7 +58,31 @@ func backtrace() {
 }
 
 func fatalSignal(sig syscall.Signal) bool {
-	return sigFatal[sig]
+	s, exists := handledSignalsMap[sig]
+	if !exists {
+		return false
+	}
+
+	return s
+}
+
+func nonFatalSignal(sig syscall.Signal) bool {
+	s, exists := handledSignalsMap[sig]
+	if !exists {
+		return false
+	}
+
+	return !s
+}
+
+func handledSignals() []syscall.Signal {
+	var signals []syscall.Signal
+
+	for sig := range handledSignalsMap {
+		signals = append(signals, sig)
+	}
+
+	return signals
 }
 
 func die() {

signals_test.go

@@ -0,0 +1,140 @@
+// Copyright (c) 2018 Intel Corporation
+//
+// SPDX-License-Identifier: Apache-2.0
+//
+
+package main
+
+import (
+	"bytes"
+	"os"
+	"reflect"
+	goruntime "runtime"
+	"sort"
+	"strings"
+	"syscall"
+	"testing"
+
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+)
+
+func TestSignalFatalSignal(t *testing.T) {
+	assert := assert.New(t)
+
+	for sig, fatal := range handledSignalsMap {
+		result := nonFatalSignal(sig)
+		if fatal {
+			assert.False(result)
+		} else {
+			assert.True(result)
+		}
+	}
+}
+
+func TestSignalHandledSignalsMap(t *testing.T) {
+	assert := assert.New(t)
+
+	for sig, fatal := range handledSignalsMap {
+		result := fatalSignal(sig)
+		if fatal {
+			assert.True(result)
+		} else {
+			assert.False(result)
+		}
+	}
+}
+
+func TestSignalHandledSignals(t *testing.T) {
+	assert := assert.New(t)
+
+	var expected []syscall.Signal
+
+	for sig := range handledSignalsMap {
+		expected = append(expected, sig)
+	}
+
+	got := handledSignals()
+
+	sort.Slice(expected, func(i, j int) bool {
+		return int(expected[i]) < int(expected[j])
+	})
+
+	sort.Slice(got, func(i, j int) bool {
+		return int(got[i]) < int(got[j])
+	})
+
+	assert.True(reflect.DeepEqual(expected, got))
+}
+
+func TestSignalNonFatalSignal(t *testing.T) {
+	assert := assert.New(t)
+
+	for sig, fatal := range handledSignalsMap {
+		result := nonFatalSignal(sig)
+		if fatal {
+			assert.False(result)
+		} else {
+			assert.True(result)
+		}
+	}
+}
+
+func TestSignalFatalSignalInvalidSignal(t *testing.T) {
+	assert := assert.New(t)
+
+	sig := syscall.SIGXCPU
+
+	result := fatalSignal(sig)
+	assert.False(result)
+}
+
+func TestSignalNonFatalSignalInvalidSignal(t *testing.T) {
+	assert := assert.New(t)
+
+	sig := syscall.SIGXCPU
+
+	result := nonFatalSignal(sig)
+	assert.False(result)
+}
+
+func TestSignalBacktrace(t *testing.T) {
+	assert := assert.New(t)
+
+	savedLog := shimLog
+	defer func() {
+		shimLog = savedLog
+	}()
+
+	shimLog = logrus.WithFields(logrus.Fields{
+		"name":        shimName,
+		"pid":         os.Getpid(),
+		"source":      "shim",
+		"test-logger": true})
+
+	// create buffer to save logger output
+	buf := &bytes.Buffer{}
+
+	savedOut := shimLog.Logger.Out
+	defer func() {
+		shimLog.Logger.Out = savedOut
+	}()
+
+	// capture output to buffer
+	shimLog.Logger.Out = buf
+
+	// determine name of *this* function
+	pc := make([]uintptr, 1)
+	goruntime.Callers(1, pc)
+	fn := goruntime.FuncForPC(pc[0])
+	name := fn.Name()
+
+	backtrace()
+
+	b := buf.String()
+
+	// very basic tests to check if a backtrace was produced
+	assert.True(strings.Contains(b, "contention:"))
+	assert.True(strings.Contains(b, `level=error`))
+	assert.True(strings.Contains(b, name))
+}