FAB-394 Chaincode log level cannot be changed

These changes make sure that the logging.chaincode setting from
core.yaml is used to set the chaincode logging level every time
the chaincode container starts. The peer reads in the value and
passes it to the chaincode via an environment variable as it
does for similar values.

Fix Issue FAB-394

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

core/chaincode/chaincode_support.go

@@ -25,6 +25,7 @@ import (
 	"time"
 
 	"github.com/golang/protobuf/proto"
+	logging "github.com/op/go-logging"
 	"github.com/spf13/viper"
 	"golang.org/x/net/context"
 
@@ -34,6 +35,7 @@ import (
 	"github.com/hyperledger/fabric/core/container/ccintf"
 	"github.com/hyperledger/fabric/core/crypto"
 	"github.com/hyperledger/fabric/core/ledger"
+	"github.com/hyperledger/fabric/flogging"
 	pb "github.com/hyperledger/fabric/protos"
 )
 
@@ -147,6 +149,21 @@ func NewChaincodeSupport(chainname ChainName, getPeerEndpoint func() (*pb.PeerEn
 		s.keepalive = time.Duration(t) * time.Second
 	}
 
+	viper.SetEnvPrefix("CORE")
+	viper.AutomaticEnv()
+	replacer := strings.NewReplacer(".", "_")
+	viper.SetEnvKeyReplacer(replacer)
+
+	chaincodeLogLevelString := viper.GetString("logging.chaincode")
+	chaincodeLogLevel, err := logging.LogLevel(chaincodeLogLevelString)
+
+	if err == nil {
+		s.chaincodeLogLevel = chaincodeLogLevel.String()
+	} else {
+		chaincodeLogger.Infof("chaincode logging level %s is invalid. defaulting to %s\n", chaincodeLogLevelString, flogging.DefaultLoggingLevel().String())
+		s.chaincodeLogLevel = flogging.DefaultLoggingLevel().String()
+	}
+
 	return s
 }
 
@@ -172,6 +189,7 @@ type ChaincodeSupport struct {
 	peerTLSKeyFile       string
 	peerTLSSvrHostOrd    string
 	keepalive            time.Duration
+	chaincodeLogLevel    string
 }
 
 // DuplicateChaincodeHandlerError returned if attempt to register same chaincodeID while a stream already exists.
@@ -290,6 +308,11 @@ func (chaincodeSupport *ChaincodeSupport) getArgsAndEnv(cID *pb.ChaincodeID, cLa
 	} else {
 		envs = append(envs, "CORE_PEER_TLS_ENABLED=false")
 	}
+
+	if chaincodeSupport.chaincodeLogLevel != "" {
+		envs = append(envs, "CORE_LOGGING_CHAINCODE="+chaincodeSupport.chaincodeLogLevel)
+	}
+
 	switch cLang {
 	case pb.ChaincodeSpec_GOLANG, pb.ChaincodeSpec_CAR:
 		//chaincode executable will be same as the name of the chaincode

core/chaincode/shim/chaincode.go

@@ -68,10 +68,7 @@ func Start(cc Chaincode) error {
 	backendFormatter := logging.NewBackendFormatter(backend, format)
 	logging.SetBackend(backendFormatter).SetLevel(logging.Level(shimLoggingLevel), "shim")
 
-	viper.SetEnvPrefix("CORE")
-	viper.AutomaticEnv()
-	replacer := strings.NewReplacer(".", "_")
-	viper.SetEnvKeyReplacer(replacer)
+	SetChaincodeLoggingLevel()
 
 	flag.StringVar(&peerAddress, "peer.address", "", "peer address")
 
@@ -105,6 +102,31 @@ func Start(cc Chaincode) error {
 	return err
 }
 
+// IsEnabledForLogLevel checks to see if the chaincodeLogger is enabled for a specific logging level
+// used primarily for testing
+func IsEnabledForLogLevel(logLevel string) bool {
+	lvl, _ := logging.LogLevel(logLevel)
+	return chaincodeLogger.IsEnabledFor(lvl)
+}
+
+// SetChaincodeLoggingLevel sets the chaincode logging level to the value
+// of CORE_LOGGING_CHAINCODE set from core.yaml by chaincode_support.go
+func SetChaincodeLoggingLevel() {
+	viper.SetEnvPrefix("CORE")
+	viper.AutomaticEnv()
+	replacer := strings.NewReplacer(".", "_")
+	viper.SetEnvKeyReplacer(replacer)
+
+	chaincodeLogLevelString := viper.GetString("logging.chaincode")
+	chaincodeLogLevel, err := LogLevel(chaincodeLogLevelString)
+
+	if err == nil {
+		SetLoggingLevel(chaincodeLogLevel)
+	} else {
+		chaincodeLogger.Infof("error with chaincode log level: %s level= %s\n", err, chaincodeLogLevelString)
+	}
+}
+
 // StartInProc is an entry point for system chaincodes bootstrap. It is not an
 // API for chaincodes.
 func StartInProc(env []string, args []string, cc Chaincode, recv <-chan *pb.ChaincodeMessage, send chan<- *pb.ChaincodeMessage) error {

core/chaincode/shim/mockstub_test.go

@@ -19,6 +19,8 @@ package shim
 import (
 	"fmt"
 	"testing"
+
+	"github.com/spf13/viper"
 )
 
 func TestMockStateRangeQueryIterator(t *testing.T) {
@@ -50,3 +52,17 @@ func TestMockStateRangeQueryIterator(t *testing.T) {
 		}
 	}
 }
+
+// TestSetChaincodeLoggingLevel uses the utlity function defined in chaincode.go to
+// set the chaincodeLogger's logging level
+func TestSetChaincodeLoggingLevel(t *testing.T) {
+	// set log level to a non-default level
+	testLogLevelString := "debug"
+	viper.Set("logging.chaincode", testLogLevelString)
+
+	SetChaincodeLoggingLevel()
+
+	if !IsEnabledForLogLevel(testLogLevelString) {
+		t.FailNow()
+	}
+}