Add ability to customize peer logging format

The logging.format string defined in peer/core.yaml will
be used to format all logging messages on the peer. See
https://godoc.org/github.com/op/go-logging#NewStringFormatter
for more details on customizing the format string.

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

Author: wlahti

core/flogging/logging.go

@@ -17,6 +17,7 @@ limitations under the License.
 package flogging
 
 import (
+	"io"
 	"os"
 	"strings"
 
@@ -27,6 +28,9 @@ import (
 // A logger to log logging logs!
 var loggingLogger = logging.MustGetLogger("logging")
 
+var loggingDefaultFormat = "%{color}%{time:2006-01-02 15:04:05.000 MST} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x}%{color:reset} %{message}"
+var loggingDefaultOutput = os.Stderr
+
 // The default logging level, in force until LoggingInit() is called or in
 // case of configuration errors.
 var loggingDefaultLevel = logging.INFO
@@ -87,15 +91,26 @@ func DefaultLoggingLevel() logging.Level {
 	return loggingDefaultLevel
 }
 
-// Initiate 'leveled' logging to stderr.
+// Initiate 'leveled' logging using the default format and output location
 func init() {
+	SetLoggingFormat(loggingDefaultFormat, loggingDefaultOutput)
+}
 
-	format := logging.MustStringFormatter(
-		"%{color}%{time:2006-01-02 15:04:05.000 MST} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x}%{color:reset} %{message}",
-	)
+// SetLoggingFormat sets the logging format and the location of the log output
+func SetLoggingFormat(formatString string, output io.Writer) {
+	if formatString == "" {
+		formatString = loggingDefaultFormat
+	}
+	format := logging.MustStringFormatter(formatString)
+
+	initLoggingBackend(format, output)
+}
 
-	backend := logging.NewLogBackend(os.Stderr, "", 0)
-	backendFormatter := logging.NewBackendFormatter(backend, format)
+// initialize the logging backend based on the provided logging formatter
+// and I/O writer
+func initLoggingBackend(logFormatter logging.Formatter, output io.Writer) {
+	backend := logging.NewLogBackend(output, "", 0)
+	backendFormatter := logging.NewBackendFormatter(backend, logFormatter)
 	logging.SetBackend(backendFormatter).SetLevel(loggingDefaultLevel, "")
 }
 

core/flogging/logging_test.go

@@ -17,6 +17,7 @@ limitations under the License.
 package flogging_test
 
 import (
+	"os"
 	"testing"
 
 	"github.com/hyperledger/fabric/core/flogging"
@@ -186,6 +187,36 @@ func TestSetModuleLoggingLevelInvalid(t *testing.T) {
 	assertModuleLoggingLevel(t, "peer", logging.WARNING)
 }
 
+func ExampleSetLoggingFormat() {
+	// initializes logging backend for testing and sets
+	// time to 1970-01-01 00:00:00.000 UTC
+	logging.InitForTesting(flogging.DefaultLoggingLevel())
+
+	logFormat := "%{time:2006-01-02 15:04:05.000 MST} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x} %{message}"
+	flogging.SetLoggingFormat(logFormat, os.Stdout)
+
+	logger := logging.MustGetLogger("floggingTest")
+	logger.Infof("test")
+
+	// Output:
+	// 1970-01-01 00:00:00.000 UTC [floggingTest] ExampleSetLoggingFormat -> INFO 001 test
+}
+
+func ExampleSetLoggingFormat_second() {
+	// initializes logging backend for testing and sets
+	// time to 1970-01-01 00:00:00.000 UTC
+	logging.InitForTesting(flogging.DefaultLoggingLevel())
+
+	logFormat := "%{time:15:04:05.000} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x} %{message}"
+	flogging.SetLoggingFormat(logFormat, os.Stdout)
+
+	logger := logging.MustGetLogger("floggingTest")
+	logger.Infof("test")
+
+	// Output:
+	// 00:00:00.000 [floggingTest] ExampleSetLoggingFormat_second -> INFO 001 test
+}
+
 func assertDefaultLoggingLevel(t *testing.T, expectedLevel logging.Level) {
 	assertModuleLoggingLevel(t, "", expectedLevel)
 }

peer/core.yaml

@@ -72,6 +72,8 @@ logging:
     protoutils: debug
     error:     warning
 
+    format: '%{color}%{time:2006-01-02 15:04:05.000 MST} [%{module}] %{shortfunc} -> %{level:.4s} %{id:03x}%{color:reset} %{message}'
+
 ###############################################################################
 #
 #    Peer section
@@ -417,9 +419,9 @@ ledger:
        username:
        password:
     # historyDatabase - options are true or false
-    # Indicates if the transaction history should be stored in 
+    # Indicates if the transaction history should be stored in
     # a querable database such as "CouchDB".
-    # The stateDatabase must be also stored in CouchDB for 
+    # The stateDatabase must be also stored in CouchDB for
     # history to be enabled.
     historyDatabase: false
 

peer/main.go

@@ -29,6 +29,7 @@ import (
 	_ "net/http/pprof"
 
 	"github.com/hyperledger/fabric/core"
+	"github.com/hyperledger/fabric/core/crypto/primitives"
 	"github.com/hyperledger/fabric/core/flogging"
 	"github.com/hyperledger/fabric/peer/chaincode"
 	"github.com/hyperledger/fabric/peer/clilogging"
@@ -38,6 +39,7 @@ import (
 )
 
 var logger = logging.MustGetLogger("main")
+var logOutput = os.Stderr
 
 // Constants go here.
 const cmdRoot = "core"
@@ -93,6 +95,13 @@ func main() {
 
 	runtime.GOMAXPROCS(viper.GetInt("peer.gomaxprocs"))
 
+	// initialize logging format from core.yaml
+	flogging.SetLoggingFormat(viper.GetString("logging.format"), logOutput)
+
+	// Init the crypto layer
+	//TODO: integrate new crypto / idp code
+	primitives.SetSecurityLevel("SHA2", 256)
+
 	// Init the MSP
 	// TODO: determine the location of this config file
 	var mspMgrConfigDir string