Add CLI to set/get module log levels on peer

Dynamically set or get the log level for the specified module running
on a peer. Useful for problem determination / debugging.

Use the following format:

peer logging setlevel <module-name> <log-level>
peer logging getlevel <module-name>

Fix Issue FAB-574

Change-Id: I5b16d100a84393bafe052511bb2e6f188214e81e
Signed-off-by: Will Lahti <wtlahti@us.ibm.com>

core/admin.go

@@ -25,6 +25,7 @@ import (
 	"golang.org/x/net/context"
 
 	"github.com/golang/protobuf/ptypes/empty"
+	"github.com/hyperledger/fabric/flogging"
 	pb "github.com/hyperledger/fabric/protos"
 )
 
@@ -78,3 +79,19 @@ func (*ServerAdmin) StopServer(context.Context, *empty.Empty) (*pb.ServerStatus,
 	defer os.Exit(0)
 	return status, nil
 }
+
+// GetModuleLogLevel gets the current logging level for the specified module
+func (*ServerAdmin) GetModuleLogLevel(ctx context.Context, request *pb.LogLevelRequest) (*pb.LogLevelResponse, error) {
+	logLevelString, err := flogging.GetModuleLogLevel(request.LogModule)
+	logResponse := &pb.LogLevelResponse{LogModule: request.LogModule, LogLevel: logLevelString}
+
+	return logResponse, err
+}
+
+// SetModuleLogLevel sets the logging level for the specified module
+func (*ServerAdmin) SetModuleLogLevel(ctx context.Context, request *pb.LogLevelRequest) (*pb.LogLevelResponse, error) {
+	logLevelString, err := flogging.SetModuleLogLevel(request.LogModule, request.LogLevel)
+	logResponse := &pb.LogLevelResponse{LogModule: request.LogModule, LogLevel: logLevelString}
+
+	return logResponse, err
+}

flogging/logging.go

@@ -98,3 +98,33 @@ func init() {
 	backendFormatter := logging.NewBackendFormatter(backend, format)
 	logging.SetBackend(backendFormatter).SetLevel(loggingDefaultLevel, "")
 }
+
+// GetModuleLogLevel gets the current logging level for the specified module
+func GetModuleLogLevel(module string) (string, error) {
+	// logging.GetLevel() returns the logging level for the module, if defined.
+	// otherwise, it returns the default logging level, as set by
+	// flogging/logging.go
+	level := logging.GetLevel(module).String()
+
+	loggingLogger.Infof("Module '%s' logger enabled for log level: %s", module, level)
+
+	return level, nil
+}
+
+// SetModuleLogLevel sets the logging level for the specified module. This is
+// currently only called from admin.go but can be called from anywhere in the
+// code on a running peer to dynamically change the log level for the module.
+func SetModuleLogLevel(module string, logLevel string) (string, error) {
+	level, err := logging.LogLevel(logLevel)
+
+	if err != nil {
+		loggingLogger.Warningf("Invalid logging level: %s - ignored", logLevel)
+	} else {
+		logging.SetLevel(logging.Level(level), module)
+		loggingLogger.Infof("Module '%s' logger enabled for log level: %s", module, level)
+	}
+
+	logLevelString := level.String()
+
+	return logLevelString, err
+}

flogging/logging_test.go

@@ -143,6 +143,49 @@ func TestLoggingLevelInvalidModuleSyntax(t *testing.T) {
 	assertDefaultLoggingLevel(t, flogging.DefaultLoggingLevel())
 }
 
