From 5d71f12f175886586f604d01a6969a480b18246f Mon Sep 17 00:00:00 2001 From: Will Lahti Date: Sun, 23 Apr 2017 10:30:05 -0400 Subject: [PATCH] [FAB-3144] Update gossip based on flogging changes This CR updates gossip-related logging features in light of the new changes to the `flogging` package. It 1) sets the log level at peer startup based on the value in core.yaml and 2) updates the gossip test cases to default to a log level of `warning`. Change-Id: I1b254379e8d0d2d0c8521bafcb9ce15ad6420d1a Signed-off-by: Will Lahti Signed-off-by: Yacov Manevich --- gossip/comm/comm_test.go | 1 + gossip/comm/crypto_test.go | 5 +++++ gossip/discovery/discovery_test.go | 2 ++ gossip/election/adapter_test.go | 5 +++++ gossip/election/election_test.go | 3 ++- gossip/gossip/algo/pull_test.go | 1 + gossip/gossip/batcher_test.go | 5 +++++ gossip/gossip/certstore_test.go | 2 ++ gossip/gossip/channel/channel_test.go | 2 ++ gossip/gossip/chanstate.go | 5 +++++ gossip/gossip/gossip_test.go | 1 + gossip/gossip/msgstore/msgs_test.go | 2 ++ gossip/gossip/orgs_test.go | 2 ++ gossip/gossip/pull/pullstore_test.go | 1 + gossip/identity/identity_test.go | 5 +++++ gossip/integration/integration_test.go | 5 +++++ gossip/service/eventer_test.go | 5 +++++ gossip/service/gossip_service.go | 4 ++++ gossip/service/gossip_service_test.go | 4 ++++ gossip/service/join_test.go | 5 +++++ gossip/state/metastate_test.go | 5 +++++ gossip/state/payloads_buffer_test.go | 5 +++++ gossip/state/state_test.go | 5 +++++ gossip/util/logging.go | 9 ++++++++- gossip/util/msgs_test.go | 4 ++++ peer/node/start.go | 20 +++++++------------- sampleconfig/core.yaml | 2 +- 27 files changed, 99 insertions(+), 16 deletions(-) diff --git a/gossip/comm/comm_test.go b/gossip/comm/comm_test.go index 274f015542c..65ee0bb6bcf 100644 --- a/gossip/comm/comm_test.go +++ b/gossip/comm/comm_test.go @@ -44,6 +44,7 @@ import ( ) func init() { + util.SetupTestLogging() rand.Seed(time.Now().UnixNano()) factory.InitFactories(nil) } diff --git a/gossip/comm/crypto_test.go b/gossip/comm/crypto_test.go index 5e53596644c..a053369773e 100644 --- a/gossip/comm/crypto_test.go +++ b/gossip/comm/crypto_test.go @@ -25,6 +25,7 @@ import ( "testing" "time" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/stretchr/testify/assert" "golang.org/x/net/context" @@ -40,6 +41,10 @@ type gossipTestServer struct { s *grpc.Server } +func init() { + util.SetupTestLogging() +} + func createTestServer(t *testing.T, cert *tls.Certificate) *gossipTestServer { tlsConf := &tls.Config{ Certificates: []tls.Certificate{*cert}, diff --git a/gossip/discovery/discovery_test.go b/gossip/discovery/discovery_test.go index db84904d61b..40d7c49d816 100644 --- a/gossip/discovery/discovery_test.go +++ b/gossip/discovery/discovery_test.go @@ -31,6 +31,7 @@ import ( "github.com/hyperledger/fabric/core/config" "github.com/hyperledger/fabric/gossip/common" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/spf13/viper" "github.com/stretchr/testify/assert" @@ -42,6 +43,7 @@ import ( var timeout = time.Second * time.Duration(15) func init() { + util.SetupTestLogging() aliveTimeInterval := time.Duration(time.Millisecond * 100) SetAliveTimeInterval(aliveTimeInterval) SetAliveExpirationTimeout(10 * aliveTimeInterval) diff --git a/gossip/election/adapter_test.go b/gossip/election/adapter_test.go index 836fec6d5af..abbcb958995 100644 --- a/gossip/election/adapter_test.go +++ b/gossip/election/adapter_test.go @@ -27,9 +27,14 @@ import ( "github.com/hyperledger/fabric/gossip/api" "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/discovery" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" ) +func init() { + util.SetupTestLogging() +} + func TestNewAdapter(t *testing.T) { selfNetworkMember := &discovery.NetworkMember{ Endpoint: "p0", diff --git a/gossip/election/election_test.go b/gossip/election/election_test.go index 8bc7eda7730..affbcc599f6 100644 --- a/gossip/election/election_test.go +++ b/gossip/election/election_test.go @@ -25,6 +25,7 @@ import ( "time" "github.com/hyperledger/fabric/core/config" + "github.com/hyperledger/fabric/gossip/util" "github.com/spf13/viper" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" @@ -36,7 +37,7 @@ const ( ) func init() { - + util.SetupTestLogging() SetStartupGracePeriod(time.Millisecond * 500) SetMembershipSampleInterval(time.Millisecond * 100) SetLeaderAliveThreshold(time.Millisecond * 500) diff --git a/gossip/gossip/algo/pull_test.go b/gossip/gossip/algo/pull_test.go index f3bae419eef..fc17c473e5c 100644 --- a/gossip/gossip/algo/pull_test.go +++ b/gossip/gossip/algo/pull_test.go @@ -32,6 +32,7 @@ import ( ) func init() { + util.SetupTestLogging() SetDigestWaitTime(time.Duration(100) * time.Millisecond) SetRequestWaitTime(time.Duration(200) * time.Millisecond) SetResponseWaitTime(time.Duration(200) * time.Millisecond) diff --git a/gossip/gossip/batcher_test.go b/gossip/gossip/batcher_test.go index fb020bec2e1..fd7aeb99d41 100644 --- a/gossip/gossip/batcher_test.go +++ b/gossip/gossip/batcher_test.go @@ -22,9 +22,14 @@ import ( "testing" "time" + "github.com/hyperledger/fabric/gossip/util" "github.com/stretchr/testify/assert" ) +func init() { + util.SetupTestLogging() +} + func TestBatchingEmitterAddAndSize(t *testing.T) { emitter := newBatchingEmitter(1, 10, time.Second, func(a []interface{}) {}) defer emitter.Stop() diff --git a/gossip/gossip/certstore_test.go b/gossip/gossip/certstore_test.go index 7e2fe2332d9..7e8922eecc0 100644 --- a/gossip/gossip/certstore_test.go +++ b/gossip/gossip/certstore_test.go @@ -27,12 +27,14 @@ import ( "github.com/hyperledger/fabric/gossip/gossip/algo" "github.com/hyperledger/fabric/gossip/gossip/pull" "github.com/hyperledger/fabric/gossip/identity" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" ) func init() { + util.SetupTestLogging() shortenedWaitTime := time.Millisecond * 300 algo.SetDigestWaitTime(shortenedWaitTime / 2) algo.SetRequestWaitTime(shortenedWaitTime) diff --git a/gossip/gossip/channel/channel_test.go b/gossip/gossip/channel/channel_test.go index 22c7dacf3b9..756855e2f46 100644 --- a/gossip/gossip/channel/channel_test.go +++ b/gossip/gossip/channel/channel_test.go @@ -31,6 +31,7 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/discovery" "github.com/hyperledger/fabric/gossip/gossip/algo" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" @@ -50,6 +51,7 @@ var conf = Config{ } func init() { + util.SetupTestLogging() shortenedWaitTime := time.Millisecond * 300 algo.SetDigestWaitTime(shortenedWaitTime / 2) algo.SetRequestWaitTime(shortenedWaitTime) diff --git a/gossip/gossip/chanstate.go b/gossip/gossip/chanstate.go index 49d6c3bfd11..4e602e395d4 100644 --- a/gossip/gossip/chanstate.go +++ b/gossip/gossip/chanstate.go @@ -26,6 +26,7 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/discovery" "github.com/hyperledger/fabric/gossip/gossip/channel" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" ) @@ -36,6 +37,10 @@ type channelState struct { g *gossipServiceImpl } +func init() { + util.SetupTestLogging() +} + func (cs *channelState) stop() { if cs.isStopping() { return diff --git a/gossip/gossip/gossip_test.go b/gossip/gossip/gossip_test.go index 4b546286e36..8e2724cee6a 100644 --- a/gossip/gossip/gossip_test.go +++ b/gossip/gossip/gossip_test.go @@ -46,6 +46,7 @@ var timeout = time.Second * time.Duration(180) var testWG = sync.WaitGroup{} func init() { + util.SetupTestLogging() rand.Seed(int64(time.Now().Second())) aliveTimeInterval := time.Duration(1000) * time.Millisecond discovery.SetAliveTimeInterval(aliveTimeInterval) diff --git a/gossip/gossip/msgstore/msgs_test.go b/gossip/gossip/msgstore/msgs_test.go index 73da2d597db..81ccb259260 100644 --- a/gossip/gossip/msgstore/msgs_test.go +++ b/gossip/gossip/msgstore/msgs_test.go @@ -25,10 +25,12 @@ import ( "sync" "github.com/hyperledger/fabric/gossip/common" + "github.com/hyperledger/fabric/gossip/util" "github.com/stretchr/testify/assert" ) func init() { + util.SetupTestLogging() rand.Seed(time.Now().UnixNano()) } diff --git a/gossip/gossip/orgs_test.go b/gossip/gossip/orgs_test.go index ecc4005b9a3..3b8600e6ecf 100644 --- a/gossip/gossip/orgs_test.go +++ b/gossip/gossip/orgs_test.go @@ -29,11 +29,13 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/discovery" "github.com/hyperledger/fabric/gossip/identity" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/stretchr/testify/assert" ) func init() { + util.SetupTestLogging() aliveTimeInterval := time.Duration(1000) * time.Millisecond discovery.SetAliveTimeInterval(aliveTimeInterval) discovery.SetAliveExpirationCheckInterval(aliveTimeInterval) diff --git a/gossip/gossip/pull/pullstore_test.go b/gossip/gossip/pull/pullstore_test.go index 4fffec0812f..e73de990dff 100644 --- a/gossip/gossip/pull/pullstore_test.go +++ b/gossip/gossip/pull/pullstore_test.go @@ -35,6 +35,7 @@ var pullInterval time.Duration var timeoutInterval = 20 * time.Second func init() { + util.SetupTestLogging() pullInterval = time.Duration(500) * time.Millisecond algo.SetDigestWaitTime(pullInterval / 5) algo.SetRequestWaitTime(pullInterval) diff --git a/gossip/identity/identity_test.go b/gossip/identity/identity_test.go index e918a9620c5..1bf144b7430 100644 --- a/gossip/identity/identity_test.go +++ b/gossip/identity/identity_test.go @@ -24,6 +24,7 @@ import ( "github.com/hyperledger/fabric/gossip/api" "github.com/hyperledger/fabric/gossip/common" + "github.com/hyperledger/fabric/gossip/util" "github.com/stretchr/testify/assert" ) @@ -33,6 +34,10 @@ type naiveCryptoService struct { revokedIdentities map[string]struct{} } +func init() { + util.SetupTestLogging() +} + func (cs *naiveCryptoService) ValidateIdentity(peerIdentity api.PeerIdentityType) error { if _, isRevoked := cs.revokedIdentities[string(cs.GetPKIidOfCert(peerIdentity))]; isRevoked { return errors.New("revoked") diff --git a/gossip/integration/integration_test.go b/gossip/integration/integration_test.go index 8c0f550cce9..029070aecb9 100644 --- a/gossip/integration/integration_test.go +++ b/gossip/integration/integration_test.go @@ -27,12 +27,17 @@ import ( "github.com/hyperledger/fabric/gossip/api" "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/identity" + "github.com/hyperledger/fabric/gossip/util" "github.com/hyperledger/fabric/msp/mgmt" "github.com/hyperledger/fabric/msp/mgmt/testtools" "github.com/spf13/viper" "google.golang.org/grpc" ) +func init() { + util.SetupTestLogging() +} + // This is just a test that shows how to instantiate a gossip component func TestNewGossipCryptoService(t *testing.T) { setupTestEnv() diff --git a/gossip/service/eventer_test.go b/gossip/service/eventer_test.go index 2791b3aef96..7e06fb82bd1 100644 --- a/gossip/service/eventer_test.go +++ b/gossip/service/eventer_test.go @@ -21,6 +21,7 @@ import ( "testing" "github.com/hyperledger/fabric/common/config" + "github.com/hyperledger/fabric/gossip/util" "github.com/hyperledger/fabric/protos/peer" ) @@ -28,6 +29,10 @@ const testChainID = "foo" type applicationOrgs []*peer.AnchorPeer +func init() { + util.SetupTestLogging() +} + func (ao applicationOrgs) AnchorPeers() []*peer.AnchorPeer { return ao } diff --git a/gossip/service/gossip_service.go b/gossip/service/gossip_service.go index 83207342796..6394c975d69 100644 --- a/gossip/service/gossip_service.go +++ b/gossip/service/gossip_service.go @@ -122,6 +122,10 @@ var logger = util.GetLogger(util.LoggingServiceModule, "") // InitGossipService initialize gossip service func InitGossipService(peerIdentity []byte, endpoint string, s *grpc.Server, mcs api.MessageCryptoService, bootPeers ...string) { + // TODO: Remove this. + // TODO: This is a temporary work-around to make the gossip leader election module load its logger at startup + // TODO: in order for the flogging package to register this logger in time so it can set the log levels as requested in the config + util.GetLogger(util.LoggingElectionModule, "") InitGossipServiceCustomDeliveryFactory(peerIdentity, endpoint, s, &deliveryFactoryImpl{}, mcs, bootPeers...) } diff --git a/gossip/service/gossip_service_test.go b/gossip/service/gossip_service_test.go index f2251f18559..dbf2bd4148c 100644 --- a/gossip/service/gossip_service_test.go +++ b/gossip/service/gossip_service_test.go @@ -44,6 +44,10 @@ import ( "google.golang.org/grpc" ) +func init() { + util.SetupTestLogging() +} + func TestInitGossipService(t *testing.T) { // Test whenever gossip service is indeed singleton grpcServer := grpc.NewServer() diff --git a/gossip/service/join_test.go b/gossip/service/join_test.go index 73940f9e48d..79900930aa0 100644 --- a/gossip/service/join_test.go +++ b/gossip/service/join_test.go @@ -25,6 +25,7 @@ import ( "github.com/hyperledger/fabric/gossip/comm" "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/discovery" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/hyperledger/fabric/protos/peer" "github.com/stretchr/testify/assert" @@ -34,6 +35,10 @@ import ( type secAdvMock struct { } +func init() { + util.SetupTestLogging() +} + func (s *secAdvMock) OrgByPeerIdentity(identity api.PeerIdentityType) api.OrgIdentityType { return api.OrgIdentityType(identity) } diff --git a/gossip/state/metastate_test.go b/gossip/state/metastate_test.go index de41ba125d3..232248d693c 100644 --- a/gossip/state/metastate_test.go +++ b/gossip/state/metastate_test.go @@ -20,8 +20,13 @@ import ( "testing" "github.com/docker/docker/pkg/testutil/assert" + "github.com/hyperledger/fabric/gossip/util" ) +func init() { + util.SetupTestLogging() +} + func TestNewNodeMetastate(t *testing.T) { metastate := NewNodeMetastate(0) assert.Equal(t, metastate.Height(), uint64(0)) diff --git a/gossip/state/payloads_buffer_test.go b/gossip/state/payloads_buffer_test.go index 1c21460cb2b..cb648694bf2 100644 --- a/gossip/state/payloads_buffer_test.go +++ b/gossip/state/payloads_buffer_test.go @@ -24,10 +24,15 @@ import ( "testing" "time" + "github.com/hyperledger/fabric/gossip/util" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/stretchr/testify/assert" ) +func init() { + util.SetupTestLogging() +} + func uuid() (string, error) { uuid := make([]byte, 16) _, err := rand.Read(uuid) diff --git a/gossip/state/state_test.go b/gossip/state/state_test.go index ee00245173f..d28987761af 100644 --- a/gossip/state/state_test.go +++ b/gossip/state/state_test.go @@ -36,6 +36,7 @@ import ( "github.com/hyperledger/fabric/gossip/common" "github.com/hyperledger/fabric/gossip/gossip" "github.com/hyperledger/fabric/gossip/identity" + gutil "github.com/hyperledger/fabric/gossip/util" pcomm "github.com/hyperledger/fabric/protos/common" proto "github.com/hyperledger/fabric/protos/gossip" "github.com/spf13/viper" @@ -57,6 +58,10 @@ var noopPeerIdentityAcceptor = func(identity api.PeerIdentityType) error { type joinChanMsg struct { } +func init() { + gutil.SetupTestLogging() +} + // SequenceNumber returns the sequence number of the block that the message // is derived from func (*joinChanMsg) SequenceNumber() uint64 { diff --git a/gossip/util/logging.go b/gossip/util/logging.go index 70cbbc349f0..543a29ea57d 100644 --- a/gossip/util/logging.go +++ b/gossip/util/logging.go @@ -41,7 +41,9 @@ const ( var loggersByModules = make(map[string]*logging.Logger) var lock = sync.Mutex{} -var logger = flogging.MustGetLogger("gossip/util") + +// defaultTestSpec is the default logging level for gossip tests +var defaultTestSpec = "WARNING" func init() { grpclog.SetLogger(log.New(ioutil.Discard, "", 0)) @@ -65,3 +67,8 @@ func GetLogger(module string, peerID string) *logging.Logger { loggersByModules[module] = lgr return lgr } + +// SetupTestLogging sets the default log levels for gossip unit tests +func SetupTestLogging() { + flogging.InitFromSpec(defaultTestSpec) +} diff --git a/gossip/util/msgs_test.go b/gossip/util/msgs_test.go index 01e2098897c..73d9cc67cae 100644 --- a/gossip/util/msgs_test.go +++ b/gossip/util/msgs_test.go @@ -24,6 +24,10 @@ import ( "github.com/stretchr/testify/assert" ) +func init() { + SetupTestLogging() +} + func TestMembershipStore(t *testing.T) { membershipStore := NewMembershipStore() diff --git a/peer/node/start.go b/peer/node/start.go index 17f42c74285..0883133b738 100644 --- a/peer/node/start.go +++ b/peer/node/start.go @@ -264,19 +264,13 @@ func serve(args []string) error { logger.Infof("Started peer with ID=[%s], network ID=[%s], address=[%s]", peerEndpoint.Id, viper.GetString("peer.networkId"), peerEndpoint.Address) - // if CORE_LOGGING_LEVEL environment variable is not set, set the logging - // level for specific modules defined in core.yaml. - // TODO Add calls to set 'gossip' and 'ledger' once all other packages - // switch to `flogging.MustGetLogger` (from `logging.MustGetLogger`) as those - // modules need the regular expression capabilities enabled by the `flogging` - // package - if viper.GetString("logging_level") == "" { - overrideLogModules := []string{"msp"} - for _, module := range overrideLogModules { - err = common.SetLogLevelFromViper(module) - if err != nil { - logger.Warningf("Error setting log level for module '%s': %s", module, err.Error()) - } + // set the logging level for specific modules defined in core.yaml. + // TODO Add calls to set 'ledger' module loggers + overrideLogModules := []string{"msp", "gossip"} + for _, module := range overrideLogModules { + err = common.SetLogLevelFromViper(module) + if err != nil { + logger.Warningf("Error setting log level for module '%s': %s", module, err.Error()) } } diff --git a/sampleconfig/core.yaml b/sampleconfig/core.yaml index 3593340907a..46ad1bbd289 100644 --- a/sampleconfig/core.yaml +++ b/sampleconfig/core.yaml @@ -26,7 +26,7 @@ logging: peer: info # Override levels for various 'peer' modules - gossip: info + gossip: warning ledger: info msp: warning