Merge pull request #748 from HuKeping/feature-hot-reload

Feature: increase/decrease logging level without restarting

cmd/notary-server/config.go

@@ -3,9 +3,12 @@ package main
 import (
 	"crypto/tls"
 	"fmt"
+	"os"
+	"os/signal"
 	"path"
 	"strconv"
 	"strings"
+	"syscall"
 	"time"
 
 	"github.com/Sirupsen/logrus"
@@ -278,3 +281,31 @@ func parseServerConfig(configFilePath string, hRegister healthRegister) (context
 		ConsistentCacheControlConfig: consistentCache,
 	}, nil
 }
+
+func setupSignalTrap() {
+	c := make(chan os.Signal, 1)
+	signal.Notify(c, notary.NotarySupportedSignals...)
+	go func() {
+		for {
+			signalHandle(<-c)
+		}
+	}()
+}
+
+// signalHandle will increase/decrease the logging level via the signal we get.
+func signalHandle(sig os.Signal) {
+	switch sig {
+	case syscall.SIGUSR1:
+		if err := utils.AdjustLogLevel(true); err != nil {
+			fmt.Printf("Attempt to increase log level failed, will remain at %s level, error: %s\n", logrus.GetLevel(), err)
+			return
+		}
+	case syscall.SIGUSR2:
+		if err := utils.AdjustLogLevel(false); err != nil {
+			fmt.Printf("Attempt to decrease log level failed, will remain at %s level, error: %s\n", logrus.GetLevel(), err)
+			return
+		}
+	}
+
+	fmt.Println("Successfully setting log level to ", logrus.GetLevel())
+}

cmd/notary-server/main.go

@@ -57,6 +57,8 @@ func main() {
 		logrus.Fatal(err.Error())
 	}
 