+func TestGetModuleLoggingLevelDefault(t *testing.T) {
+	level, _ := flogging.GetModuleLogLevel("peer")
+
+	// peer should be using the default log level at this point
+	if level != "INFO" {
+		t.FailNow()
+	}
+}
+
+func TestGetModuleLoggingLevelDebug(t *testing.T) {
+	flogging.SetModuleLogLevel("peer", "DEBUG")
+	level, _ := flogging.GetModuleLogLevel("peer")
+
+	// ensure that the log level has changed to debug
+	if level != "DEBUG" {
+		t.FailNow()
+	}
+}
+
+func TestGetModuleLoggingLevelInvalid(t *testing.T) {
+	flogging.SetModuleLogLevel("peer", "invalid")
+	level, _ := flogging.GetModuleLogLevel("peer")
+
+	// ensure that the log level didn't change after invalid log level specified
+	if level != "DEBUG" {
+		t.FailNow()
+	}
+}
+
+func TestSetModuleLoggingLevel(t *testing.T) {
+	flogging.SetModuleLogLevel("peer", "WARNING")
+
+	// ensure that the log level has changed to warning
+	assertModuleLoggingLevel(t, "peer", logging.WARNING)
+}
+
+func TestSetModuleLoggingLevelInvalid(t *testing.T) {
+	flogging.SetModuleLogLevel("peer", "invalid")
+
+	// ensure that the log level didn't change after invalid log level specified
+	assertModuleLoggingLevel(t, "peer", logging.WARNING)
+}
+
 func assertDefaultLoggingLevel(t *testing.T, expectedLevel logging.Level) {
 	assertModuleLoggingLevel(t, "", expectedLevel)
 }

peer/clilogging/common.go

