From 37ef5485b43e22eb2fdfa4b935308ca718affdfc Mon Sep 17 00:00:00 2001 From: Jae Kwon Date: Tue, 26 Jun 2018 16:52:38 -0700 Subject: [PATCH] Add logs to lite/*; Fix rpc status to return consensus height, not blockstore height --- .gitignore | 1 + cmd/tendermint/commands/lite.go | 13 +++++---- consensus/state.go | 9 +++++++ lite/client/provider.go | 24 +++++++++++------ lite/dbprovider.go | 45 +++++++++++++++++++++++++++----- lite/doc.go | 5 ++-- lite/inquiring_certifier.go | 19 +++++++++----- lite/inquiring_certifier_test.go | 17 ++++++------ lite/multiprovider.go | 31 +++++++++++++++------- lite/provider.go | 4 +++ lite/provider_test.go | 10 ++++--- lite/proxy/certifier.go | 26 +++++++++++------- lite/proxy/wrapper.go | 28 +++++++++++++++----- rpc/core/pipe.go | 3 ++- rpc/core/status.go | 7 ++++- 15 files changed, 174 insertions(+), 68 deletions(-) diff --git a/.gitignore b/.gitignore index bcfd36db1..269066e39 100644 --- a/.gitignore +++ b/.gitignore @@ -27,3 +27,4 @@ scripts/cutWALUntil/cutWALUntil libs/pubsub/query/fuzz_test/output shunit2 +.tendermint-lite diff --git a/cmd/tendermint/commands/lite.go b/cmd/tendermint/commands/lite.go index 53b3ec182..5fe99d363 100644 --- a/cmd/tendermint/commands/lite.go +++ b/cmd/tendermint/commands/lite.go @@ -6,10 +6,9 @@ import ( "github.com/spf13/cobra" - cmn "github.com/tendermint/tmlibs/common" - "github.com/tendermint/tendermint/lite/proxy" rpcclient "github.com/tendermint/tendermint/rpc/client" + cmn "github.com/tendermint/tmlibs/common" ) // LiteCmd represents the base command when called without any subcommands @@ -66,17 +65,21 @@ func runProxy(cmd *cobra.Command, args []string) error { } // First, connect a client + logger.Info("Connecting to source HTTP client...") node := rpcclient.NewHTTP(nodeAddr, "/websocket") - cert, err := proxy.GetCertifier(chainID, home, node) + logger.Info("Constructing certifier...") + cert, err := proxy.NewCertifier(chainID, home, node, logger) if err != nil { - return err + return cmn.ErrorWrap(err, "constructing certifier") } + cert.SetLogger(logger) sc := proxy.SecureClient(node, cert) + logger.Info("Starting proxy...") err = proxy.StartProxy(sc, listenAddr, logger) if err != nil { - return err + return cmn.ErrorWrap(err, "starting proxy") } cmn.TrapSignal(func() { diff --git a/consensus/state.go b/consensus/state.go index 93e1f6b49..7c18d8b09 100644 --- a/consensus/state.go +++ b/consensus/state.go @@ -196,6 +196,15 @@ func (cs *ConsensusState) GetState() sm.State { return cs.state.Copy() } +// GetLastHeight returns the last height committed. +// If there were no blocks, returns 0. +func (cs *ConsensusState) GetLastHeight() int64 { + cs.mtx.Lock() + defer cs.mtx.Unlock() + + return cs.RoundState.Height - 1 +} + // GetRoundState returns a shallow copy of the internal consensus state. func (cs *ConsensusState) GetRoundState() *cstypes.RoundState { cs.mtx.Lock() diff --git a/lite/client/provider.go b/lite/client/provider.go index 8175c5b55..3ef15344a 100644 --- a/lite/client/provider.go +++ b/lite/client/provider.go @@ -8,12 +8,12 @@ package client import ( "fmt" + "github.com/tendermint/tendermint/lite" + lerr "github.com/tendermint/tendermint/lite/errors" rpcclient "github.com/tendermint/tendermint/rpc/client" ctypes "github.com/tendermint/tendermint/rpc/core/types" "github.com/tendermint/tendermint/types" - - "github.com/tendermint/tendermint/lite" - lerr "github.com/tendermint/tendermint/lite/errors" + log "github.com/tendermint/tmlibs/log" ) // SignStatusClient combines a SignClient and StatusClient. @@ -23,22 +23,30 @@ type SignStatusClient interface { } type provider struct { + logger log.Logger chainID string client SignStatusClient } // NewProvider implements Provider (but not PersistentProvider). func NewProvider(chainID string, client SignStatusClient) lite.Provider { - return &provider{chainID: chainID, client: client} + return &provider{ + logger: log.NewNopLogger(), + chainID: chainID, + client: client, + } } // NewHTTPProvider can connect to a tendermint json-rpc endpoint // at the given url, and uses that as a read-only provider. func NewHTTPProvider(chainID, remote string) lite.Provider { - return &provider{ - chainID: chainID, - client: rpcclient.NewHTTP(remote, "/websocket"), - } + return NewProvider(chainID, rpcclient.NewHTTP(remote, "/websocket")) +} + +// Implements Provider. +func (p *provider) SetLogger(logger log.Logger) { + logger = logger.With("module", "lite/client") + p.logger = logger } // StatusClient returns the internal client as a StatusClient diff --git a/lite/dbprovider.go b/lite/dbprovider.go index 81710c9e2..f39f033c3 100644 --- a/lite/dbprovider.go +++ b/lite/dbprovider.go @@ -10,23 +10,34 @@ import ( lerr "github.com/tendermint/tendermint/lite/errors" "github.com/tendermint/tendermint/types" dbm "github.com/tendermint/tmlibs/db" + log "github.com/tendermint/tmlibs/log" ) type DBProvider struct { - chainID string - db dbm.DB - cdc *amino.Codec - limit int + logger log.Logger + label string + db dbm.DB + cdc *amino.Codec + limit int } -func NewDBProvider(db dbm.DB) *DBProvider { +func NewDBProvider(label string, db dbm.DB) *DBProvider { //db = dbm.NewDebugDB("db provider "+cmn.RandStr(4), db) cdc := amino.NewCodec() crypto.RegisterAmino(cdc) - dbp := &DBProvider{db: db, cdc: cdc} + dbp := &DBProvider{ + logger: log.NewNopLogger(), + label: label, + db: db, + cdc: cdc, + } return dbp } +func (dbp *DBProvider) SetLogger(logger log.Logger) { + dbp.logger = logger.With("label", dbp.label) +} + func (dbp *DBProvider) SetLimit(limit int) *DBProvider { dbp.limit = limit return dbp @@ -35,6 +46,7 @@ func (dbp *DBProvider) SetLimit(limit int) *DBProvider { // Implements PersistentProvider. func (dbp *DBProvider) SaveFullCommit(fc FullCommit) error { + dbp.logger.Info("DBProvider.SaveFullCommit()...", "fc", fc) batch := dbp.db.NewBatch() // Save the fc.validators. @@ -79,6 +91,9 @@ func (dbp *DBProvider) SaveFullCommit(fc FullCommit) error { func (dbp *DBProvider) LatestFullCommit(chainID string, minHeight, maxHeight int64) ( FullCommit, error) { + dbp.logger.Info("DBProvider.LatestFullCommit()...", + "chainID", chainID, "minHeight", minHeight, "maxHeight", maxHeight) + if minHeight <= 0 { minHeight = 1 } @@ -107,7 +122,15 @@ func (dbp *DBProvider) LatestFullCommit(chainID string, minHeight, maxHeight int if err != nil { return FullCommit{}, err } else { - return dbp.fillFullCommit(sh) + lfc, err := dbp.fillFullCommit(sh) + if err == nil { + dbp.logger.Info("DBProvider.LatestFullCommit() found latest.", "height", lfc.Height()) + return lfc, nil + } else { + dbp.logger.Info("DBProvider.LatestFullCommit() got error", "lfc", lfc) + dbp.logger.Info(fmt.Sprintf("%+v", err)) + return lfc, err + } } } } @@ -155,6 +178,9 @@ func (dbp *DBProvider) fillFullCommit(sh types.SignedHeader) (FullCommit, error) } func (dbp *DBProvider) deleteAfterN(chainID string, after int) error { + + dbp.logger.Info("DBProvider.deleteAfterN()...", "chainID", chainID, "after", after) + itr := dbp.db.ReverseIterator( signedHeaderKey(chainID, 1<<63-1), signedHeaderKey(chainID, 0), @@ -163,6 +189,7 @@ func (dbp *DBProvider) deleteAfterN(chainID string, after int) error { var lastHeight int64 = 1<<63 - 1 var numSeen = 0 + var numDeleted = 0 for itr.Valid() { key := itr.Key() @@ -176,9 +203,13 @@ func (dbp *DBProvider) deleteAfterN(chainID string, after int) error { } if numSeen > after { dbp.db.Delete(key) + numDeleted += 1 } } + itr.Next() } + + dbp.logger.Info(fmt.Sprintf("DBProvider.deleteAfterN() deleted %v items\n", numDeleted)) return nil } diff --git a/lite/doc.go b/lite/doc.go index 881880f66..07977ebe7 100644 --- a/lite/doc.go +++ b/lite/doc.go @@ -92,8 +92,9 @@ type PersistentProvider interface { * MultiProvider - combine multiple providers. The suggested use for local light clients is client.NewHTTPProvider(...) for -getting new data (Source), and NewMultiProvider(NewDBProvider(dbm.NewMemDB()), -NewDBProvider(db.NewFileDB(...))) to store confirmed full commits (Trusted) +getting new data (Source), and NewMultiProvider(NewDBProvider("label", +dbm.NewMemDB()), NewDBProvider("label", db.NewFileDB(...))) to store confirmed +full commits (Trusted) # How We Track Validators diff --git a/lite/inquiring_certifier.go b/lite/inquiring_certifier.go index c4c6173b8..f030ec574 100644 --- a/lite/inquiring_certifier.go +++ b/lite/inquiring_certifier.go @@ -3,9 +3,9 @@ package lite import ( "bytes" - "github.com/tendermint/tendermint/types" - lerr "github.com/tendermint/tendermint/lite/errors" + "github.com/tendermint/tendermint/types" + log "github.com/tendermint/tmlibs/log" ) var _ Certifier = (*InquiringCertifier)(nil) @@ -15,6 +15,7 @@ var _ Certifier = (*InquiringCertifier)(nil) // validator set changes. It stores properly validated data on the // "trusted" local system. type InquiringCertifier struct { + logger log.Logger chainID string // These are only properly validated data, from local system. trusted PersistentProvider @@ -28,14 +29,20 @@ type InquiringCertifier struct { // // The trusted provider should a CacheProvider, MemProvider or // files.Provider. The source provider should be a client.HTTPProvider. -func NewInquiringCertifier(chainID string, trusted PersistentProvider, source Provider) ( - *InquiringCertifier, error) { - +func NewInquiringCertifier(chainID string, trusted PersistentProvider, source Provider) *InquiringCertifier { return &InquiringCertifier{ + logger: log.NewNopLogger(), chainID: chainID, trusted: trusted, source: source, - }, nil + } +} + +func (ic *InquiringCertifier) SetLogger(logger log.Logger) { + logger = logger.With("module", "lite") + ic.logger = logger + ic.trusted.SetLogger(logger) + ic.source.SetLogger(logger) } // Implements Certifier. diff --git a/lite/inquiring_certifier_test.go b/lite/inquiring_certifier_test.go index 8da5a7c1e..23cb54885 100644 --- a/lite/inquiring_certifier_test.go +++ b/lite/inquiring_certifier_test.go @@ -8,12 +8,13 @@ import ( "github.com/stretchr/testify/require" dbm "github.com/tendermint/tmlibs/db" + log "github.com/tendermint/tmlibs/log" ) func TestInquirerValidPath(t *testing.T) { assert, require := assert.New(t), require.New(t) - trust := NewDBProvider(dbm.NewMemDB()) - source := NewDBProvider(dbm.NewMemDB()) + trust := NewDBProvider("trust", dbm.NewMemDB()) + source := NewDBProvider("source", dbm.NewMemDB()) // Set up the validators to generate test blocks. var vote int64 = 10 @@ -43,8 +44,8 @@ func TestInquirerValidPath(t *testing.T) { // Initialize a certifier with the initial state. err := trust.SaveFullCommit(fcz[0]) require.Nil(err) - cert, err := NewInquiringCertifier(chainID, trust, source) - require.Nil(err) + cert := NewInquiringCertifier(chainID, trust, source) + cert.SetLogger(log.TestingLogger()) // This should fail validation: sh := fcz[count-1].SignedHeader @@ -70,8 +71,8 @@ func TestInquirerValidPath(t *testing.T) { func TestInquirerVerifyHistorical(t *testing.T) { assert, require := assert.New(t), require.New(t) - trust := NewDBProvider(dbm.NewMemDB()) - source := NewDBProvider(dbm.NewMemDB()) + trust := NewDBProvider("trust", dbm.NewMemDB()) + source := NewDBProvider("source", dbm.NewMemDB()) // Set up the validators to generate test blocks. var vote int64 = 10 @@ -101,8 +102,8 @@ func TestInquirerVerifyHistorical(t *testing.T) { // Initialize a certifier with the initial state. err := trust.SaveFullCommit(fcz[0]) require.Nil(err) - cert, err := NewInquiringCertifier(chainID, trust, source) - require.Nil(err) + cert := NewInquiringCertifier(chainID, trust, source) + cert.SetLogger(log.TestingLogger()) // Store a few full commits as trust. for _, i := range []int{2, 5} { diff --git a/lite/multiprovider.go b/lite/multiprovider.go index dcfd1318c..8ff523b4f 100644 --- a/lite/multiprovider.go +++ b/lite/multiprovider.go @@ -3,24 +3,35 @@ package lite import ( lerr "github.com/tendermint/tendermint/lite/errors" "github.com/tendermint/tendermint/types" + log "github.com/tendermint/tmlibs/log" ) // multiProvider allows you to place one or more caches in front of a source // Provider. It runs through them in order until a match is found. type multiProvider struct { - Providers []PersistentProvider + logger log.Logger + providers []PersistentProvider } // NewMultiProvider returns a new provider which wraps multiple other providers. -func NewMultiProvider(providers ...PersistentProvider) multiProvider { - return multiProvider{ - Providers: providers, +func NewMultiProvider(providers ...PersistentProvider) *multiProvider { + return &multiProvider{ + logger: log.NewNopLogger(), + providers: providers, + } +} + +// SetLogger sets logger on self and all subproviders. +func (mc *multiProvider) SetLogger(logger log.Logger) { + mc.logger = logger + for _, p := range mc.providers { + p.SetLogger(logger) } } // SaveFullCommit saves on all providers, and aborts on the first error. -func (mc multiProvider) SaveFullCommit(fc FullCommit) (err error) { - for _, p := range mc.Providers { +func (mc *multiProvider) SaveFullCommit(fc FullCommit) (err error) { + for _, p := range mc.providers { err = p.SaveFullCommit(fc) if err != nil { return @@ -32,8 +43,8 @@ func (mc multiProvider) SaveFullCommit(fc FullCommit) (err error) { // LatestFullCommit loads the latest from all providers and provides // the latest FullCommit that satisfies the conditions. // Returns the first error encountered. -func (mc multiProvider) LatestFullCommit(chainID string, minHeight, maxHeight int64) (fc FullCommit, err error) { - for _, p := range mc.Providers { +func (mc *multiProvider) LatestFullCommit(chainID string, minHeight, maxHeight int64) (fc FullCommit, err error) { + for _, p := range mc.providers { var fc_ FullCommit fc_, err = p.LatestFullCommit(chainID, minHeight, maxHeight) if lerr.IsErrCommitNotFound(err) { @@ -60,8 +71,8 @@ func (mc multiProvider) LatestFullCommit(chainID string, minHeight, maxHeight in // ValidatorSet returns validator set at height as provided by the first // provider which has it, or an error otherwise. -func (mc multiProvider) ValidatorSet(chainID string, height int64) (valset *types.ValidatorSet, err error) { - for _, p := range mc.Providers { +func (mc *multiProvider) ValidatorSet(chainID string, height int64) (valset *types.ValidatorSet, err error) { + for _, p := range mc.providers { valset, err = p.ValidatorSet(chainID, height) if err == nil { // TODO Log unexpected types of errors. diff --git a/lite/provider.go b/lite/provider.go index 34ba40d44..c31b2da43 100644 --- a/lite/provider.go +++ b/lite/provider.go @@ -2,6 +2,7 @@ package lite import ( "github.com/tendermint/tendermint/types" + log "github.com/tendermint/tmlibs/log" ) // Provider provides information for the lite client to sync validators. @@ -16,6 +17,9 @@ type Provider interface { // Get the valset that corresponds to chainID and height and return. // Height must be >= 1. ValidatorSet(chainID string, height int64) (*types.ValidatorSet, error) + + // Set a logger. + SetLogger(logger log.Logger) } // A provider that can also persist new information. diff --git a/lite/provider_test.go b/lite/provider_test.go index 96523d943..09e8119b6 100644 --- a/lite/provider_test.go +++ b/lite/provider_test.go @@ -10,6 +10,7 @@ import ( lerr "github.com/tendermint/tendermint/lite/errors" "github.com/tendermint/tendermint/types" dbm "github.com/tendermint/tmlibs/db" + log "github.com/tendermint/tmlibs/log" ) // missingProvider doesn't store anything, always a miss. @@ -28,16 +29,17 @@ func (missingProvider) LatestFullCommit(chainID string, minHeight, maxHeight int func (missingProvider) ValidatorSet(chainID string, height int64) (*types.ValidatorSet, error) { return nil, errors.New("missing validator set") } +func (missingProvider) SetLogger(_ log.Logger) {} func TestMemProvider(t *testing.T) { - p := NewDBProvider(dbm.NewMemDB()) + p := NewDBProvider("mem", dbm.NewMemDB()) checkProvider(t, p, "test-mem", "empty") } func TestMultiProvider(t *testing.T) { p := NewMultiProvider( NewMissingProvider(), - NewDBProvider(dbm.NewMemDB()), + NewDBProvider("mem", dbm.NewMemDB()), NewMissingProvider(), ) checkProvider(t, p, "test-cache", "kjfhekfhkewhgit") @@ -105,8 +107,8 @@ func TestMultiLatestFullCommit(t *testing.T) { // We will write data to the second level of the cache (p2), and see what // gets cached/stored in. - p := NewDBProvider(dbm.NewMemDB()) - p2 := NewDBProvider(dbm.NewMemDB()) + p := NewDBProvider("mem1", dbm.NewMemDB()) + p2 := NewDBProvider("mem2", dbm.NewMemDB()) cp := NewMultiProvider(p, p2) chainID := "cache-best-height" diff --git a/lite/proxy/certifier.go b/lite/proxy/certifier.go index 772af58f5..a1ab02c59 100644 --- a/lite/proxy/certifier.go +++ b/lite/proxy/certifier.go @@ -3,33 +3,39 @@ package proxy import ( "github.com/tendermint/tendermint/lite" lclient "github.com/tendermint/tendermint/lite/client" + cmn "github.com/tendermint/tmlibs/common" dbm "github.com/tendermint/tmlibs/db" + log "github.com/tendermint/tmlibs/log" ) -func GetCertifier(chainID, rootDir string, client lclient.SignStatusClient) (*lite.InquiringCertifier, error) { +func NewCertifier(chainID, rootDir string, client lclient.SignStatusClient, logger log.Logger) (*lite.InquiringCertifier, error) { + + logger = logger.With("module", "lite/proxy") + logger.Info("lite/proxy/NewCertifier()...", "chainID", chainID, "rootDir", rootDir, "client", client) + + memProvider := lite.NewDBProvider("trusted.mem", dbm.NewMemDB()).SetLimit(10) + lvlProvider := lite.NewDBProvider("trusted.lvl", dbm.NewDB("trust-base", dbm.LevelDBBackend, rootDir)) trust := lite.NewMultiProvider( - lite.NewDBProvider(dbm.NewMemDB()).SetLimit(10), - lite.NewDBProvider(dbm.NewDB("trust-base", dbm.LevelDBBackend, rootDir)), + memProvider, + lvlProvider, ) source := lclient.NewProvider(chainID, client) + cert := lite.NewInquiringCertifier(chainID, trust, source) + cert.SetLogger(logger) // Sets logger recursively. // TODO: Make this more secure, e.g. make it interactive in the console? _, err := trust.LatestFullCommit(chainID, 1, 1<<63-1) if err != nil { + logger.Info("lite/proxy/NewCertifier found no trusted full commit, initializing from source from height 1...") fc, err := source.LatestFullCommit(chainID, 1, 1) if err != nil { - return nil, err + return nil, cmn.ErrorWrap(err, "fetching source full commit @ height 1") } err = trust.SaveFullCommit(fc) if err != nil { - return nil, err + return nil, cmn.ErrorWrap(err, "saving full commit to trusted") } } - cert, err := lite.NewInquiringCertifier(chainID, trust, source) - if err != nil { - return nil, err - } - return cert, nil } diff --git a/lite/proxy/wrapper.go b/lite/proxy/wrapper.go index 83fc96a15..82b1fb092 100644 --- a/lite/proxy/wrapper.go +++ b/lite/proxy/wrapper.go @@ -89,33 +89,49 @@ func (w Wrapper) BlockchainInfo(minHeight, maxHeight int64) (*ctypes.ResultBlock // Block returns an entire block and verifies all signatures func (w Wrapper) Block(height *int64) (*ctypes.ResultBlock, error) { - r, err := w.Client.Block(height) + resBlock, err := w.Client.Block(height) if err != nil { return nil, err } // get a checkpoint to verify from - res, err := w.Commit(height) + resCommit, err := w.Commit(height) if err != nil { return nil, err } - sh := res.SignedHeader + sh := resCommit.SignedHeader // now verify - err = ValidateBlockMeta(r.BlockMeta, sh) + err = ValidateBlockMeta(resBlock.BlockMeta, sh) if err != nil { return nil, err } - err = ValidateBlock(r.Block, sh) + err = ValidateBlock(resBlock.Block, sh) if err != nil { return nil, err } - return r, nil + return resBlock, nil } // Commit downloads the Commit and certifies it with the lite. // // This is the foundation for all other verification in this module func (w Wrapper) Commit(height *int64) (*ctypes.ResultCommit, error) { + if height == nil { + resStatus, err := w.Client.Status() + if err != nil { + return nil, err + } + // NOTE: If resStatus.CatchingUp, there is a race + // condition where the validator set for the next height + // isn't available until some time after the blockstore + // has height h on the remote node. This isn't an issue + // once the node has caught up, and a syncing node likely + // won't have this issue esp with the implementation we + // have here, but we may have to address this at some + // point. + height = new(int64) + *height = resStatus.SyncInfo.LatestBlockHeight + } rpcclient.WaitForHeight(w.Client, *height, nil) res, err := w.Client.Commit(height) // if we got it, then certify it diff --git a/rpc/core/pipe.go b/rpc/core/pipe.go index 9fcb75e19..52fe1b551 100644 --- a/rpc/core/pipe.go +++ b/rpc/core/pipe.go @@ -3,8 +3,8 @@ package core import ( "time" - crypto "github.com/tendermint/tendermint/crypto" "github.com/tendermint/tendermint/consensus" + crypto "github.com/tendermint/tendermint/crypto" "github.com/tendermint/tendermint/p2p" "github.com/tendermint/tendermint/proxy" sm "github.com/tendermint/tendermint/state" @@ -28,6 +28,7 @@ var subscribeTimeout = 5 * time.Second type Consensus interface { GetState() sm.State GetValidators() (int64, []*types.Validator) + GetLastHeight() int64 GetRoundStateJSON() ([]byte, error) GetRoundStateSimpleJSON() ([]byte, error) } diff --git a/rpc/core/status.go b/rpc/core/status.go index 5738685b6..00a14c54c 100644 --- a/rpc/core/status.go +++ b/rpc/core/status.go @@ -64,7 +64,12 @@ import ( //} // ``` func Status() (*ctypes.ResultStatus, error) { - latestHeight := blockStore.Height() + var latestHeight int64 = -1 + if consensusReactor.FastSync() { + latestHeight = blockStore.Height() + } else { + latestHeight = consensusState.GetLastHeight() + } var ( latestBlockMeta *types.BlockMeta latestBlockHash cmn.HexBytes