From 6271740817001163a5a83e8270873adfed663473 Mon Sep 17 00:00:00 2001 From: Ray Chen Date: Mon, 16 Jan 2017 23:58:24 +0800 Subject: [PATCH] [FAB-1217] Integrate flogging with gossip logging Integrate the flogging package with gossip logging, making the gossip logging control consistent with the logging control methods of the core fabric modules. - Support all the control methods described in the logging control document when gossip is in a peer process, see: https://hyperledger-fabric.readthedocs.io/en/latest/Setup/logging-control/ For example, if the gossip modules is called by `peer node start`, the gossip logging level can be overridden in these ways listed below, from strongest to weakest: 1. The --logging-level= command line option. 2. The CORE_LOGGING_LEVEL env variable. 3. The CORE_LOGGING_NODE env variable. 4. The "logging.node" spec defined in the peer/core.yaml file. And a command like: peer logging setlevel [flags] can set logging level for a specified module on the fly. - Fallback to gossip's default logging level and format when gossip is not in a peer process. The current default logging level is set to "WARNING", and the default logging format is taken from the flogging package. Resolves FAB-1217. Change-Id: I57e0d5ca4dc10a4774e3ac20e2e71e6ff85e18b8 Signed-off-by: Xiaoyi Wang Signed-off-by: Ray Chen --- gossip/comm/comm_impl.go | 4 +- gossip/comm/conn.go | 8 +-- gossip/comm/mock/mock_comm.go | 9 +--- gossip/discovery/discovery_impl.go | 4 +- gossip/discovery/discovery_test.go | 2 - gossip/election/election.go | 4 +- gossip/gossip/certstore.go | 7 ++- gossip/gossip/channel/channel.go | 5 +- gossip/gossip/chanstate.go | 4 +- gossip/gossip/gossip_impl.go | 7 +-- gossip/gossip/pull/pullstore.go | 5 +- gossip/service/gossip_service.go | 4 +- gossip/state/payloads_buffer.go | 4 +- gossip/state/state.go | 9 +--- gossip/state/state_test.go | 4 +- gossip/util/logging.go | 81 +++++++++++------------------- 16 files changed, 60 insertions(+), 101 deletions(-) diff --git a/gossip/comm/comm_impl.go b/gossip/comm/comm_impl.go index 6cc31985093..b09ef3c1d26 100644 --- a/gossip/comm/comm_impl.go +++ b/gossip/comm/comm_impl.go @@ -113,8 +113,6 @@ func NewCommInstanceWithServer(port int, idMapper identity.Mapper, peerIdentity proto.RegisterGossipServer(s, commInst) } - commInst.logger.SetLevel(logging.WARNING) - return commInst, nil } @@ -143,7 +141,7 @@ type commImpl struct { selfCertHash []byte peerIdentity api.PeerIdentityType idMapper identity.Mapper - logger *util.Logger + logger *logging.Logger opts []grpc.DialOption connStore *connectionStore PKIID []byte diff --git a/gossip/comm/conn.go b/gossip/comm/conn.go index 89bf72246bb..95d6719601f 100644 --- a/gossip/comm/conn.go +++ b/gossip/comm/conn.go @@ -23,7 +23,7 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/proto" - "github.com/hyperledger/fabric/gossip/util" + "github.com/op/go-logging" "google.golang.org/grpc" ) @@ -34,7 +34,7 @@ type connFactory interface { } type connectionStore struct { - logger *util.Logger // logger + logger *logging.Logger // logger isClosing bool // whether this connection store is shutting down connFactory connFactory // creates a connection to remote peer sync.RWMutex // synchronize access to shared variables @@ -43,7 +43,7 @@ type connectionStore struct { // used to prevent concurrent connection establishment to the same remote endpoint } -func newConnStore(connFactory connFactory, logger *util.Logger) *connectionStore { +func newConnStore(connFactory connFactory, logger *logging.Logger) *connectionStore { return &connectionStore{ connFactory: connFactory, isClosing: false, @@ -197,7 +197,7 @@ func newConnection(cl proto.GossipClient, c *grpc.ClientConn, cs proto.Gossip_Go type connection struct { outBuff chan *msgSending - logger *util.Logger // logger + logger *logging.Logger // logger pkiID common.PKIidType // pkiID of the remote endpoint handler handler // function to invoke upon a message reception conn *grpc.ClientConn // gRPC connection to remote endpoint diff --git a/gossip/comm/mock/mock_comm.go b/gossip/comm/mock/mock_comm.go index 2f8884284e3..8c8b346de76 100644 --- a/gossip/comm/mock/mock_comm.go +++ b/gossip/comm/mock/mock_comm.go @@ -20,7 +20,7 @@ import ( "github.com/hyperledger/fabric/gossip/comm" "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/proto" - "github.com/op/go-logging" + "github.com/hyperledger/fabric/gossip/util" ) // Mock which aims to simulate socket @@ -61,12 +61,7 @@ type commMock struct { done chan struct{} } -var logger *logging.Logger // package-level logger - -func init() { - logger = logging.MustGetLogger("mockComm") - logging.SetLevel(logging.DEBUG, logger.Module) -} +var logger = util.GetLogger(util.LoggingMockModule, "") // NewCommMock creates mocked communication object func NewCommMock(id string, members map[string]*socketMock) comm.Comm { diff --git a/gossip/discovery/discovery_impl.go b/gossip/discovery/discovery_impl.go index 335a794baa3..6792d3b292c 100644 --- a/gossip/discovery/discovery_impl.go +++ b/gossip/discovery/discovery_impl.go @@ -91,7 +91,7 @@ type gossipDiscoveryImpl struct { toDieChan chan struct{} toDieFlag int32 - logger *util.Logger + logger *logging.Logger } // NewDiscoveryService returns a new discovery service with the comm module passed and the crypto service passed @@ -118,8 +118,6 @@ func NewDiscoveryService(bootstrapPeers []string, self NetworkMember, comm CommS logger: util.GetLogger(util.LoggingDiscoveryModule, self.Endpoint), } - d.logger.SetLevel(logging.WARNING) - go d.periodicalSendAlive() go d.periodicalCheckAlive() go d.handleMessages() diff --git a/gossip/discovery/discovery_test.go b/gossip/discovery/discovery_test.go index da2873fe3ea..86185c8fe74 100644 --- a/gossip/discovery/discovery_test.go +++ b/gossip/discovery/discovery_test.go @@ -27,7 +27,6 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/proto" - "github.com/op/go-logging" "github.com/stretchr/testify/assert" "golang.org/x/net/context" "google.golang.org/grpc" @@ -245,7 +244,6 @@ func createDiscoveryInstanceThatGossips(port int, id string, bootstrapPeers []st s := grpc.NewServer() discSvc := NewDiscoveryService(bootstrapPeers, self, comm, comm) - discSvc.(*gossipDiscoveryImpl).logger.SetLevel(logging.WARNING) gossInst := &gossipInstance{comm: comm, gRGCserv: s, Discovery: discSvc, lsnr: ll, shouldGossip: shouldGossip} proto.RegisterGossipServer(s, gossInst) diff --git a/gossip/election/election.go b/gossip/election/election.go index 42c6be5d3e8..f9e64aac982 100644 --- a/gossip/election/election.go +++ b/gossip/election/election.go @@ -143,7 +143,7 @@ func NewLeaderElectionService(adapter LeaderElectionAdapter, id string, callback adapter: adapter, stopChan: make(chan struct{}, 1), interruptChan: make(chan struct{}, 1), - logger: logging.MustGetLogger("LeaderElection"), + logger: util.GetLogger(util.LoggingElectionModule, ""), callback: noopCallback, } @@ -151,8 +151,6 @@ func NewLeaderElectionService(adapter LeaderElectionAdapter, id string, callback le.callback = callback } - // TODO: This will be configured using the core.yaml when FAB-1217 (Integrate peer logging with gossip logging) is done - logging.SetLevel(logging.WARNING, "LeaderElection") go le.start() return le } diff --git a/gossip/gossip/certstore.go b/gossip/gossip/certstore.go index 38f015024ce..d23c03679cd 100644 --- a/gossip/gossip/certstore.go +++ b/gossip/gossip/certstore.go @@ -28,6 +28,7 @@ import ( "github.com/hyperledger/fabric/gossip/identity" "github.com/hyperledger/fabric/gossip/proto" "github.com/hyperledger/fabric/gossip/util" + "github.com/op/go-logging" ) // certStore supports pull dissemination of identity messages @@ -36,13 +37,13 @@ type certStore struct { selfIdentity api.PeerIdentityType idMapper identity.Mapper pull pull.Mediator - logger *util.Logger + logger *logging.Logger mcs api.MessageCryptoService } func newCertStore(puller pull.Mediator, idMapper identity.Mapper, selfIdentity api.PeerIdentityType, mcs api.MessageCryptoService) *certStore { selfPKIID := idMapper.GetPKIidOfCert(selfIdentity) - logger := util.GetLogger("certStore", string(selfPKIID)) + logger := util.GetLogger(util.LoggingGossipModule, string(selfPKIID)) if err := idMapper.Put(selfPKIID, selfIdentity); err != nil { logger.Error("Failed associating self PKIID to cert:", err) panic(fmt.Errorf("Failed associating self PKIID to cert: %v", err)) @@ -56,8 +57,6 @@ func newCertStore(puller pull.Mediator, idMapper identity.Mapper, selfIdentity a logger: logger, } - certStore.logger = util.GetLogger("certStore", string(selfPKIID)) - if err := certStore.idMapper.Put(selfPKIID, selfIdentity); err != nil { certStore.logger.Panic("Failed associating self PKIID to cert:", err) } diff --git a/gossip/gossip/channel/channel.go b/gossip/gossip/channel/channel.go index 82e8c53a15e..52e9d33d114 100644 --- a/gossip/gossip/channel/channel.go +++ b/gossip/gossip/channel/channel.go @@ -32,6 +32,7 @@ import ( "github.com/hyperledger/fabric/gossip/gossip/pull" "github.com/hyperledger/fabric/gossip/proto" "github.com/hyperledger/fabric/gossip/util" + "github.com/op/go-logging" ) // Config is a configuration item @@ -122,7 +123,7 @@ type gossipChannel struct { leaderMsgStore msgstore.MessageStore chainID common.ChainID blocksPuller pull.Mediator - logger *util.Logger + logger *logging.Logger stateInfoPublishScheduler *time.Ticker stateInfoRequestScheduler *time.Ticker memFilter *membershipFilter @@ -149,7 +150,7 @@ func NewGossipChannel(mcs api.MessageCryptoService, chainID common.ChainID, adap gc := &gossipChannel{ mcs: mcs, Adapter: adapter, - logger: util.GetLogger("channelState", adapter.GetConf().ID), + logger: util.GetLogger(util.LoggingChannelModule, adapter.GetConf().ID), stopChan: make(chan struct{}, 1), shouldGossipStateInfo: int32(0), stateInfoPublishScheduler: time.NewTicker(adapter.GetConf().PublishStateInfoInterval), diff --git a/gossip/gossip/chanstate.go b/gossip/gossip/chanstate.go index e0e2b905545..016175d6019 100644 --- a/gossip/gossip/chanstate.go +++ b/gossip/gossip/chanstate.go @@ -29,7 +29,7 @@ import ( "github.com/hyperledger/fabric/gossip/gossip/msgstore" "github.com/hyperledger/fabric/gossip/gossip/pull" "github.com/hyperledger/fabric/gossip/proto" - "github.com/hyperledger/fabric/gossip/util" + "github.com/op/go-logging" ) type channelState struct { @@ -159,7 +159,7 @@ type gossipChannel struct { stateInfoMsgStore msgstore.MessageStore chainID common.ChainID blocksPuller pull.Mediator - logger *util.Logger + logger *logging.Logger stateInfoPublishScheduler *time.Ticker stateInfoRequestScheduler *time.Ticker } diff --git a/gossip/gossip/gossip_impl.go b/gossip/gossip/gossip_impl.go index 583d19be58c..d02f5cb5095 100644 --- a/gossip/gossip/gossip_impl.go +++ b/gossip/gossip/gossip_impl.go @@ -35,6 +35,7 @@ import ( "github.com/hyperledger/fabric/gossip/identity" "github.com/hyperledger/fabric/gossip/proto" "github.com/hyperledger/fabric/gossip/util" + "github.com/op/go-logging" "google.golang.org/grpc" ) @@ -56,7 +57,7 @@ type gossipServiceImpl struct { incTime time.Time selfOrg api.OrgIdentityType *comm.ChannelDeMultiplexer - logger *util.Logger + logger *logging.Logger stopSignal *sync.WaitGroup conf *Config toDieChan chan struct{} @@ -687,10 +688,10 @@ type discoverySecurityAdapter struct { idMapper identity.Mapper mcs api.MessageCryptoService c comm.Comm - logger *util.Logger + logger *logging.Logger } -func newDiscoverySecurityAdapter(idMapper identity.Mapper, mcs api.MessageCryptoService, c comm.Comm, logger *util.Logger) *discoverySecurityAdapter { +func newDiscoverySecurityAdapter(idMapper identity.Mapper, mcs api.MessageCryptoService, c comm.Comm, logger *logging.Logger) *discoverySecurityAdapter { return &discoverySecurityAdapter{ idMapper: idMapper, mcs: mcs, diff --git a/gossip/gossip/pull/pullstore.go b/gossip/gossip/pull/pullstore.go index 0b793f137ad..e16a68493c7 100644 --- a/gossip/gossip/pull/pullstore.go +++ b/gossip/gossip/pull/pullstore.go @@ -26,6 +26,7 @@ import ( "github.com/hyperledger/fabric/gossip/gossip/algo" "github.com/hyperledger/fabric/gossip/proto" "github.com/hyperledger/fabric/gossip/util" + "github.com/op/go-logging" ) const ( @@ -91,7 +92,7 @@ type pullMediatorImpl struct { idExtractor proto.IdentifierExtractor msgCons proto.MsgConsumer config PullConfig - logger *util.Logger + logger *logging.Logger sync.RWMutex itemId2msg map[string]*proto.GossipMessage Sender @@ -105,7 +106,7 @@ func NewPullMediator(config PullConfig, sndr Sender, memSvc MembershipService, i msgType2Hook: make(map[PullMsgType][]MessageHook), idExtractor: idExtractor, config: config, - logger: util.GetLogger("Pull", config.Id), + logger: util.GetLogger(util.LoggingPullModule, config.Id), itemId2msg: make(map[string]*proto.GossipMessage), memBvc: memSvc, Sender: sndr, diff --git a/gossip/service/gossip_service.go b/gossip/service/gossip_service.go index 28da598bb01..6dbbcfdde56 100644 --- a/gossip/service/gossip_service.go +++ b/gossip/service/gossip_service.go @@ -28,8 +28,8 @@ import ( "github.com/hyperledger/fabric/gossip/integration" "github.com/hyperledger/fabric/gossip/proto" "github.com/hyperledger/fabric/gossip/state" + "github.com/hyperledger/fabric/gossip/util" "github.com/hyperledger/fabric/protos/common" - "github.com/op/go-logging" "google.golang.org/grpc" ) @@ -90,7 +90,7 @@ func (jcm *joinChannelMessage) AnchorPeers() []api.AnchorPeer { return jcm.anchorPeers } -var logger = logging.MustGetLogger("gossipService") +var logger = util.GetLogger(util.LoggingServiceModule, "") // InitGossipService initialize gossip service func InitGossipService(identity []byte, endpoint string, s *grpc.Server, bootPeers ...string) { diff --git a/gossip/state/payloads_buffer.go b/gossip/state/payloads_buffer.go index 9bc142e56fd..fbdea3f1b83 100644 --- a/gossip/state/payloads_buffer.go +++ b/gossip/state/payloads_buffer.go @@ -23,6 +23,7 @@ import ( "sync/atomic" "github.com/hyperledger/fabric/gossip/proto" + "github.com/hyperledger/fabric/gossip/util" "github.com/op/go-logging" ) @@ -66,12 +67,11 @@ type PayloadsBufferImpl struct { // NewPayloadsBuffer is factory function to create new payloads buffer func NewPayloadsBuffer(next uint64) PayloadsBuffer { - logger, _ := logging.GetLogger("GossipStateProvider") return &PayloadsBufferImpl{ buf: make(map[uint64]*proto.Payload), readyChan: make(chan struct{}, 0), next: next, - logger: logger, + logger: util.GetLogger(util.LoggingStateModule, ""), } } diff --git a/gossip/state/state.go b/gossip/state/state.go index 0ca3911a28a..59c3850421b 100644 --- a/gossip/state/state.go +++ b/gossip/state/state.go @@ -29,6 +29,7 @@ import ( common2 "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/gossip" "github.com/hyperledger/fabric/gossip/proto" + "github.com/hyperledger/fabric/gossip/util" "github.com/hyperledger/fabric/protos/common" "github.com/op/go-logging" ) @@ -47,10 +48,6 @@ type GossipStateProvider interface { Stop() } -var logFormat = logging.MustStringFormatter( - `%{color}%{level} %{longfunc}():%{color:reset}(%{module})%{message}`, -) - var remoteStateMsgFilter = func(message interface{}) bool { return message.(comm.ReceivedMessage).GetGossipMessage().IsRemoteStateMessage() } @@ -92,7 +89,7 @@ type GossipStateProviderImpl struct { // NewGossipStateProvider creates initialized instance of gossip state provider func NewGossipStateProvider(chainID string, g gossip.Gossip, committer committer.Committer) GossipStateProvider { - logger, _ := logging.GetLogger("GossipStateProvider") + logger := util.GetLogger(util.LoggingStateModule, "") gossipChan, _ := g.Accept(func(message interface{}) bool { // Get only data messages @@ -133,8 +130,6 @@ func NewGossipStateProvider(chainID string, g gossip.Gossip, committer committer logger: logger, } - logging.SetFormatter(logFormat) - state := NewNodeMetastate(height - 1) s.logger.Infof("Updating node metadata information, current ledger sequence is at = %d, next expected block is = %d", state.LedgerHeight, s.payloads.Next()) diff --git a/gossip/state/state_test.go b/gossip/state/state_test.go index 564f7d4e81b..e4db73e83fe 100644 --- a/gossip/state/state_test.go +++ b/gossip/state/state_test.go @@ -35,15 +35,15 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/gossip" "github.com/hyperledger/fabric/gossip/proto" + gossipUtil "github.com/hyperledger/fabric/gossip/util" pcomm "github.com/hyperledger/fabric/protos/common" - "github.com/op/go-logging" "github.com/spf13/viper" "github.com/stretchr/testify/assert" ) var ( portPrefix = 5610 - logger, _ = logging.GetLogger("GossipStateProviderTest") + logger = gossipUtil.GetLogger(gossipUtil.LoggingStateModule, "") ) var orgId = []byte("ORG1") diff --git a/gossip/util/logging.go b/gossip/util/logging.go index 34acd8395e5..b8980823bc3 100644 --- a/gossip/util/logging.go +++ b/gossip/util/logging.go @@ -17,66 +17,52 @@ limitations under the License. package util import ( - "fmt" "io/ioutil" "log" - "os" "sync" + "github.com/hyperledger/fabric/common/flogging" "github.com/op/go-logging" "google.golang.org/grpc/grpclog" ) +// Module names for logger initialization. const ( - // LoggingMessageBuffModule defines the module for logging message buffer - LoggingMessageBuffModule = "mbuff" - // LoggingEmitterModule defines the module for logging emitter - LoggingEmitterModule = "emitter" - // LoggingGossipModule defines the module for logging gossip - LoggingGossipModule = "gossip" - // LoggingDiscoveryModule defines the module for logging discovery - LoggingDiscoveryModule = "discovery" - // LoggingCommModule defines the module for logging communication - LoggingCommModule = "comm" + LoggingChannelModule = "gossip/channel" + LoggingCommModule = "gossip/comm" + LoggingDiscoveryModule = "gossip/discovery" + LoggingElectionModule = "gossip/election" + LoggingGossipModule = "gossip/gossip" + LoggingMockModule = "gossip/comm/mock" + LoggingPullModule = "gossip/pull" + LoggingServiceModule = "gossip/service" + LoggingStateModule = "gossip/state" ) -var loggersByModules = make(map[string]*Logger) -var defaultLevel = logging.WARNING +var loggersByModules = make(map[string]*logging.Logger) var lock = sync.Mutex{} +var logger = logging.MustGetLogger("gossip/util") -var format = logging.MustStringFormatter( - `%{color} %{level} %{longfunc}():%{color:reset}(%{module})%{message}`, -) +// defaultSpec is used to set the default logging level for all the +// gossip modules. +var defaultSpec = "WARNING" func init() { - logging.SetFormatter(format) - grpclog.SetLogger(log.New(ioutil.Discard, "", 0)) -} - -// Logger defines a logger for gossip -type Logger struct { - logging.Logger - module string -} - -// SetDefaultFormat sets the formatter for the gossip logger -func SetDefaultFormat(formatStr string) { - format = logging.MustStringFormatter(formatStr) -} + // This make sure we get a "leveled" logging using the default + // format and output location defined in the flogging package, + // when the gossip module is not called from a peer process. + flogging.InitFromSpec(defaultSpec) + logger.Debugf("Setting default logging level to %s.", defaultSpec) -// SetDefaultLoggingLevel sets the default logging level for the gossip logger -func SetDefaultLoggingLevel(level logging.Level) { - defaultLevel = level -} - -// SetLevel sets the level for the logger -func (l *Logger) SetLevel(lvl logging.Level) { - logging.SetLevel(lvl, l.module) + grpclog.SetLogger(log.New(ioutil.Discard, "", 0)) } // GetLogger returns a logger for given gossip module and peerID -func GetLogger(module string, peerID string) *Logger { - module = module + "-" + peerID +func GetLogger(module string, peerID string) *logging.Logger { + if peerID != "" { + module = module + "#" + peerID + } + lock.Lock() defer lock.Unlock() @@ -85,18 +71,7 @@ func GetLogger(module string, peerID string) *Logger { } // Logger doesn't exist, create a new one - - lvl, err := logging.LogLevel(defaultLevel.String()) - // Shouldn't happen, since setting default logging level validity - // is checked in compile-time - if err != nil { - fmt.Fprintf(os.Stderr, "Invalid default logging level: %v\n", err) - return nil - } - logging.SetLevel(lvl, module) - lgr := &Logger{} - lgr.Logger = *logging.MustGetLogger(module) - lgr.module = module + lgr := logging.MustGetLogger(module) loggersByModules[module] = lgr return lgr }