@@ -0,0 +1,47 @@
+/*
+Copyright IBM Corp. 2016 All Rights Reserved.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+		 http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package clilogging
+
+import (
+	"fmt"
+
+	"github.com/op/go-logging"
+	"github.com/spf13/cobra"
+)
+
+func checkLoggingCmdParams(cmd *cobra.Command, args []string) error {
+	var err error
+
+	// check that at least one parameter is passed in
+	if len(args) == 0 {
+		return fmt.Errorf("no parameters provided")
+	}
+
+	if cmd.Name() == "setlevel" {
+		if len(args) == 1 {
+			err = fmt.Errorf("no log level provided")
+		} else {
+			// check that log level is valid. if not, err is set
+			_, err = logging.LogLevel(args[1])
+			if err != nil {
+				err = fmt.Errorf("%s - %s", err, args[1])
+			}
+		}
+	}
+
+	return err
+}

peer/clilogging/getlevel.go

@@ -0,0 +1,66 @@
+/*
+Copyright IBM Corp. 2016 All Rights Reserved.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+		 http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package clilogging
+
+import (
+	"fmt"
+
+	"github.com/hyperledger/fabric/core/peer"
+	pb "github.com/hyperledger/fabric/protos"
+	"github.com/spf13/cobra"
+	"golang.org/x/net/context"
+)
+
+func getLevelCmd() *cobra.Command {
+	return loggingGetLevelCmd
+}
+
+var loggingGetLevelCmd = &cobra.Command{
+	Use:   "getlevel <module>",
+	Short: "Returns the logging level of the requested module logger.",
+	Long:  `Returns the logging level of the requested module logger`,
+	Run: func(cmd *cobra.Command, args []string) {
+		getLevel(cmd, args)
+	},
+}
+
+func getLevel(cmd *cobra.Command, args []string) (err error) {
+	err = checkLoggingCmdParams(cmd, args)
+
+	if err != nil {
+		logger.Warningf("Error: %s", err)
+	} else {
+		clientConn, err := peer.NewPeerClientConnection()
+		if err != nil {
+			logger.Infof("Error trying to connect to local peer: %s", err)
+			err = fmt.Errorf("Error trying to connect to local peer: %s", err)
+			fmt.Println(&pb.ServerStatus{Status: pb.ServerStatus_UNKNOWN})
+			return err
+		}
+
+		serverClient := pb.NewAdminClient(clientConn)
+
+		logResponse, err := serverClient.GetModuleLogLevel(context.Background(), &pb.LogLevelRequest{LogModule: args[0]})
+
+		if err != nil {
+			logger.Warningf("Error retrieving log level")
+			return err
+		}
+		logger.Infof("Current log level for module '%s': %s", logResponse.LogModule, logResponse.LogLevel)
+	}
+	return err
+}

peer/clilogging/logging.go

@@ -0,0 +1,42 @@
+/*
+Copyright IBM Corp. 2016 All Rights Reserved.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+		 http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package clilogging
+
+import (
+	"fmt"
+
+	"github.com/op/go-logging"
+	"github.com/spf13/cobra"
+)
+
+const loggingFuncName = "logging"
+
+var logger = logging.MustGetLogger("loggingCmd")
+
+// Cmd returns the cobra command for Logging
+func Cmd() *cobra.Command {
+	loggingCmd.AddCommand(getLevelCmd())
+	loggingCmd.AddCommand(setLevelCmd())
+
+	return loggingCmd
+}
+
+var loggingCmd = &cobra.Command{
+	Use:   loggingFuncName,
+	Short: fmt.Sprintf("%s specific commands.", loggingFuncName),
+	Long:  fmt.Sprintf("%s specific commands.", loggingFuncName),
+}

peer/clilogging/logging_test.go

@@ -0,0 +1,98 @@
+/*
+ Copyright Digital Asset Holdings, LLC 2016 All Rights Reserved.
+
+ Licensed under the Apache License, Version 2.0 (the "License");
+ you may not use this file except in compliance with the License.
+ You may obtain a copy of the License at
+
+      http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing, software
+ distributed under the License is distributed on an "AS IS" BASIS,
+ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ See the License for the specific language governing permissions and
+ limitations under the License.
+*/
+
+package clilogging
+
+import "testing"
+
+// TestGetLevelEmptyParams tests the parameter checking for getlevel, which
+// should return an error when no parameters are provided
+func TestGetLevelEmptyParams(t *testing.T) {
+	var args []string
+
+	err := checkLoggingCmdParams(getLevelCmd(), args)
+
+	if err == nil {
+		t.FailNow()
+	}
+}
+
+// TestGetLevel tests the parameter checking for getlevel, which should
+// should return a nil error when one (or more) parameters are provided
+func TestGetLevel(t *testing.T) {
+	args := make([]string, 1)
+	args[0] = "peer"
+
+	err := checkLoggingCmdParams(getLevelCmd(), args)
+
+	if err != nil {
+		t.FailNow()
+	}
+}
+
+// TestSetLevelEmptyParams tests the parameter checking for setlevel, which
+// should return an error when no parameters are provided
+func TestSetLevelEmptyParams(t *testing.T) {
+	var args []string
+
+	err := checkLoggingCmdParams(setLevelCmd(), args)
+
+	if err == nil {
+		t.FailNow()
+	}
+}
+
+// TestSetLevelEmptyParams tests the parameter checking for setlevel, which
+// should return an error when only one parameter is provided
+func TestSetLevelOneParam(t *testing.T) {
+	args := make([]string, 1)
+	args[0] = "peer"
+
+	err := checkLoggingCmdParams(setLevelCmd(), args)
+
+	if err == nil {
+		t.FailNow()
+	}
+}
+
+// TestSetLevelEmptyParams tests the parameter checking for setlevel, which
+// should return an error when an invalid log level is provided
+func TestSetLevelInvalid(t *testing.T) {
+	args := make([]string, 2)
+	args[0] = "peer"
+	args[1] = "invalidlevel"
+
+	err := checkLoggingCmdParams(setLevelCmd(), args)
+
+	if err == nil {
+		t.FailNow()
+	}
+}
+
+// TestSetLevelEmptyParams tests the parameter checking for setlevel, which
+// should return a nil error when two parameters, the second of which is a
+// valid log level, are provided
+func TestSetLevel(t *testing.T) {
+	args := make([]string, 2)
+	args[0] = "peer"
+	args[1] = "debug"
+
+	err := checkLoggingCmdParams(setLevelCmd(), args)
+
+	if err != nil {
+		t.FailNow()
+	}
+}