[FAB-7347] Flag and env var for logging level

Introduce flags and env var for setting logging
level on fabric ca client and server.

Change-Id: Ibea14acb2e52132d7e60a52e8e84777038d7f7a6
Signed-off-by: Saad Karim <skarim@us.ibm.com>

cmd/fabric-ca-client/command/affiliation.go

@@ -21,6 +21,7 @@ import (
 
 	"github.com/cloudflare/cfssl/log"
 	"github.com/hyperledger/fabric-ca/api"
+	calog "github.com/hyperledger/fabric-ca/lib/common/log"
 	"github.com/spf13/cobra"
 )
 
@@ -50,7 +51,7 @@ func (c *ClientCmd) newListAffiliationCommand() *cobra.Command {
 		Short: "List affiliations",
 		Long:  "List affiliations visible to caller",
 		PreRunE: func(cmd *cobra.Command, args []string) error {
-			log.Level = log.LevelWarning
+			c.SetDefaultLogLevel(calog.WARNING)
 			err := c.ConfigInit()
 			if err != nil {
 				return err

cmd/fabric-ca-client/command/certificate.go

@@ -14,6 +14,7 @@ import (
 	"github.com/cloudflare/cfssl/log"
 	"github.com/hyperledger/fabric-ca/api"
 	"github.com/hyperledger/fabric-ca/lib"
+	calog "github.com/hyperledger/fabric-ca/lib/common/log"
 	"github.com/hyperledger/fabric-ca/util"
 	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
@@ -73,7 +74,7 @@ func newListCertificateCommand(c *certificateCommand) *cobra.Command {
 }
 
 func (c *certificateCommand) preRunCertificate(cmd *cobra.Command, args []string) error {
-	log.Level = log.LevelWarning
+	c.command.SetDefaultLogLevel(calog.WARNING)
 	err := c.command.ConfigInit()
 	if err != nil {
 		return err

cmd/fabric-ca-client/command/certificate_test.go

@@ -45,6 +45,7 @@ func TestCreateCertificateCommand(t *testing.T) {
 
 func TestBadPreRunCertificate(t *testing.T) {
 	mockBadClientCmd := new(mocks.Command)
+	mockBadClientCmd.On("SetDefaultLogLevel", "warning")
 	mockBadClientCmd.On("ConfigInit").Return(errors.New("Failed to initialize config"))
 	cmd := newCertificateCommand(mockBadClientCmd)
 	err := cmd.preRunCertificate(&cobra.Command{}, []string{})
@@ -53,6 +54,7 @@ func TestBadPreRunCertificate(t *testing.T) {
 
 func TestGoodPreRunCertificate(t *testing.T) {
 	mockGoodClientCmd := new(mocks.Command)
+	mockGoodClientCmd.On("SetDefaultLogLevel", "warning")
 	mockGoodClientCmd.On("ConfigInit").Return(nil)
 	mockGoodClientCmd.On("GetClientCfg").Return(&lib.ClientConfig{})
 	cmd := newCertificateCommand(mockGoodClientCmd)
@@ -62,6 +64,7 @@ func TestGoodPreRunCertificate(t *testing.T) {
 
 func TestFailLoadIdentity(t *testing.T) {
 	mockBadClientCmd := new(mocks.Command)
+	mockBadClientCmd.On("SetDefaultLogLevel", "warning")
 	mockBadClientCmd.On("LoadMyIdentity").Return(nil, errors.New("Failed to load identity"))
 	cmd := newCertificateCommand(mockBadClientCmd)
 	err := cmd.runListCertificate(&cobra.Command{}, []string{})
@@ -70,6 +73,7 @@ func TestFailLoadIdentity(t *testing.T) {
 
 func TestBadRunListCertificate(t *testing.T) {
 	cmd := new(mocks.Command)
+	cmd.On("SetDefaultLogLevel", "warning")
 	cmd.On("LoadMyIdentity").Return(&lib.Identity{}, nil)
 	certCmd := newCertificateCommand(cmd)
 	certCmd.timeArgs = timeArgs{
@@ -81,6 +85,7 @@ func TestBadRunListCertificate(t *testing.T) {
 
 func TestBadExpirationTime(t *testing.T) {
 	cmd := new(mocks.Command)
+	cmd.On("SetDefaultLogLevel", "warning")
 	cmd.On("LoadMyIdentity").Return(&lib.Identity{}, nil)
 	certCmd := newCertificateCommand(cmd)
 	certCmd.timeArgs = timeArgs{
@@ -98,6 +103,7 @@ func TestBadExpirationTime(t *testing.T) {
 
 func TestGoodExpirationTime(t *testing.T) {
 	cmd := new(mocks.Command)
+	cmd.On("SetDefaultLogLevel", "warning")
 	cmd.On("LoadMyIdentity").Return(&lib.Identity{}, nil)
 	certCmd := newCertificateCommand(cmd)
 	certCmd.timeArgs = timeArgs{
@@ -109,6 +115,7 @@ func TestGoodExpirationTime(t *testing.T) {
 
 func TestBadRevocationTime(t *testing.T) {
 	cmd := new(mocks.Command)
+	cmd.On("SetDefaultLogLevel", "warning")
 	cmd.On("LoadMyIdentity").Return(&lib.Identity{}, nil)
 	certCmd := newCertificateCommand(cmd)
 	certCmd.timeArgs = timeArgs{
@@ -126,6 +133,7 @@ func TestBadRevocationTime(t *testing.T) {
 
 func TestGoodRevocationTime(t *testing.T) {
 	cmd := new(mocks.Command)
+	cmd.On("SetDefaultLogLevel", "warning")
 	cmd.On("LoadMyIdentity").Return(&lib.Identity{}, nil)
 	certCmd := newCertificateCommand(cmd)
 	certCmd.timeArgs = timeArgs{

cmd/fabric-ca-client/command/clientcmd.go

@@ -50,7 +50,10 @@ type Command interface {
 	GetClientCfg() *lib.ClientConfig
 	// Returns viper instance associated with this comamnd
 	GetViper() *viper.Viper
+	// Returns the client's home directoty
 	GetHomeDirectory() string
+	// Set the default level to be something other than 'info'
+	SetDefaultLogLevel(string)
 }
 
 type crlArgs struct {
@@ -109,8 +112,8 @@ type ClientCmd struct {
 	dynamicIdentity identityArgs
 	// Dynamically configuring affiliations
 	dynamicAffiliation affiliationArgs
-	// Enable debug level logging
-	debug bool
+	// Set to log level
+	logLevel string
 }
 
 // NewCommand returns new ClientCmd ready for running
@@ -200,7 +203,6 @@ func (c *ClientCmd) registerFlags() {
 		"Hostname to include in the certificate signing request during enrollment")
 	pflags.StringSliceVarP(
 		&c.cfgCsrNames, "csr.names", "", nil, "A list of comma-separated CSR names of the form <name>=<value> (e.g. C=CA,O=Org1)")
-	pflags.BoolVarP(&c.debug, "debug", "d", false, "Enable debug level logging")
 
 	c.clientCfg = &lib.ClientConfig{}
 	tags := map[string]string{
@@ -284,3 +286,8 @@ func (c *ClientCmd) GetCfgFileName() string {
 func (c *ClientCmd) GetViper() *viper.Viper {
 	return c.myViper
 }
+
+// SetDefaultLogLevel sets the default log level for a command to a specific level
+func (c *ClientCmd) SetDefaultLogLevel(logLevel string) {
+	c.logLevel = logLevel
+}

cmd/fabric-ca-client/command/config.go

@@ -20,6 +20,7 @@ import (
 	"github.com/hyperledger/fabric-ca/api"
 	"github.com/hyperledger/fabric-ca/lib"
 	"github.com/hyperledger/fabric-ca/lib/attr"
+	calog "github.com/hyperledger/fabric-ca/lib/common/log"
 	"github.com/hyperledger/fabric-ca/util"
 	"github.com/pkg/errors"
 )
@@ -202,8 +203,18 @@ bccsp:
 func (c *ClientCmd) ConfigInit() error {
 	var err error
 
-	if c.debug {
-		log.Level = log.LevelDebug
+	c.myViper.AutomaticEnv() // read in environment variables that match
+	logLevel := c.myViper.GetString("loglevel")
+	debug := c.myViper.GetBool("debug")
+
+	// If log level has been set via the new loglevel property use that as the loglevel
+	// and override any default log levels defined for the commands
+	if logLevel != "" {
+		c.logLevel = logLevel
+	}
+	calog.SetLogLevel(c.logLevel, debug)
+	if err != nil {
+		return err
 	}
 
 	c.cfgFileName, c.homeDirectory, err = util.ValidateAndReturnAbsConf(c.cfgFileName, c.homeDirectory, cmdName)
@@ -215,7 +226,6 @@ func (c *ClientCmd) ConfigInit() error {
 
 	// Set configuration file name for viper and configure it to read env variables
 	c.myViper.SetConfigFile(c.cfgFileName)
-	c.myViper.AutomaticEnv() // read in environment variables that match
 
 	// If the config file doesn't exist, create a default one if enroll
 	// command being executed. Enroll should be the first command to be

cmd/fabric-ca-client/command/identity.go

@@ -22,6 +22,7 @@ import (
 	"github.com/cloudflare/cfssl/log"
 	"github.com/hyperledger/fabric-ca/api"
 	"github.com/hyperledger/fabric-ca/lib"
+	calog "github.com/hyperledger/fabric-ca/lib/common/log"
 	"github.com/hyperledger/fabric-ca/util"
 	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
@@ -54,7 +55,7 @@ func (c *ClientCmd) newListIdentityCommand() *cobra.Command {
 		Short: "List identities",
 		Long:  "List identities visible to caller",
 		PreRunE: func(cmd *cobra.Command, args []string) error {
-			log.Level = log.LevelWarning
+			c.SetDefaultLogLevel(calog.WARNING)
 			err := c.ConfigInit()
 			if err != nil {
 				return err

cmd/fabric-ca-client/command/main_test.go

@@ -2138,6 +2138,49 @@ func TestDebugSetting(t *testing.T) {
 	assert.Equal(t, 0, log.Level) // With '-d' flag log level should be debug (0)
 }
 
+func TestClientLogLevelCLI(t *testing.T) {
+	// Not passing in -u flag, don't need for the enroll to complete successfully to
+	// verify that the log level is correctly getting set
+	RunMain([]string{cmdName, "enroll", "--loglevel", "info"})
+	assert.Equal(t, log.Level, log.LevelInfo)
+
+	RunMain([]string{cmdName, "enroll", "--loglevel", "debug"})
+	assert.Equal(t, log.Level, log.LevelDebug)
+
+	RunMain([]string{cmdName, "enroll", "--loglevel", "warning"})
+	assert.Equal(t, log.Level, log.LevelWarning)
+
+	RunMain([]string{cmdName, "enroll", "--loglevel", "fatal"})
+	assert.Equal(t, log.Level, log.LevelFatal)
+
+	RunMain([]string{cmdName, "enroll", "--loglevel", "critical"})
+	assert.Equal(t, log.Level, log.LevelCritical)
+}
+
+func TestClientLogLevelEnvVar(t *testing.T) {
+	// Not passing in -u flag, don't need for the enroll to complete successfully to
+	// verify that the log level is correctly getting set
+	os.Setenv("FABRIC_CA_CLIENT_LOGLEVEL", "info")
+	RunMain([]string{cmdName, "enroll"})
+	assert.Equal(t, log.Level, log.LevelInfo)
+
+	os.Setenv("FABRIC_CA_CLIENT_LOGLEVEL", "debug")
+	RunMain([]string{cmdName, "enroll"})
+	assert.Equal(t, log.Level, log.LevelDebug)
+
+	os.Setenv("FABRIC_CA_CLIENT_LOGLEVEL", "warning")
+	RunMain([]string{cmdName, "enroll"})
+	assert.Equal(t, log.Level, log.LevelWarning)
+
+	os.Setenv("FABRIC_CA_CLIENT_LOGLEVEL", "fatal")
+	RunMain([]string{cmdName, "enroll"})
+	assert.Equal(t, log.Level, log.LevelFatal)
+
+	os.Setenv("FABRIC_CA_CLIENT_LOGLEVEL", "critical")
+	RunMain([]string{cmdName, "enroll"})
+	assert.Equal(t, log.Level, log.LevelCritical)
+}
+
 func TestCleanUp(t *testing.T) {
 	os.Remove(filepath.Join(tdDir, "ca-cert.pem"))
 	os.Remove(filepath.Join(tdDir, "ca-key.pem"))

cmd/fabric-ca-server/config.go

@@ -14,6 +14,7 @@ import (
 
 	"github.com/cloudflare/cfssl/log"
 	"github.com/hyperledger/fabric-ca/lib"
+	calog "github.com/hyperledger/fabric-ca/lib/common/log"
 	"github.com/hyperledger/fabric-ca/lib/metadata"
 	"github.com/hyperledger/fabric-ca/util"
 	"github.com/pkg/errors"
@@ -480,6 +481,11 @@ func (s *ServerCmd) configInit() (err error) {
 		return err
 	}
 
+	s.myViper.AutomaticEnv() // read in environment variables that match
+	logLevel := s.myViper.GetString("loglevel")
+	debug := s.myViper.GetBool("debug")
+	calog.SetLogLevel(logLevel, debug)
+
 	log.Debugf("Home directory: %s", s.homeDirectory)
 
 	// If the config file doesn't exist, create a default one
@@ -494,7 +500,6 @@ func (s *ServerCmd) configInit() (err error) {
 	}
 
 	// Read the config
-	s.myViper.AutomaticEnv() // read in environment variables that match
 	err = lib.UnmarshalConfig(s.cfg, s.myViper, s.cfgFileName, true)
 	if err != nil {
 		return err
@@ -565,7 +570,7 @@ func (s *ServerCmd) createDefaultConfigFile() error {
 	cfg = strings.Replace(cfg, "<<<ADMINPW>>>", pass, 1)
 	cfg = strings.Replace(cfg, "<<<MYHOST>>>", myhost, 1)
 	purl := s.myViper.GetString("intermediate.parentserver.url")
-	log.Debugf("parent server URL: '%s'", purl)
+	log.Debugf("parent server URL: '%s'", util.GetMaskedURL(purl))
 	if purl == "" {
 		// This is a root CA
 		cfg = strings.Replace(cfg, "<<<COMMONNAME>>>", "fabric-ca-server", 1)

cmd/fabric-ca-server/main_test.go

@@ -27,6 +27,7 @@ import (
 	"regexp"
 	"testing"
 
+	"github.com/cloudflare/cfssl/log"
 	"github.com/hyperledger/fabric-ca/api"
 	"github.com/hyperledger/fabric-ca/lib"
 	"github.com/hyperledger/fabric-ca/lib/metadata"
@@ -372,6 +373,49 @@ func TestVersion(t *testing.T) {
 	}
 }
 
+func TestServerLogLevelCLI(t *testing.T) {
+	// Not passing in -b flag, don't need for the server to completely start to
+	// verify that the log level is correctly getting set
+	RunMain([]string{cmdName, "start", "--loglevel", "info"})
+	assert.Equal(t, log.Level, log.LevelInfo)
+
+	RunMain([]string{cmdName, "start", "--loglevel", "debug"})
+	assert.Equal(t, log.Level, log.LevelDebug)
+
+	RunMain([]string{cmdName, "start", "--loglevel", "warning"})
+	assert.Equal(t, log.Level, log.LevelWarning)
+
+	RunMain([]string{cmdName, "start", "--loglevel", "fatal"})
+	assert.Equal(t, log.Level, log.LevelFatal)
+
+	RunMain([]string{cmdName, "start", "--loglevel", "critical"})
+	assert.Equal(t, log.Level, log.LevelCritical)
+}
+
+func TestServerLogLevelEnvVar(t *testing.T) {
+	// Not passing in -b flag, don't need for the server to completely start to
+	// verify that the log level is correctly getting set
+	os.Setenv("FABRIC_CA_SERVER_LOGLEVEL", "info")
+	RunMain([]string{cmdName, "start"})
+	assert.Equal(t, log.LevelInfo, log.Level)
+
+	os.Setenv("FABRIC_CA_SERVER_LOGLEVEL", "debug")
+	RunMain([]string{cmdName, "start"})
+	assert.Equal(t, log.LevelDebug, log.Level)
+
+	os.Setenv("FABRIC_CA_SERVER_LOGLEVEL", "warning")
+	RunMain([]string{cmdName, "start"})
+	assert.Equal(t, log.LevelWarning, log.Level)
+
+	os.Setenv("FABRIC_CA_SERVER_LOGLEVEL", "fatal")
+	RunMain([]string{cmdName, "start"})
+	assert.Equal(t, log.LevelFatal, log.Level)
+
+	os.Setenv("FABRIC_CA_SERVER_LOGLEVEL", "critical")
+	RunMain([]string{cmdName, "start"})
+	assert.Equal(t, log.LevelCritical, log.Level)
+}
+
 // Run server with specified args and check if the configuration and datasource
 // files exist in the specified locations
 func checkConfigAndDBLoc(t *testing.T, args TestData, cfgFile string, dsFile string) {

docs/source/clientcli.rst

@@ -30,7 +30,6 @@ Fabric-CA Client's CLI
           --csr.keyrequest.size int        Specify key size
           --csr.names stringSlice          A list of comma-separated CSR names of the form <name>=<value> (e.g. C=CA,O=Org1)
           --csr.serialnumber string        The serial number in a certificate signing request
-      -d, --debug                          Enable debug level logging
           --enrollment.attrs stringSlice   A list of comma-separated attribute requests of the form <name>[:opt] (e.g. foo,bar:opt)
           --enrollment.label string        Label to use in HSM operations
           --enrollment.profile string      Name of the signing profile to use in issuing the certificate
@@ -42,6 +41,7 @@ Fabric-CA Client's CLI
           --id.name string                 Unique name of the identity
           --id.secret string               The enrollment secret for the identity being registered
           --id.type string                 Type of identity being registered (e.g. 'peer, app, user') (default "client")
+          --loglevel string                Set logging level (info, warning, debug, error, fatal, critical)
       -M, --mspdir string                  Membership Service Provider directory (default "msp")
       -m, --myhost string                  Hostname to include in the certificate signing request during enrollment (default "$HOSTNAME")
       -a, --revoke.aki string              AKI (Authority Key Identifier) of the certificate to be revoked

docs/source/servercli.rst

@@ -37,7 +37,6 @@ Fabric-CA Server's CLI
           --db.tls.client.certfile string             PEM-encoded certificate file when mutual authenticate is enabled
           --db.tls.client.keyfile string              PEM-encoded key file when mutual authentication is enabled
           --db.type string                            Type of database; one of: sqlite3, postgres, mysql (default "sqlite3")
-      -d, --debug                                     Enable debug level logging
       -H, --home string                               Server's home directory (default "/etc/hyperledger/fabric-ca")
           --idemix.nonceexpiration string             Duration after which a nonce expires (default "15s")
           --idemix.noncesweepinterval string          Interval at which expired nonces are deleted (default "15m")
@@ -58,6 +57,7 @@ Fabric-CA Server's CLI
           --ldap.tls.client.keyfile string            PEM-encoded key file when mutual authentication is enabled
           --ldap.url string                           LDAP client URL of form ldap://adminDN:adminPassword@host[:port]/base
           --ldap.userfilter string                    The LDAP user filter to use when searching for users (default "(uid=%s)")
+          --loglevel string                           Set logging level (info, warning, debug, error, fatal, critical)
       -p, --port int                                  Listening port of fabric-ca-server (default 7054)
           --registry.maxenrollments int               Maximum number of enrollments; valid if LDAP not enabled (default -1)
           --tls.certfile string                       PEM-encoded TLS certificate file for server's listening port (default "tls-cert.pem")

lib/clientconfig.go

@@ -41,6 +41,8 @@ type ClientConfig struct {
 	CAInfo     api.GetCAInfoRequest
 	CAName     string               `help:"Name of CA"`
 	CSP        *factory.FactoryOpts `mapstructure:"bccsp" hide:"true"`
+	Debug      bool                 `opt:"d" help:"Enable debug level logging" hide:"true"`
+	LogLevel   string               `help:"Set logging level (info, warning, debug, error, fatal, critical)"`
 }
 
 // Enroll a client given the server's URL and the client's home directory.