+	setupSignalTrap()
+
 	if doBootstrap {
 		err = bootstrap(ctx)
 	} else {

cmd/notary-server/main_test.go

@@ -8,9 +8,11 @@ import (
 	"os"
 	"reflect"
 	"strings"
+	"syscall"
 	"testing"
 	"time"
 
+	"github.com/Sirupsen/logrus"
 	"github.com/docker/distribution/health"
 	"github.com/docker/notary"
 	"github.com/docker/notary/server/storage"
@@ -413,3 +415,28 @@ func TestSampleConfig(t *testing.T) {
 	// once for the DB, once for the trust service
 	require.Equal(t, registerCalled, 2)
 }
+
+func TestSignalHandle(t *testing.T) {
+	f, err := os.Create("/tmp/testSignalHandle.json")
+	defer os.Remove(f.Name())
+	require.NoError(t, err)
+
+	f.WriteString(`{"logging": {"level": "info"}}`)
+
+	v := viper.New()
+	utils.SetupViper(v, "envPrefix")
+	err = utils.ParseViper(v, f.Name())
+	require.NoError(t, err)
+
+	// Info + SIGUSR1 -> Debug
+	signalHandle(syscall.SIGUSR1)
+	require.Equal(t, logrus.GetLevel(), logrus.DebugLevel)
+
+	// Debug + SIGUSR1 -> Debug
+	signalHandle(syscall.SIGUSR1)
+	require.Equal(t, logrus.GetLevel(), logrus.DebugLevel)
+
+	// Debug + SIGUSR2-> Info
+	signalHandle(syscall.SIGUSR2)
+	require.Equal(t, logrus.GetLevel(), logrus.InfoLevel)
+}

const.go

@@ -1,6 +1,8 @@
 package notary
 
 import (
+	"os"
+	"syscall"
 	"time"
 )
 
@@ -66,3 +68,11 @@ var NotaryDefaultExpiries = map[string]time.Duration{
 	"snapshot":  NotarySnapshotExpiry,
 	"timestamp": NotaryTimestampExpiry,
 }
+
+// NotarySupportedSignals contains the signals we would like to capture:
+// - SIGUSR1, indicates a increment of the log level.
+// - SIGUSR2, indicates a decrement of the log level.
+var NotarySupportedSignals = []os.Signal{
+	syscall.SIGUSR1,
+	syscall.SIGUSR2,
+}

docs/reference/server-config.md

@@ -19,6 +19,8 @@ A configuration file is required by Notary server, and the path to the
 configuration file must be specified using the `-config` option on the command
 line.
 
+Notary server also allows you to [increase/decrease](server-config.md#hot-logging-level-reload) the logging level without having to restart.
+
 Here is a full server configuration file example; please click on the top level JSON keys to
 learn more about the configuration section corresponding to that key:
 
@@ -359,6 +361,42 @@ Example:
 	</tr>
 </table>
 
+## Hot logging level reload
+We don't support completely reloading notary configuration files yet at present. What we support for now is:
+- increase logging level by signaling `SIGUSR1`
+- decrease logging level by signaling `SIGUSR2`
+
+Example:
+
+To increase logging level
+```
+$ kill -s SIGUSR1 PID
+
+or
+
+$ docker exec -i CONTAINER_ID kill -s SIGUSR1 PID
+```
+
+To decrease logging level
+```
+$ kill -s SIGUSR2 PID
+
+or
+
+$ docker exec -i CONTAINER_ID kill -s SIGUSR2 PID
+```
+PID is the process id of `notary-server` and it may not the PID 1 process if you are running
+the container with some kind of wrapper startup script or something.
+
+You can get the PID of `notary-server` through
+```
+$ docker exec CONTAINER_ID ps aux
+
+or
+
+$ ps aux | grep "notary-server -config" | grep -v "grep"
+```
+
 ## Related information
 
 * [Notary Signer Configuration File](signer-config.md)

utils/configuration.go

@@ -222,3 +222,25 @@ func ParseViper(v *viper.Viper, configFile string) error {
 	}
 	return nil
 }
+
+// AdjustLogLevel increases/decreases the log level, return error if the operation is invaild.
+func AdjustLogLevel(increment bool) error {
+	lvl := logrus.GetLevel()
+
+	// The log level seems not possible, in the foreseeable future,
+	// out of range [Panic, Debug]
+	if increment {
+		if lvl == logrus.DebugLevel {
+			return fmt.Errorf("log level can not be set higher than %s", "Debug")
+		}
+		lvl++
+	} else {
+		if lvl == logrus.PanicLevel {
+			return fmt.Errorf("log level can not be set lower than %s", "Panic")
+		}
+		lvl--
+	}
+
+	logrus.SetLevel(lvl)
+	return nil
+}

utils/configuration_test.go

@@ -485,3 +485,74 @@ func TestParseViperWithValidFile(t *testing.T) {
 
 	require.Equal(t, "debug", v.GetString("logging.level"))
 }
+
+func TestAdjustLogLevel(t *testing.T) {
+
+	// To indicate increment or decrement the logging level
+	optIncrement := true
+	optDecrement := false
+
+	// Debug is the highest level for now, so we expected a error here
+	logrus.SetLevel(logrus.DebugLevel)
+	err := AdjustLogLevel(optIncrement)
+	require.Error(t, err)
+	// Debug -> Info
+	logrus.SetLevel(logrus.DebugLevel)
+	err = AdjustLogLevel(optDecrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.InfoLevel, logrus.GetLevel())
+
+	// Info -> Debug
+	logrus.SetLevel(logrus.InfoLevel)
+	err = AdjustLogLevel(optIncrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.DebugLevel, logrus.GetLevel())
+	// Info -> Warn
+	logrus.SetLevel(logrus.InfoLevel)
+	err = AdjustLogLevel(optDecrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.WarnLevel, logrus.GetLevel())
+
+	// Warn -> Info
+	logrus.SetLevel(logrus.WarnLevel)
+	err = AdjustLogLevel(optIncrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.InfoLevel, logrus.GetLevel())
+	// Warn -> Error
+	logrus.SetLevel(logrus.WarnLevel)
+	err = AdjustLogLevel(optDecrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.ErrorLevel, logrus.GetLevel())
+
+	// Error -> Warn
+	logrus.SetLevel(logrus.ErrorLevel)
+	err = AdjustLogLevel(optIncrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.WarnLevel, logrus.GetLevel())
+	// Error -> Fatal
+	logrus.SetLevel(logrus.ErrorLevel)
+	err = AdjustLogLevel(optDecrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.FatalLevel, logrus.GetLevel())
+
+	// Fatal -> Error
+	logrus.SetLevel(logrus.FatalLevel)
+	err = AdjustLogLevel(optIncrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.ErrorLevel, logrus.GetLevel())
+	// Fatal -> Panic
+	logrus.SetLevel(logrus.FatalLevel)
+	err = AdjustLogLevel(optDecrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.PanicLevel, logrus.GetLevel())
+
+	// Panic -> Fatal
+	logrus.SetLevel(logrus.PanicLevel)
+	err = AdjustLogLevel(optIncrement)
+	require.NoError(t, err)
+	require.Equal(t, logrus.FatalLevel, logrus.GetLevel())
+	// Panic is the lowest level for now, so we expected a error here
+	logrus.SetLevel(logrus.PanicLevel)
+	err = AdjustLogLevel(optDecrement)
+	require.Error(t, err)
+}