fluencelabs/tendermint
1
0
Fork 0
mirror of https://github.com/fluencelabs/tendermint synced 2025-06-18 15:41:20 +00:00
Code Issues Projects Releases Wiki Activity

info->notice, debug->info

Browse Source
This commit is contained in:
Ethan Buchman
2015-07-19 21:49:13 +00:00
parent e087284a4f
commit bb4ca1407f
26 changed files with 239 additions and 239 deletions
Download Patch File Download Diff File Expand all files Collapse all files

58
binary/reflect.go
View File

@ -260,7 +260,7 @@ func readReflectBinary(rv reflect.Value, rt reflect.Type, opts Options, r io.Rea
if *err != nil { if *err != nil {
return return
} }
log.Debug("Read bytearray", "bytes", buf) log.Info("Read bytearray", "bytes", buf)
reflect.Copy(rv, reflect.ValueOf(buf)) reflect.Copy(rv, reflect.ValueOf(buf))
} else { } else {
for i := 0; i < length; i++ { for i := 0; i < length; i++ {
@ -274,7 +274,7 @@ func readReflectBinary(rv reflect.Value, rt reflect.Type, opts Options, r io.Rea
return return
} }
} }
log.Debug(Fmt("Read %v-array", elemRt), "length", length) log.Info(Fmt("Read %v-array", elemRt), "length", length)
} }
case reflect.Slice: case reflect.Slice:
@ -282,13 +282,13 @@ func readReflectBinary(rv reflect.Value, rt reflect.Type, opts Options, r io.Rea
if elemRt.Kind() == reflect.Uint8 { if elemRt.Kind() == reflect.Uint8 {
// Special case: Byteslices // Special case: Byteslices
byteslice := ReadByteSlice(r, n, err) byteslice := ReadByteSlice(r, n, err)
log.Debug("Read byteslice", "bytes", byteslice) log.Info("Read byteslice", "bytes", byteslice)
rv.Set(reflect.ValueOf(byteslice)) rv.Set(reflect.ValueOf(byteslice))
} else { } else {
var sliceRv reflect.Value var sliceRv reflect.Value
// Read length // Read length
length := ReadVarint(r, n, err) length := ReadVarint(r, n, err)
log.Debug(Fmt("Read length: %v", length)) log.Info(Fmt("Read length: %v", length))
sliceRv = reflect.MakeSlice(rt, 0, 0) sliceRv = reflect.MakeSlice(rt, 0, 0)
// read one ReflectSliceChunk at a time and append // read one ReflectSliceChunk at a time and append
for i := 0; i*ReflectSliceChunk < length; i++ { for i := 0; i*ReflectSliceChunk < length; i++ {
@ -315,7 +315,7 @@ func readReflectBinary(rv reflect.Value, rt reflect.Type, opts Options, r io.Rea
if rt == timeType { if rt == timeType {
// Special case: time.Time // Special case: time.Time
t := ReadTime(r, n, err) t := ReadTime(r, n, err)
log.Debug(Fmt("Read time: %v", t)) log.Info(Fmt("Read time: %v", t))
rv.Set(reflect.ValueOf(t)) rv.Set(reflect.ValueOf(t))
} else { } else {
for _, fieldInfo := range typeInfo.Fields { for _, fieldInfo := range typeInfo.Fields {
@ -327,74 +327,74 @@ func readReflectBinary(rv reflect.Value, rt reflect.Type, opts Options, r io.Rea
case reflect.String: case reflect.String:
str := ReadString(r, n, err) str := ReadString(r, n, err)
log.Debug(Fmt("Read string: %v", str)) log.Info(Fmt("Read string: %v", str))
rv.SetString(str) rv.SetString(str)
case reflect.Int64: case reflect.Int64:
if opts.Varint { if opts.Varint {
num := ReadVarint(r, n, err) num := ReadVarint(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
} else { } else {
num := ReadInt64(r, n, err) num := ReadInt64(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
} }
case reflect.Int32: case reflect.Int32:
num := ReadUint32(r, n, err) num := ReadUint32(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
case reflect.Int16: case reflect.Int16:
num := ReadUint16(r, n, err) num := ReadUint16(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
case reflect.Int8: case reflect.Int8:
num := ReadUint8(r, n, err) num := ReadUint8(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
case reflect.Int: case reflect.Int:
num := ReadVarint(r, n, err) num := ReadVarint(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
case reflect.Uint64: case reflect.Uint64:
if opts.Varint { if opts.Varint {
num := ReadVarint(r, n, err) num := ReadVarint(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
} else { } else {
num := ReadUint64(r, n, err) num := ReadUint64(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
} }
case reflect.Uint32: case reflect.Uint32:
num := ReadUint32(r, n, err) num := ReadUint32(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
case reflect.Uint16: case reflect.Uint16:
num := ReadUint16(r, n, err) num := ReadUint16(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
case reflect.Uint8: case reflect.Uint8:
num := ReadUint8(r, n, err) num := ReadUint8(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
case reflect.Uint: case reflect.Uint:
num := ReadVarint(r, n, err) num := ReadVarint(r, n, err)
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
case reflect.Bool: case reflect.Bool:
num := ReadUint8(r, n, err) num := ReadUint8(r, n, err)
log.Debug(Fmt("Read bool: %v", num)) log.Info(Fmt("Read bool: %v", num))
rv.SetBool(num > 0) rv.SetBool(num > 0)
default: default:
@ -669,7 +669,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = errors.New(Fmt("Expected bytearray of length %v but got %v", length, len(buf))) *err = errors.New(Fmt("Expected bytearray of length %v but got %v", length, len(buf)))
return return
} }
log.Debug("Read bytearray", "bytes", buf) log.Info("Read bytearray", "bytes", buf)
reflect.Copy(rv, reflect.ValueOf(buf)) reflect.Copy(rv, reflect.ValueOf(buf))
} else { } else {
oSlice, ok := o.([]interface{}) oSlice, ok := o.([]interface{})
@ -685,7 +685,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
elemRv := rv.Index(i) elemRv := rv.Index(i)
readReflectJSON(elemRv, elemRt, oSlice[i], err) readReflectJSON(elemRv, elemRt, oSlice[i], err)
} }
log.Debug(Fmt("Read %v-array", elemRt), "length", length) log.Info(Fmt("Read %v-array", elemRt), "length", length)
} }
case reflect.Slice: case reflect.Slice:
@ -702,7 +702,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = err_ *err = err_
return return
} }
log.Debug("Read byteslice", "bytes", byteslice) log.Info("Read byteslice", "bytes", byteslice)
rv.Set(reflect.ValueOf(byteslice)) rv.Set(reflect.ValueOf(byteslice))
} else { } else {
// Read length // Read length
@ -712,7 +712,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
return return
} }
length := len(oSlice) length := len(oSlice)
log.Debug(Fmt("Read length: %v", length)) log.Info(Fmt("Read length: %v", length))
sliceRv := reflect.MakeSlice(rt, length, length) sliceRv := reflect.MakeSlice(rt, length, length)
// Read elems // Read elems
for i := 0; i < length; i++ { for i := 0; i < length; i++ {
@ -730,7 +730,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = errors.New(Fmt("Expected string but got type %v", reflect.TypeOf(o))) *err = errors.New(Fmt("Expected string but got type %v", reflect.TypeOf(o)))
return return
} }
log.Debug(Fmt("Read time: %v", str)) log.Info(Fmt("Read time: %v", str))
t, err_ := time.Parse(rfc2822, str) t, err_ := time.Parse(rfc2822, str)
if err_ != nil { if err_ != nil {
*err = err_ *err = err_
@ -762,7 +762,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = errors.New(Fmt("Expected string but got type %v", reflect.TypeOf(o))) *err = errors.New(Fmt("Expected string but got type %v", reflect.TypeOf(o)))
return return
} }
log.Debug(Fmt("Read string: %v", str)) log.Info(Fmt("Read string: %v", str))
rv.SetString(str) rv.SetString(str)
case reflect.Int64, reflect.Int32, reflect.Int16, reflect.Int8, reflect.Int: case reflect.Int64, reflect.Int32, reflect.Int16, reflect.Int8, reflect.Int:
@ -771,7 +771,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = errors.New(Fmt("Expected numeric but got type %v", reflect.TypeOf(o))) *err = errors.New(Fmt("Expected numeric but got type %v", reflect.TypeOf(o)))
return return
} }
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetInt(int64(num)) rv.SetInt(int64(num))
case reflect.Uint64, reflect.Uint32, reflect.Uint16, reflect.Uint8, reflect.Uint: case reflect.Uint64, reflect.Uint32, reflect.Uint16, reflect.Uint8, reflect.Uint:
@ -784,7 +784,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = errors.New(Fmt("Expected unsigned numeric but got %v", num)) *err = errors.New(Fmt("Expected unsigned numeric but got %v", num))
return return
} }
log.Debug(Fmt("Read num: %v", num)) log.Info(Fmt("Read num: %v", num))
rv.SetUint(uint64(num)) rv.SetUint(uint64(num))
case reflect.Bool: case reflect.Bool:
@ -793,7 +793,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
*err = errors.New(Fmt("Expected boolean but got type %v", reflect.TypeOf(o))) *err = errors.New(Fmt("Expected boolean but got type %v", reflect.TypeOf(o)))
return return
} }
log.Debug(Fmt("Read boolean: %v", bl)) log.Info(Fmt("Read boolean: %v", bl))
rv.SetBool(bl) rv.SetBool(bl)
default: default:
@ -803,7 +803,7 @@ func readReflectJSON(rv reflect.Value, rt reflect.Type, o interface{}, err *erro
} }
func writeReflectJSON(rv reflect.Value, rt reflect.Type, w io.Writer, n *int64, err *error) { func writeReflectJSON(rv reflect.Value, rt reflect.Type, w io.Writer, n *int64, err *error) {
log.Debug(Fmt("writeReflectJSON(%v, %v, %v, %v, %v)", rv, rt, w, n, err)) log.Info(Fmt("writeReflectJSON(%v, %v, %v, %v, %v)", rv, rt, w, n, err))
// Get typeInfo // Get typeInfo
typeInfo := GetTypeInfo(rt) typeInfo := GetTypeInfo(rt)

4
binary/reflect_test.go
View File

@ -356,7 +356,7 @@ func TestBinary(t *testing.T) {
for i, testCase := range testCases { for i, testCase := range testCases {
log.Info(fmt.Sprintf("Running test case %v", i)) log.Notice(fmt.Sprintf("Running test case %v", i))
// Construct an object // Construct an object
o := testCase.Constructor() o := testCase.Constructor()
@ -398,7 +398,7 @@ func TestJSON(t *testing.T) {
for i, testCase := range testCases { for i, testCase := range testCases {
log.Info(fmt.Sprintf("Running test case %v", i)) log.Notice(fmt.Sprintf("Running test case %v", i))
// Construct an object // Construct an object
o := testCase.Constructor() o := testCase.Constructor()

8
blockchain/pool.go
View File

@ -71,14 +71,14 @@ func NewBlockPool(start int, requestsCh chan<- BlockRequest, timeoutsCh chan<- s
func (pool *BlockPool) Start() { func (pool *BlockPool) Start() {
if atomic.CompareAndSwapInt32(&pool.running, 0, 1) { if atomic.CompareAndSwapInt32(&pool.running, 0, 1) {
log.Info("Starting BlockPool") log.Notice("Starting BlockPool")
go pool.run() go pool.run()
} }
} }
func (pool *BlockPool) Stop() { func (pool *BlockPool) Stop() {
if atomic.CompareAndSwapInt32(&pool.running, 1, 0) { if atomic.CompareAndSwapInt32(&pool.running, 1, 0) {
log.Info("Stopping BlockPool") log.Notice("Stopping BlockPool")
pool.repeater.Stop() pool.repeater.Stop()
} }
} }
@ -354,12 +354,12 @@ func requestRoutine(pool *BlockPool, height int) {
PICK_LOOP: PICK_LOOP:
for { for {
if !pool.IsRunning() { if !pool.IsRunning() {
log.Debug("BlockPool not running. Stopping requestRoutine", "height", height) log.Info("BlockPool not running. Stopping requestRoutine", "height", height)
return return
} }
peer = pool.pickIncrAvailablePeer(height) peer = pool.pickIncrAvailablePeer(height)
if peer == nil { if peer == nil {
//log.Debug("No peers available", "height", height) //log.Info("No peers available", "height", height)
time.Sleep(requestIntervalMS * time.Millisecond) time.Sleep(requestIntervalMS * time.Millisecond)
continue PICK_LOOP continue PICK_LOOP
} }

8
blockchain/pool_test.go
View File

@ -60,7 +60,7 @@ func TestBasic(t *testing.T) {
case peerId := <-timeoutsCh: case peerId := <-timeoutsCh:
t.Errorf("timeout: %v", peerId) t.Errorf("timeout: %v", peerId)
case request := <-requestsCh: case request := <-requestsCh:
log.Debug("TEST: Pulled new BlockRequest", "request", request) log.Info("TEST: Pulled new BlockRequest", "request", request)
if request.Height == 300 { if request.Height == 300 {
return // Done! return // Done!
} }
@ -68,7 +68,7 @@ func TestBasic(t *testing.T) {
go func() { go func() {
block := &types.Block{Header: &types.Header{Height: request.Height}} block := &types.Block{Header: &types.Header{Height: request.Height}}
pool.AddBlock(block, request.PeerId) pool.AddBlock(block, request.PeerId)
log.Debug("TEST: Added block", "block", request.Height, "peer", request.PeerId) log.Info("TEST: Added block", "block", request.Height, "peer", request.PeerId)
}() }()
} }
} }
@ -112,7 +112,7 @@ func TestTimeout(t *testing.T) {
for { for {
select { select {
case peerId := <-timeoutsCh: case peerId := <-timeoutsCh:
log.Debug("Timeout", "peerId", peerId) log.Info("Timeout", "peerId", peerId)
if _, ok := timedOut[peerId]; !ok { if _, ok := timedOut[peerId]; !ok {
counter++ counter++
if counter == len(peers) { if counter == len(peers) {
@ -120,7 +120,7 @@ func TestTimeout(t *testing.T) {
} }
} }
case request := <-requestsCh: case request := <-requestsCh:
log.Debug("TEST: Pulled new BlockRequest", "request", request) log.Info("TEST: Pulled new BlockRequest", "request", request)
} }
} }

14
blockchain/reactor.go
View File

@ -83,7 +83,7 @@ func NewBlockchainReactor(state *sm.State, store *BlockStore, sync bool) *Blockc
// Implements Reactor // Implements Reactor
func (bcR *BlockchainReactor) Start(sw *p2p.Switch) { func (bcR *BlockchainReactor) Start(sw *p2p.Switch) {
if atomic.CompareAndSwapUint32(&bcR.running, 0, 1) { if atomic.CompareAndSwapUint32(&bcR.running, 0, 1) {
log.Info("Starting BlockchainReactor") log.Notice("Starting BlockchainReactor")
bcR.sw = sw bcR.sw = sw
if bcR.sync { if bcR.sync {
bcR.pool.Start() bcR.pool.Start()
@ -95,7 +95,7 @@ func (bcR *BlockchainReactor) Start(sw *p2p.Switch) {
// Implements Reactor // Implements Reactor
func (bcR *BlockchainReactor) Stop() { func (bcR *BlockchainReactor) Stop() {
if atomic.CompareAndSwapUint32(&bcR.running, 1, 0) { if atomic.CompareAndSwapUint32(&bcR.running, 1, 0) {
log.Info("Stopping BlockchainReactor") log.Notice("Stopping BlockchainReactor")
close(bcR.quit) close(bcR.quit)
bcR.pool.Stop() bcR.pool.Stop()
} }
@ -132,7 +132,7 @@ func (bcR *BlockchainReactor) Receive(chId byte, src *p2p.Peer, msgBytes []byte)
return return
} }
log.Info("Received message", "msg", msg) log.Notice("Received message", "msg", msg)
switch msg := msg.(type) { switch msg := msg.(type) {
case *bcBlockRequestMessage: case *bcBlockRequestMessage:
@ -201,7 +201,7 @@ FOR_LOOP:
case _ = <-switchToConsensusTicker.C: case _ = <-switchToConsensusTicker.C:
height, numPending, numUnassigned := bcR.pool.GetStatus() height, numPending, numUnassigned := bcR.pool.GetStatus()
outbound, inbound, _ := bcR.sw.NumPeers() outbound, inbound, _ := bcR.sw.NumPeers()
log.Debug("Consensus ticker", "numUnassigned", numUnassigned, "numPending", numPending, log.Info("Consensus ticker", "numUnassigned", numUnassigned, "numPending", numPending,
"total", len(bcR.pool.requests), "outbound", outbound, "inbound", inbound) "total", len(bcR.pool.requests), "outbound", outbound, "inbound", inbound)
// NOTE: this condition is very strict right now. may need to weaken // NOTE: this condition is very strict right now. may need to weaken
// If all `maxPendingRequests` requests are unassigned // If all `maxPendingRequests` requests are unassigned
@ -210,7 +210,7 @@ FOR_LOOP:
allUnassigned := numPending == numUnassigned allUnassigned := numPending == numUnassigned
enoughPeers := outbound+inbound >= 3 enoughPeers := outbound+inbound >= 3
if maxPending && allUnassigned && enoughPeers { if maxPending && allUnassigned && enoughPeers {
log.Info("Time to switch to consensus reactor!", "height", height) log.Notice("Time to switch to consensus reactor!", "height", height)
bcR.pool.Stop() bcR.pool.Stop()
conR := bcR.sw.Reactor("CONSENSUS").(consensusReactor) conR := bcR.sw.Reactor("CONSENSUS").(consensusReactor)
@ -224,7 +224,7 @@ FOR_LOOP:
for i := 0; i < 10; i++ { for i := 0; i < 10; i++ {
// See if there are any blocks to sync. // See if there are any blocks to sync.
first, second := bcR.pool.PeekTwoBlocks() first, second := bcR.pool.PeekTwoBlocks()
//log.Debug("TrySync peeked", "first", first, "second", second) //log.Info("TrySync peeked", "first", first, "second", second)
if first == nil || second == nil { if first == nil || second == nil {
// We need both to sync the first block. // We need both to sync the first block.
break SYNC_LOOP break SYNC_LOOP
@ -235,7 +235,7 @@ FOR_LOOP:
err := bcR.state.BondedValidators.VerifyValidation( err := bcR.state.BondedValidators.VerifyValidation(
bcR.state.ChainID, first.Hash(), firstPartsHeader, first.Height, second.LastValidation) bcR.state.ChainID, first.Hash(), firstPartsHeader, first.Height, second.LastValidation)
if err != nil { if err != nil {
log.Debug("error in validation", "error", err) log.Info("error in validation", "error", err)
bcR.pool.RedoRequest(first.Height) bcR.pool.RedoRequest(first.Height)
break SYNC_LOOP break SYNC_LOOP
} else { } else {

2
cmd/barak/main.go
View File

@ -86,7 +86,7 @@ func Run(authCommand AuthCommand) (interface{}, error) {
if err != nil { if err != nil {
return nil, err return nil, err
} }
log.Info(Fmt("Run() received command %v:%v", reflect.TypeOf(command), command)) log.Notice(Fmt("Run() received command %v:%v", reflect.TypeOf(command), command))
// Issue command // Issue command
switch c := command.(type) { switch c := command.(type) {
case CommandStartProcess: case CommandStartProcess:

4
cmd/barak/validate.go
View File

@ -24,7 +24,7 @@ NOTE: Not used, just here in case we want it later.
func ValidateHandler(handler http.Handler, validators []Validator) http.Handler { func ValidateHandler(handler http.Handler, validators []Validator) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
sigStrs := r.Header[http.CanonicalHeaderKey("signatures")] sigStrs := r.Header[http.CanonicalHeaderKey("signatures")]
log.Debug("Woot", "sigstrs", sigStrs, "len", len(sigStrs)) log.Info("Woot", "sigstrs", sigStrs, "len", len(sigStrs))
// from https://medium.com/@xoen/golang-read-from-an-io-readwriter-without-loosing-its-content-2c6911805361 // from https://medium.com/@xoen/golang-read-from-an-io-readwriter-without-loosing-its-content-2c6911805361
// Read the content // Read the content
var bodyBytes []byte var bodyBytes []byte
@ -46,7 +46,7 @@ func ValidateHandler(handler http.Handler, validators []Validator) http.Handler
signBytes := binary.BinaryBytes(tuple) signBytes := binary.BinaryBytes(tuple)
// Validate the sign bytes. // Validate the sign bytes.
//if validate(signBytes, validators, //if validate(signBytes, validators,
log.Debug("Should sign", "bytes", signBytes) log.Info("Should sign", "bytes", signBytes)
// If validation fails // If validation fails
// XXX // XXX
// If validation passes // If validation passes

4
cmd/tendermint/reset_priv_validator.go
View File

@ -18,11 +18,11 @@ func reset_priv_validator() {
privValidator.LastRound = 0 privValidator.LastRound = 0
privValidator.LastStep = 0 privValidator.LastStep = 0
privValidator.Save() privValidator.Save()
log.Info("Reset PrivValidator", "file", privValidatorFile) log.Notice("Reset PrivValidator", "file", privValidatorFile)
} else { } else {
privValidator = sm.GenPrivValidator() privValidator = sm.GenPrivValidator()
privValidator.SetFile(privValidatorFile) privValidator.SetFile(privValidatorFile)
privValidator.Save() privValidator.Save()
log.Info("Generated PrivValidator", "file", privValidatorFile) log.Notice("Generated PrivValidator", "file", privValidatorFile)
} }
} }

4
consensus/height_vote_set.go
View File

@ -78,7 +78,7 @@ func (hvs *HeightVoteSet) addRound(round int) {
if _, ok := hvs.roundVoteSets[round]; ok { if _, ok := hvs.roundVoteSets[round]; ok {
panic("addRound() for an existing round") panic("addRound() for an existing round")
} }
log.Debug("addRound(round)", "round", round) log.Info("addRound(round)", "round", round)
prevotes := NewVoteSet(hvs.height, round, types.VoteTypePrevote, hvs.valSet) prevotes := NewVoteSet(hvs.height, round, types.VoteTypePrevote, hvs.valSet)
precommits := NewVoteSet(hvs.height, round, types.VoteTypePrecommit, hvs.valSet) precommits := NewVoteSet(hvs.height, round, types.VoteTypePrecommit, hvs.valSet)
hvs.roundVoteSets[round] = RoundVoteSet{ hvs.roundVoteSets[round] = RoundVoteSet{
@ -135,7 +135,7 @@ func (hvs *HeightVoteSet) POLRound() int {
} }
func (hvs *HeightVoteSet) getVoteSet(round int, type_ byte) *VoteSet { func (hvs *HeightVoteSet) getVoteSet(round int, type_ byte) *VoteSet {
log.Debug("getVoteSet(round)", "round", round, "type", type_) log.Info("getVoteSet(round)", "round", round, "type", type_)
rvs, ok := hvs.roundVoteSets[round] rvs, ok := hvs.roundVoteSets[round]
if !ok { if !ok {
return nil return nil

56
consensus/reactor.go
View File

@ -56,7 +56,7 @@ func NewConsensusReactor(consensusState *ConsensusState, blockStore *bc.BlockSto
// Implements Reactor // Implements Reactor
func (conR *ConsensusReactor) Start(sw *p2p.Switch) { func (conR *ConsensusReactor) Start(sw *p2p.Switch) {
if atomic.CompareAndSwapUint32(&conR.running, 0, 1) { if atomic.CompareAndSwapUint32(&conR.running, 0, 1) {
log.Info("Starting ConsensusReactor", "fastSync", conR.fastSync) log.Notice("Starting ConsensusReactor", "fastSync", conR.fastSync)
conR.sw = sw conR.sw = sw
if !conR.fastSync { if !conR.fastSync {
conR.conS.Start() conR.conS.Start()
@ -68,7 +68,7 @@ func (conR *ConsensusReactor) Start(sw *p2p.Switch) {
// Implements Reactor // Implements Reactor
func (conR *ConsensusReactor) Stop() { func (conR *ConsensusReactor) Stop() {
if atomic.CompareAndSwapUint32(&conR.running, 1, 0) { if atomic.CompareAndSwapUint32(&conR.running, 1, 0) {
log.Info("Stopping ConsensusReactor") log.Notice("Stopping ConsensusReactor")
conR.conS.Stop() conR.conS.Stop()
close(conR.quit) close(conR.quit)
} }
@ -133,7 +133,7 @@ func (conR *ConsensusReactor) RemovePeer(peer *p2p.Peer, reason interface{}) {
// Implements Reactor // Implements Reactor
// NOTE: We process these messages even when we're fast_syncing. // NOTE: We process these messages even when we're fast_syncing.
func (conR *ConsensusReactor) Receive(chId byte, peer *p2p.Peer, msgBytes []byte) { func (conR *ConsensusReactor) Receive(chId byte, peer *p2p.Peer, msgBytes []byte) {
log.Debug("Receive", "channel", chId, "peer", peer, "bytes", msgBytes) log.Info("Receive", "channel", chId, "peer", peer, "bytes", msgBytes)
if !conR.IsRunning() { if !conR.IsRunning() {
return return
} }
@ -146,7 +146,7 @@ func (conR *ConsensusReactor) Receive(chId byte, peer *p2p.Peer, msgBytes []byte
log.Warn("Error decoding message", "channel", chId, "peer", peer, "msg", msg, "error", err, "bytes", msgBytes) log.Warn("Error decoding message", "channel", chId, "peer", peer, "msg", msg, "error", err, "bytes", msgBytes)
return return
} }
log.Debug("Receive", "channel", chId, "peer", peer, "msg", msg, "rsHeight", rs.Height) //, "bytes", msgBytes) log.Info("Receive", "channel", chId, "peer", peer, "msg", msg, "rsHeight", rs.Height) //, "bytes", msgBytes)
switch chId { switch chId {
case StateChannel: case StateChannel:
@ -275,7 +275,7 @@ func (conR *ConsensusReactor) SetPrivValidator(priv *sm.PrivValidator) {
// Switch from the fast_sync to the consensus: // Switch from the fast_sync to the consensus:
// reset the state, turn off fast_sync, start the consensus-state-machine // reset the state, turn off fast_sync, start the consensus-state-machine
func (conR *ConsensusReactor) SwitchToConsensus(state *sm.State) { func (conR *ConsensusReactor) SwitchToConsensus(state *sm.State) {
log.Info("SwitchToConsensus") log.Notice("SwitchToConsensus")
// NOTE: The line below causes broadcastNewRoundStepRoutine() to // NOTE: The line below causes broadcastNewRoundStepRoutine() to
// broadcast a NewRoundStepMessage. // broadcast a NewRoundStepMessage.
conR.conS.updateToState(state, false) conR.conS.updateToState(state, false)
@ -349,7 +349,7 @@ OUTER_LOOP:
for { for {
// Manage disconnects from self or peer. // Manage disconnects from self or peer.
if !peer.IsRunning() || !conR.IsRunning() { if !peer.IsRunning() || !conR.IsRunning() {
log.Info(Fmt("Stopping gossipDataRoutine for %v.", peer)) log.Notice(Fmt("Stopping gossipDataRoutine for %v.", peer))
return return
} }
rs := conR.conS.GetRoundState() rs := conR.conS.GetRoundState()
@ -357,7 +357,7 @@ OUTER_LOOP:
// Send proposal Block parts? // Send proposal Block parts?
if rs.ProposalBlockParts.HasHeader(prs.ProposalBlockPartsHeader) { if rs.ProposalBlockParts.HasHeader(prs.ProposalBlockPartsHeader) {
//log.Debug("ProposalBlockParts matched", "blockParts", prs.ProposalBlockParts) //log.Info("ProposalBlockParts matched", "blockParts", prs.ProposalBlockParts)
if index, ok := rs.ProposalBlockParts.BitArray().Sub(prs.ProposalBlockParts.Copy()).PickRandom(); ok { if index, ok := rs.ProposalBlockParts.BitArray().Sub(prs.ProposalBlockParts.Copy()).PickRandom(); ok {
part := rs.ProposalBlockParts.GetPart(index) part := rs.ProposalBlockParts.GetPart(index)
msg := &BlockPartMessage{ msg := &BlockPartMessage{
@ -373,12 +373,12 @@ OUTER_LOOP:
// If the peer is on a previous height, help catch up. // If the peer is on a previous height, help catch up.
if (0 < prs.Height) && (prs.Height < rs.Height) { if (0 < prs.Height) && (prs.Height < rs.Height) {
//log.Debug("Data catchup", "height", rs.Height, "peerHeight", prs.Height, "peerProposalBlockParts", prs.ProposalBlockParts) //log.Info("Data catchup", "height", rs.Height, "peerHeight", prs.Height, "peerProposalBlockParts", prs.ProposalBlockParts)
if index, ok := prs.ProposalBlockParts.Not().PickRandom(); ok { if index, ok := prs.ProposalBlockParts.Not().PickRandom(); ok {
// Ensure that the peer's PartSetHeader is correct // Ensure that the peer's PartSetHeader is correct
blockMeta := conR.blockStore.LoadBlockMeta(prs.Height) blockMeta := conR.blockStore.LoadBlockMeta(prs.Height)
if !blockMeta.PartsHeader.Equals(prs.ProposalBlockPartsHeader) { if !blockMeta.PartsHeader.Equals(prs.ProposalBlockPartsHeader) {
log.Debug("Peer ProposalBlockPartsHeader mismatch, sleeping", log.Info("Peer ProposalBlockPartsHeader mismatch, sleeping",
"peerHeight", prs.Height, "blockPartsHeader", blockMeta.PartsHeader, "peerBlockPartsHeader", prs.ProposalBlockPartsHeader) "peerHeight", prs.Height, "blockPartsHeader", blockMeta.PartsHeader, "peerBlockPartsHeader", prs.ProposalBlockPartsHeader)
time.Sleep(peerGossipSleepDuration) time.Sleep(peerGossipSleepDuration)
continue OUTER_LOOP continue OUTER_LOOP
@ -401,7 +401,7 @@ OUTER_LOOP:
ps.SetHasProposalBlockPart(prs.Height, prs.Round, index) ps.SetHasProposalBlockPart(prs.Height, prs.Round, index)
continue OUTER_LOOP continue OUTER_LOOP
} else { } else {
//log.Debug("No parts to send in catch-up, sleeping") //log.Info("No parts to send in catch-up, sleeping")
time.Sleep(peerGossipSleepDuration) time.Sleep(peerGossipSleepDuration)
continue OUTER_LOOP continue OUTER_LOOP
} }
@ -409,7 +409,7 @@ OUTER_LOOP:
// If height and round don't match, sleep. // If height and round don't match, sleep.
if (rs.Height != prs.Height) || (rs.Round != prs.Round) { if (rs.Height != prs.Height) || (rs.Round != prs.Round) {
//log.Debug("Peer Height|Round mismatch, sleeping", "peerHeight", prs.Height, "peerRound", prs.Round, "peer", peer) //log.Info("Peer Height|Round mismatch, sleeping", "peerHeight", prs.Height, "peerRound", prs.Round, "peer", peer)
time.Sleep(peerGossipSleepDuration) time.Sleep(peerGossipSleepDuration)
continue OUTER_LOOP continue OUTER_LOOP
} }
@ -458,7 +458,7 @@ OUTER_LOOP:
for { for {
// Manage disconnects from self or peer. // Manage disconnects from self or peer.
if !peer.IsRunning() || !conR.IsRunning() { if !peer.IsRunning() || !conR.IsRunning() {
log.Info(Fmt("Stopping gossipVotesRoutine for %v.", peer)) log.Notice(Fmt("Stopping gossipVotesRoutine for %v.", peer))
return return
} }
rs := conR.conS.GetRoundState() rs := conR.conS.GetRoundState()
@ -471,7 +471,7 @@ OUTER_LOOP:
sleeping = 0 sleeping = 0
} }
log.Debug("gossipVotesRoutine", "rsHeight", rs.Height, "rsRound", rs.Round, log.Info("gossipVotesRoutine", "rsHeight", rs.Height, "rsRound", rs.Round,
"prsHeight", prs.Height, "prsRound", prs.Round, "prsStep", prs.Step) "prsHeight", prs.Height, "prsRound", prs.Round, "prsStep", prs.Step)
// If height matches, then send LastCommit, Prevotes, Precommits. // If height matches, then send LastCommit, Prevotes, Precommits.
@ -479,35 +479,35 @@ OUTER_LOOP:
// If there are lastCommits to send... // If there are lastCommits to send...
if prs.Step == RoundStepNewHeight { if prs.Step == RoundStepNewHeight {
if ps.PickSendVote(rs.LastCommit) { if ps.PickSendVote(rs.LastCommit) {
log.Debug("Picked rs.LastCommit to send") log.Info("Picked rs.LastCommit to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
// If there are prevotes to send... // If there are prevotes to send...
if rs.Round == prs.Round && prs.Step <= RoundStepPrevote { if rs.Round == prs.Round && prs.Step <= RoundStepPrevote {
if ps.PickSendVote(rs.Votes.Prevotes(rs.Round)) { if ps.PickSendVote(rs.Votes.Prevotes(rs.Round)) {
log.Debug("Picked rs.Prevotes(rs.Round) to send") log.Info("Picked rs.Prevotes(rs.Round) to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
// If there are precommits to send... // If there are precommits to send...
if rs.Round == prs.Round && prs.Step <= RoundStepPrecommit { if rs.Round == prs.Round && prs.Step <= RoundStepPrecommit {
if ps.PickSendVote(rs.Votes.Precommits(rs.Round)) { if ps.PickSendVote(rs.Votes.Precommits(rs.Round)) {
log.Debug("Picked rs.Precommits(rs.Round) to send") log.Info("Picked rs.Precommits(rs.Round) to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
// If there are prevotes to send for the last round... // If there are prevotes to send for the last round...
if rs.Round == prs.Round+1 && prs.Step <= RoundStepPrevote { if rs.Round == prs.Round+1 && prs.Step <= RoundStepPrevote {
if ps.PickSendVote(rs.Votes.Prevotes(prs.Round)) { if ps.PickSendVote(rs.Votes.Prevotes(prs.Round)) {
log.Debug("Picked rs.Prevotes(prs.Round) to send") log.Info("Picked rs.Prevotes(prs.Round) to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
// If there are precommits to send for the last round... // If there are precommits to send for the last round...
if rs.Round == prs.Round+1 && prs.Step <= RoundStepPrecommit { if rs.Round == prs.Round+1 && prs.Step <= RoundStepPrecommit {
if ps.PickSendVote(rs.Votes.Precommits(prs.Round)) { if ps.PickSendVote(rs.Votes.Precommits(prs.Round)) {
log.Debug("Picked rs.Precommits(prs.Round) to send") log.Info("Picked rs.Precommits(prs.Round) to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
@ -515,7 +515,7 @@ OUTER_LOOP:
if 0 <= prs.ProposalPOLRound { if 0 <= prs.ProposalPOLRound {
if polPrevotes := rs.Votes.Prevotes(prs.ProposalPOLRound); polPrevotes != nil { if polPrevotes := rs.Votes.Prevotes(prs.ProposalPOLRound); polPrevotes != nil {
if ps.PickSendVote(polPrevotes) { if ps.PickSendVote(polPrevotes) {
log.Debug("Picked rs.Prevotes(prs.ProposalPOLRound) to send") log.Info("Picked rs.Prevotes(prs.ProposalPOLRound) to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
@ -526,7 +526,7 @@ OUTER_LOOP:
// If peer is lagging by height 1, send LastCommit. // If peer is lagging by height 1, send LastCommit.
if prs.Height != 0 && rs.Height == prs.Height+1 { if prs.Height != 0 && rs.Height == prs.Height+1 {
if ps.PickSendVote(rs.LastCommit) { if ps.PickSendVote(rs.LastCommit) {
log.Debug("Picked rs.LastCommit to send") log.Info("Picked rs.LastCommit to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
@ -537,9 +537,9 @@ OUTER_LOOP:
// Load the block validation for prs.Height, // Load the block validation for prs.Height,
// which contains precommit signatures for prs.Height. // which contains precommit signatures for prs.Height.
validation := conR.blockStore.LoadBlockValidation(prs.Height) validation := conR.blockStore.LoadBlockValidation(prs.Height)
log.Debug("Loaded BlockValidation for catch-up", "height", prs.Height, "validation", validation) log.Info("Loaded BlockValidation for catch-up", "height", prs.Height, "validation", validation)
if ps.PickSendVote(validation) { if ps.PickSendVote(validation) {
log.Debug("Picked Catchup validation to send") log.Info("Picked Catchup validation to send")
continue OUTER_LOOP continue OUTER_LOOP
} }
} }
@ -547,7 +547,7 @@ OUTER_LOOP:
if sleeping == 0 { if sleeping == 0 {
// We sent nothing. Sleep... // We sent nothing. Sleep...
sleeping = 1 sleeping = 1
log.Debug("No votes to send, sleeping", "peer", peer, log.Info("No votes to send, sleeping", "peer", peer,
"localPV", rs.Votes.Prevotes(rs.Round).BitArray(), "peerPV", prs.Prevotes, "localPV", rs.Votes.Prevotes(rs.Round).BitArray(), "peerPV", prs.Prevotes,
"localPC", rs.Votes.Precommits(rs.Round).BitArray(), "peerPC", prs.Precommits) "localPC", rs.Votes.Precommits(rs.Round).BitArray(), "peerPC", prs.Precommits)
} else if sleeping == 2 { } else if sleeping == 2 {
@ -783,23 +783,23 @@ func (ps *PeerState) setHasVote(height int, round int, type_ byte, index int) {
switch type_ { switch type_ {
case types.VoteTypePrevote: case types.VoteTypePrevote:
ps.Prevotes.SetIndex(index, true) ps.Prevotes.SetIndex(index, true)
log.Debug("SetHasVote(round-match)", "prevotes", ps.Prevotes, "index", index) log.Info("SetHasVote(round-match)", "prevotes", ps.Prevotes, "index", index)
case types.VoteTypePrecommit: case types.VoteTypePrecommit:
ps.Precommits.SetIndex(index, true) ps.Precommits.SetIndex(index, true)
log.Debug("SetHasVote(round-match)", "precommits", ps.Precommits, "index", index) log.Info("SetHasVote(round-match)", "precommits", ps.Precommits, "index", index)
} }
} else if ps.CatchupCommitRound == round { } else if ps.CatchupCommitRound == round {
switch type_ { switch type_ {
case types.VoteTypePrevote: case types.VoteTypePrevote:
case types.VoteTypePrecommit: case types.VoteTypePrecommit:
ps.CatchupCommit.SetIndex(index, true) ps.CatchupCommit.SetIndex(index, true)
log.Debug("SetHasVote(CatchupCommit)", "precommits", ps.Precommits, "index", index) log.Info("SetHasVote(CatchupCommit)", "precommits", ps.Precommits, "index", index)
} }
} else if ps.ProposalPOLRound == round { } else if ps.ProposalPOLRound == round {
switch type_ { switch type_ {
case types.VoteTypePrevote: case types.VoteTypePrevote:
ps.ProposalPOL.SetIndex(index, true) ps.ProposalPOL.SetIndex(index, true)
log.Debug("SetHasVote(ProposalPOL)", "prevotes", ps.Prevotes, "index", index) log.Info("SetHasVote(ProposalPOL)", "prevotes", ps.Prevotes, "index", index)
case types.VoteTypePrecommit: case types.VoteTypePrecommit:
} }
} }
@ -809,7 +809,7 @@ func (ps *PeerState) setHasVote(height int, round int, type_ byte, index int) {
case types.VoteTypePrevote: case types.VoteTypePrevote:
case types.VoteTypePrecommit: case types.VoteTypePrecommit:
ps.LastCommit.SetIndex(index, true) ps.LastCommit.SetIndex(index, true)
log.Debug("setHasVote(LastCommit)", "lastCommit", ps.LastCommit, "index", index) log.Info("setHasVote(LastCommit)", "lastCommit", ps.LastCommit, "index", index)
} }
} }
} else { } else {

80
consensus/state.go
View File

@ -365,14 +365,14 @@ func (cs *ConsensusState) NewStepCh() chan *RoundState {
func (cs *ConsensusState) Start() { func (cs *ConsensusState) Start() {
if atomic.CompareAndSwapUint32(&cs.started, 0, 1) { if atomic.CompareAndSwapUint32(&cs.started, 0, 1) {
log.Info("Starting ConsensusState") log.Notice("Starting ConsensusState")
cs.scheduleRound0(cs.Height) cs.scheduleRound0(cs.Height)
} }
} }
// EnterNewRound(height, 0) at cs.StartTime. // EnterNewRound(height, 0) at cs.StartTime.
func (cs *ConsensusState) scheduleRound0(height int) { func (cs *ConsensusState) scheduleRound0(height int) {
//log.Debug("scheduleRound0", "now", time.Now(), "startTime", cs.StartTime) //log.Info("scheduleRound0", "now", time.Now(), "startTime", cs.StartTime)
sleepDuration := cs.StartTime.Sub(time.Now()) sleepDuration := cs.StartTime.Sub(time.Now())
go func() { go func() {
if 0 < sleepDuration { if 0 < sleepDuration {
@ -384,7 +384,7 @@ func (cs *ConsensusState) scheduleRound0(height int) {
func (cs *ConsensusState) Stop() { func (cs *ConsensusState) Stop() {
if atomic.CompareAndSwapUint32(&cs.stopped, 0, 1) { if atomic.CompareAndSwapUint32(&cs.stopped, 0, 1) {
log.Info("Stopping ConsensusState") log.Notice("Stopping ConsensusState")
close(cs.quit) close(cs.quit)
} }
} }
@ -409,7 +409,7 @@ func (cs *ConsensusState) updateToState(state *sm.State, contiguous bool) {
// This happens when SwitchToConsensus() is called in the reactor. // This happens when SwitchToConsensus() is called in the reactor.
// We don't want to reset e.g. the Votes. // We don't want to reset e.g. the Votes.
if cs.state != nil && (state.LastBlockHeight <= cs.state.LastBlockHeight) { if cs.state != nil && (state.LastBlockHeight <= cs.state.LastBlockHeight) {
log.Info("Ignoring updateToState()", "newHeight", state.LastBlockHeight+1, "oldHeight", cs.state.LastBlockHeight+1) log.Notice("Ignoring updateToState()", "newHeight", state.LastBlockHeight+1, "oldHeight", cs.state.LastBlockHeight+1)
return return
} }
@ -474,7 +474,7 @@ func (cs *ConsensusState) maybeRebond() {
log.Error("Failed to broadcast RebondTx", log.Error("Failed to broadcast RebondTx",
"height", cs.Height, "round", cs.Round, "tx", rebondTx, "error", err) "height", cs.Height, "round", cs.Round, "tx", rebondTx, "error", err)
} else { } else {
log.Info("Signed and broadcast RebondTx", log.Notice("Signed and broadcast RebondTx",
"height", cs.Height, "round", cs.Round, "tx", rebondTx) "height", cs.Height, "round", cs.Round, "tx", rebondTx)
} }
} else { } else {
@ -498,13 +498,13 @@ func (cs *ConsensusState) EnterNewRound(height int, round int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || round < cs.Round || (cs.Round == round && cs.Step != RoundStepNewHeight) { if cs.Height != height || round < cs.Round || (cs.Round == round && cs.Step != RoundStepNewHeight) {
log.Debug(Fmt("EnterNewRound(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterNewRound(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
return return
} }
if now := time.Now(); cs.StartTime.After(now) { if now := time.Now(); cs.StartTime.After(now) {
log.Warn("Need to set a buffer and log.Warn() here for sanity.", "startTime", cs.StartTime, "now", now) log.Warn("Need to set a buffer and log.Warn() here for sanity.", "startTime", cs.StartTime, "now", now)
} }
log.Info(Fmt("EnterNewRound(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Notice(Fmt("EnterNewRound(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
// Increment validators if necessary // Increment validators if necessary
validators := cs.Validators validators := cs.Validators
@ -537,10 +537,10 @@ func (cs *ConsensusState) EnterPropose(height int, round int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPropose <= cs.Step) { if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPropose <= cs.Step) {
log.Debug(Fmt("EnterPropose(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPropose(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
return return
} }
log.Debug(Fmt("EnterPropose(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPropose(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
defer func() { defer func() {
// Done EnterPropose: // Done EnterPropose:
@ -566,9 +566,9 @@ func (cs *ConsensusState) EnterPropose(height int, round int) {
} }
if !bytes.Equal(cs.Validators.Proposer().Address, cs.privValidator.Address) { if !bytes.Equal(cs.Validators.Proposer().Address, cs.privValidator.Address) {
log.Debug("EnterPropose: Not our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator) log.Info("EnterPropose: Not our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator)
} else { } else {
log.Debug("EnterPropose: Our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator) log.Info("EnterPropose: Our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator)
cs.decideProposal(height, round) cs.decideProposal(height, round)
} }
} }
@ -591,8 +591,8 @@ func (cs *ConsensusState) decideProposal(height int, round int) {
proposal := NewProposal(height, round, blockParts.Header(), cs.Votes.POLRound()) proposal := NewProposal(height, round, blockParts.Header(), cs.Votes.POLRound())
err := cs.privValidator.SignProposal(cs.state.ChainID, proposal) err := cs.privValidator.SignProposal(cs.state.ChainID, proposal)
if err == nil { if err == nil {
log.Info("Signed and set proposal", "height", height, "round", round, "proposal", proposal) log.Notice("Signed and set proposal", "height", height, "round", round, "proposal", proposal)
log.Debug(Fmt("Signed and set proposal block: %v", block)) log.Info(Fmt("Signed and set proposal block: %v", block))
// Set fields // Set fields
cs.Proposal = proposal cs.Proposal = proposal
cs.ProposalBlock = block cs.ProposalBlock = block
@ -670,10 +670,10 @@ func (cs *ConsensusState) EnterPrevote(height int, round int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrevote <= cs.Step) { if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrevote <= cs.Step) {
log.Debug(Fmt("EnterPrevote(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrevote(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
return return
} }
log.Debug(Fmt("EnterPrevote(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrevote(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
// Sign and broadcast vote as necessary // Sign and broadcast vote as necessary
cs.doPrevote(height, round) cs.doPrevote(height, round)
@ -691,7 +691,7 @@ func (cs *ConsensusState) EnterPrevote(height int, round int) {
func (cs *ConsensusState) doPrevote(height int, round int) { func (cs *ConsensusState) doPrevote(height int, round int) {
// If a block is locked, prevote that. // If a block is locked, prevote that.
if cs.LockedBlock != nil { if cs.LockedBlock != nil {
log.Debug("EnterPrevote: Block was locked") log.Info("EnterPrevote: Block was locked")
cs.signAddVote(types.VoteTypePrevote, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header()) cs.signAddVote(types.VoteTypePrevote, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header())
return return
} }
@ -722,13 +722,13 @@ func (cs *ConsensusState) EnterPrevoteWait(height int, round int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrevoteWait <= cs.Step) { if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrevoteWait <= cs.Step) {
log.Debug(Fmt("EnterPrevoteWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrevoteWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
return return
} }
if !cs.Votes.Prevotes(round).HasTwoThirdsAny() { if !cs.Votes.Prevotes(round).HasTwoThirdsAny() {
panic(Fmt("EnterPrevoteWait(%v/%v), but Prevotes does not have any +2/3 votes", height, round)) panic(Fmt("EnterPrevoteWait(%v/%v), but Prevotes does not have any +2/3 votes", height, round))
} }
log.Debug(Fmt("EnterPrevoteWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrevoteWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
// Done EnterPrevoteWait: // Done EnterPrevoteWait:
cs.Round = round cs.Round = round
@ -752,10 +752,10 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrecommit <= cs.Step) { if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrecommit <= cs.Step) {
log.Debug(Fmt("EnterPrecommit(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrecommit(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
return return
} }
log.Debug(Fmt("EnterPrecommit(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrecommit(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
defer func() { defer func() {
// Done EnterPrecommit: // Done EnterPrecommit:
@ -773,10 +773,10 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) {
// If we don't have two thirds of prevotes, just precommit locked block or nil // If we don't have two thirds of prevotes, just precommit locked block or nil
if !ok { if !ok {
if cs.LockedBlock != nil { if cs.LockedBlock != nil {
log.Debug("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting lock.") log.Info("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting lock.")
cs.signAddVote(types.VoteTypePrecommit, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header()) cs.signAddVote(types.VoteTypePrecommit, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header())
} else { } else {
log.Debug("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting nil.") log.Info("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting nil.")
cs.signAddVote(types.VoteTypePrecommit, nil, types.PartSetHeader{}) cs.signAddVote(types.VoteTypePrecommit, nil, types.PartSetHeader{})
} }
return return
@ -785,9 +785,9 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) {
// +2/3 prevoted nil. Unlock and precommit nil. // +2/3 prevoted nil. Unlock and precommit nil.
if len(hash) == 0 { if len(hash) == 0 {
if cs.LockedBlock == nil { if cs.LockedBlock == nil {
log.Debug("EnterPrecommit: +2/3 prevoted for nil.") log.Info("EnterPrecommit: +2/3 prevoted for nil.")
} else { } else {
log.Debug("EnterPrecommit: +2/3 prevoted for nil. Unlocking") log.Info("EnterPrecommit: +2/3 prevoted for nil. Unlocking")
cs.LockedRound = 0 cs.LockedRound = 0
cs.LockedBlock = nil cs.LockedBlock = nil
cs.LockedBlockParts = nil cs.LockedBlockParts = nil
@ -800,14 +800,14 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) {
// If +2/3 prevoted for already locked block, precommit it. // If +2/3 prevoted for already locked block, precommit it.
if cs.LockedBlock.HashesTo(hash) { if cs.LockedBlock.HashesTo(hash) {
log.Debug("EnterPrecommit: +2/3 prevoted locked block.") log.Info("EnterPrecommit: +2/3 prevoted locked block.")
cs.signAddVote(types.VoteTypePrecommit, hash, partsHeader) cs.signAddVote(types.VoteTypePrecommit, hash, partsHeader)
return return
} }
// If +2/3 prevoted for proposal block, stage and precommit it // If +2/3 prevoted for proposal block, stage and precommit it
if cs.ProposalBlock.HashesTo(hash) { if cs.ProposalBlock.HashesTo(hash) {
log.Debug("EnterPrecommit: +2/3 prevoted proposal block.") log.Info("EnterPrecommit: +2/3 prevoted proposal block.")
// Validate the block. // Validate the block.
if err := cs.stageBlock(cs.ProposalBlock, cs.ProposalBlockParts); err != nil { if err := cs.stageBlock(cs.ProposalBlock, cs.ProposalBlockParts); err != nil {
panic(Fmt("EnterPrecommit: +2/3 prevoted for an invalid block: %v", err)) panic(Fmt("EnterPrecommit: +2/3 prevoted for an invalid block: %v", err))
@ -841,13 +841,13 @@ func (cs *ConsensusState) EnterPrecommitWait(height int, round int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrecommitWait <= cs.Step) { if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrecommitWait <= cs.Step) {
log.Debug(Fmt("EnterPrecommitWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrecommitWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
return return
} }
if !cs.Votes.Precommits(round).HasTwoThirdsAny() { if !cs.Votes.Precommits(round).HasTwoThirdsAny() {
panic(Fmt("EnterPrecommitWait(%v/%v), but Precommits does not have any +2/3 votes", height, round)) panic(Fmt("EnterPrecommitWait(%v/%v), but Precommits does not have any +2/3 votes", height, round))
} }
log.Debug(Fmt("EnterPrecommitWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterPrecommitWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
// Done EnterPrecommitWait: // Done EnterPrecommitWait:
cs.Round = round cs.Round = round
@ -870,10 +870,10 @@ func (cs *ConsensusState) EnterCommit(height int) {
cs.mtx.Lock() cs.mtx.Lock()
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || RoundStepCommit <= cs.Step { if cs.Height != height || RoundStepCommit <= cs.Step {
log.Debug(Fmt("EnterCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step))
return return
} }
log.Debug(Fmt("EnterCommit(%v). Current: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("EnterCommit(%v). Current: %v/%v/%v", height, cs.Height, cs.Round, cs.Step))
defer func() { defer func() {
// Done Entercommit: // Done Entercommit:
@ -944,7 +944,7 @@ func (cs *ConsensusState) FinalizeCommit(height int) {
defer cs.mtx.Unlock() defer cs.mtx.Unlock()
if cs.Height != height || cs.Step != RoundStepCommit { if cs.Height != height || cs.Step != RoundStepCommit {
log.Debug(Fmt("FinalizeCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) log.Info(Fmt("FinalizeCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step))
return return
} }
@ -965,7 +965,7 @@ func (cs *ConsensusState) FinalizeCommit(height int) {
} }
// END SANITY CHECK // END SANITY CHECK
log.Debug(Fmt("Finalizing commit of block: %v", cs.ProposalBlock)) log.Info(Fmt("Finalizing commit of block: %v", cs.ProposalBlock))
// We have the block, so stage/save/commit-vote. // We have the block, so stage/save/commit-vote.
cs.saveBlock(cs.ProposalBlock, cs.ProposalBlockParts, cs.Votes.Precommits(cs.Round)) cs.saveBlock(cs.ProposalBlock, cs.ProposalBlockParts, cs.Votes.Precommits(cs.Round))
// Increment height. // Increment height.
@ -1044,7 +1044,7 @@ func (cs *ConsensusState) AddProposalBlockPart(height int, part *types.Part) (ad
var n int64 var n int64
var err error var err error
cs.ProposalBlock = binary.ReadBinary(&types.Block{}, cs.ProposalBlockParts.GetReader(), &n, &err).(*types.Block) cs.ProposalBlock = binary.ReadBinary(&types.Block{}, cs.ProposalBlockParts.GetReader(), &n, &err).(*types.Block)
log.Debug("Received complete proposal", "hash", cs.ProposalBlock.Hash()) log.Info("Received complete proposal", "hash", cs.ProposalBlock.Hash())
if cs.Step == RoundStepPropose && cs.isProposalComplete() { if cs.Step == RoundStepPropose && cs.isProposalComplete() {
// Move onto the next step // Move onto the next step
go cs.EnterPrevote(height, cs.Round) go cs.EnterPrevote(height, cs.Round)
@ -1067,13 +1067,13 @@ func (cs *ConsensusState) AddVote(address []byte, vote *types.Vote, peerKey stri
//----------------------------------------------------------------------------- //-----------------------------------------------------------------------------
func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey string) (added bool, index int, err error) { func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey string) (added bool, index int, err error) {
log.Debug("addVote", "voteHeight", vote.Height, "voteType", vote.Type, "csHeight", cs.Height) log.Info("addVote", "voteHeight", vote.Height, "voteType", vote.Type, "csHeight", cs.Height)
// A precommit for the previous height? // A precommit for the previous height?
if vote.Height+1 == cs.Height && vote.Type == types.VoteTypePrecommit { if vote.Height+1 == cs.Height && vote.Type == types.VoteTypePrecommit {
added, index, err = cs.LastCommit.AddByAddress(address, vote) added, index, err = cs.LastCommit.AddByAddress(address, vote)
if added { if added {
log.Debug(Fmt("Added to lastPrecommits: %v", cs.LastCommit.StringShort())) log.Info(Fmt("Added to lastPrecommits: %v", cs.LastCommit.StringShort()))
} }
return return
} }
@ -1086,7 +1086,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri
switch vote.Type { switch vote.Type {
case types.VoteTypePrevote: case types.VoteTypePrevote:
prevotes := cs.Votes.Prevotes(vote.Round) prevotes := cs.Votes.Prevotes(vote.Round)
log.Debug(Fmt("Added to prevotes: %v", prevotes.StringShort())) log.Info(Fmt("Added to prevotes: %v", prevotes.StringShort()))
// First, unlock if prevotes is a valid POL. // First, unlock if prevotes is a valid POL.
// >> lockRound < POLRound <= unlockOrChangeLockRound (see spec) // >> lockRound < POLRound <= unlockOrChangeLockRound (see spec)
// NOTE: If (lockRound < POLRound) but !(POLRound <= unlockOrChangeLockRound), // NOTE: If (lockRound < POLRound) but !(POLRound <= unlockOrChangeLockRound),
@ -1095,7 +1095,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri
if (cs.LockedBlock != nil) && (cs.LockedRound < vote.Round) && (vote.Round <= cs.Round) { if (cs.LockedBlock != nil) && (cs.LockedRound < vote.Round) && (vote.Round <= cs.Round) {
hash, _, ok := prevotes.TwoThirdsMajority() hash, _, ok := prevotes.TwoThirdsMajority()
if ok && !cs.LockedBlock.HashesTo(hash) { if ok && !cs.LockedBlock.HashesTo(hash) {
log.Info("Unlocking because of POL.", "lockedRound", cs.LockedRound, "POLRound", vote.Round) log.Notice("Unlocking because of POL.", "lockedRound", cs.LockedRound, "POLRound", vote.Round)
cs.LockedRound = 0 cs.LockedRound = 0
cs.LockedBlock = nil cs.LockedBlock = nil
cs.LockedBlockParts = nil cs.LockedBlockParts = nil
@ -1122,7 +1122,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri
} }
case types.VoteTypePrecommit: case types.VoteTypePrecommit:
precommits := cs.Votes.Precommits(vote.Round) precommits := cs.Votes.Precommits(vote.Round)
log.Debug(Fmt("Added to precommit: %v", precommits.StringShort())) log.Info(Fmt("Added to precommit: %v", precommits.StringShort()))
if cs.Round <= vote.Round && precommits.HasTwoThirdsAny() { if cs.Round <= vote.Round && precommits.HasTwoThirdsAny() {
go func() { go func() {
hash, _, ok := precommits.TwoThirdsMajority() hash, _, ok := precommits.TwoThirdsMajority()
@ -1149,7 +1149,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri
} }
// Height mismatch, bad peer? // Height mismatch, bad peer?
log.Debug("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height) log.Info("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height)
return return
} }
@ -1196,7 +1196,7 @@ func (cs *ConsensusState) signAddVote(type_ byte, hash []byte, header types.Part
err := cs.privValidator.SignVote(cs.state.ChainID, vote) err := cs.privValidator.SignVote(cs.state.ChainID, vote)
if err == nil { if err == nil {
_, _, err := cs.addVote(cs.privValidator.Address, vote, "") _, _, err := cs.addVote(cs.privValidator.Address, vote, "")
log.Info("Signed and added vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err) log.Notice("Signed and added vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err)
return vote return vote
} else { } else {
log.Warn("Error signing vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err) log.Warn("Error signing vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err)

16
mempool/mempool.go
View File

@ -43,10 +43,10 @@ func (mem *Mempool) AddTx(tx types.Tx) (err error) {
defer mem.mtx.Unlock() defer mem.mtx.Unlock()
err = sm.ExecTx(mem.cache, tx, false, nil) err = sm.ExecTx(mem.cache, tx, false, nil)
if err != nil { if err != nil {
log.Debug("AddTx() error", "tx", tx, "error", err) log.Info("AddTx() error", "tx", tx, "error", err)
return err return err
} else { } else {
log.Debug("AddTx() success", "tx", tx) log.Info("AddTx() success", "tx", tx)
mem.txs = append(mem.txs, tx) mem.txs = append(mem.txs, tx)
return nil return nil
} }
@ -55,7 +55,7 @@ func (mem *Mempool) AddTx(tx types.Tx) (err error) {
func (mem *Mempool) GetProposalTxs() []types.Tx { func (mem *Mempool) GetProposalTxs() []types.Tx {
mem.mtx.Lock() mem.mtx.Lock()
defer mem.mtx.Unlock() defer mem.mtx.Unlock()
log.Debug("GetProposalTxs:", "txs", mem.txs) log.Info("GetProposalTxs:", "txs", mem.txs)
return mem.txs return mem.txs
} }
@ -80,10 +80,10 @@ func (mem *Mempool) ResetForBlockAndState(block *types.Block, state *sm.State) {
for _, tx := range mem.txs { for _, tx := range mem.txs {
txID := types.TxID(state.ChainID, tx) txID := types.TxID(state.ChainID, tx)
if _, ok := blockTxsMap[string(txID)]; ok { if _, ok := blockTxsMap[string(txID)]; ok {
log.Debug("Filter out, already committed", "tx", tx, "txID", txID) log.Info("Filter out, already committed", "tx", tx, "txID", txID)
continue continue
} else { } else {
log.Debug("Filter in, still new", "tx", tx, "txID", txID) log.Info("Filter in, still new", "tx", tx, "txID", txID)
txs = append(txs, tx) txs = append(txs, tx)
} }
} }
@ -93,15 +93,15 @@ func (mem *Mempool) ResetForBlockAndState(block *types.Block, state *sm.State) {
for _, tx := range txs { for _, tx := range txs {
err := sm.ExecTx(mem.cache, tx, false, nil) err := sm.ExecTx(mem.cache, tx, false, nil)
if err == nil { if err == nil {
log.Debug("Filter in, valid", "tx", tx) log.Info("Filter in, valid", "tx", tx)
validTxs = append(validTxs, tx) validTxs = append(validTxs, tx)
} else { } else {
// tx is no longer valid. // tx is no longer valid.
log.Debug("Filter out, no longer valid", "tx", tx, "error", err) log.Info("Filter out, no longer valid", "tx", tx, "error", err)
} }
} }
// We're done! // We're done!
log.Debug("New txs", "txs", validTxs, "oldTxs", mem.txs) log.Info("New txs", "txs", validTxs, "oldTxs", mem.txs)
mem.txs = validTxs mem.txs = validTxs
} }

10
mempool/reactor.go
View File

@ -41,14 +41,14 @@ func NewMempoolReactor(mempool *Mempool) *MempoolReactor {
func (memR *MempoolReactor) Start(sw *p2p.Switch) { func (memR *MempoolReactor) Start(sw *p2p.Switch) {
if atomic.CompareAndSwapUint32(&memR.started, 0, 1) { if atomic.CompareAndSwapUint32(&memR.started, 0, 1) {
memR.sw = sw memR.sw = sw
log.Info("Starting MempoolReactor") log.Notice("Starting MempoolReactor")
} }
} }
// Implements Reactor // Implements Reactor
func (memR *MempoolReactor) Stop() { func (memR *MempoolReactor) Stop() {
if atomic.CompareAndSwapUint32(&memR.stopped, 0, 1) { if atomic.CompareAndSwapUint32(&memR.stopped, 0, 1) {
log.Info("Stopping MempoolReactor") log.Notice("Stopping MempoolReactor")
close(memR.quit) close(memR.quit)
} }
} }
@ -78,17 +78,17 @@ func (memR *MempoolReactor) Receive(chId byte, src *p2p.Peer, msgBytes []byte) {
log.Warn("Error decoding message", "error", err) log.Warn("Error decoding message", "error", err)
return return
} }
log.Info("MempoolReactor received message", "msg", msg) log.Notice("MempoolReactor received message", "msg", msg)
switch msg := msg.(type) { switch msg := msg.(type) {
case *TxMessage: case *TxMessage:
err := memR.Mempool.AddTx(msg.Tx) err := memR.Mempool.AddTx(msg.Tx)
if err != nil { if err != nil {
// Bad, seen, or conflicting tx. // Bad, seen, or conflicting tx.
log.Debug("Could not add tx", "tx", msg.Tx) log.Info("Could not add tx", "tx", msg.Tx)
return return
} else { } else {
log.Debug("Added valid tx", "tx", msg.Tx) log.Info("Added valid tx", "tx", msg.Tx)
} }
// Share tx. // Share tx.
// We use a simple shotgun approach for now. // We use a simple shotgun approach for now.

10
node/node.go
View File

@ -84,13 +84,13 @@ func NewNode() *Node {
privValidatorFile := config.GetString("priv_validator_file") privValidatorFile := config.GetString("priv_validator_file")
if _, err := os.Stat(privValidatorFile); err == nil { if _, err := os.Stat(privValidatorFile); err == nil {
privValidator = sm.LoadPrivValidator(privValidatorFile) privValidator = sm.LoadPrivValidator(privValidatorFile)
log.Info("Loaded PrivValidator", log.Notice("Loaded PrivValidator",
"file", privValidatorFile, "privValidator", privValidator) "file", privValidatorFile, "privValidator", privValidator)
} else { } else {
privValidator = sm.GenPrivValidator() privValidator = sm.GenPrivValidator()
privValidator.SetFile(privValidatorFile) privValidator.SetFile(privValidatorFile)
privValidator.Save() privValidator.Save()
log.Info("Generated PrivValidator", "file", privValidatorFile) log.Notice("Generated PrivValidator", "file", privValidatorFile)
} }
// Generate node PrivKey // Generate node PrivKey
@ -154,7 +154,7 @@ func (n *Node) Start() {
} }
func (n *Node) Stop() { func (n *Node) Stop() {
log.Info("Stopping Node") log.Notice("Stopping Node")
// TODO: gracefully disconnect from peers. // TODO: gracefully disconnect from peers.
n.sw.Stop() n.sw.Stop()
n.book.Stop() n.book.Stop()
@ -171,7 +171,7 @@ func SetFireable(evsw *events.EventSwitch, eventables ...events.Eventable) {
// Add listeners before starting the Node. // Add listeners before starting the Node.
// The first listener is the primary listener (in NodeInfo) // The first listener is the primary listener (in NodeInfo)
func (n *Node) AddListener(l p2p.Listener) { func (n *Node) AddListener(l p2p.Listener) {
log.Info(Fmt("Added %v", l)) log.Notice(Fmt("Added %v", l))
n.sw.AddListener(l) n.sw.AddListener(l)
n.book.AddOurAddress(l.ExternalAddress()) n.book.AddOurAddress(l.ExternalAddress())
} }
@ -199,7 +199,7 @@ func (n *Node) dialSeed(addr *p2p.NetAddress) {
//n.book.MarkAttempt(addr) //n.book.MarkAttempt(addr)
return return
} else { } else {
log.Info("Connected to seed", "peer", peer) log.Notice("Connected to seed", "peer", peer)
n.book.AddAddress(addr, addr) n.book.AddAddress(addr, addr)
} }
} }

18
p2p/addrbook.go
View File

@ -126,7 +126,7 @@ func (a *AddrBook) init() {
func (a *AddrBook) Start() { func (a *AddrBook) Start() {
if atomic.CompareAndSwapUint32(&a.started, 0, 1) { if atomic.CompareAndSwapUint32(&a.started, 0, 1) {
log.Info("Starting AddrBook") log.Notice("Starting AddrBook")
a.loadFromFile(a.filePath) a.loadFromFile(a.filePath)
a.wg.Add(1) a.wg.Add(1)
go a.saveRoutine() go a.saveRoutine()
@ -135,7 +135,7 @@ func (a *AddrBook) Start() {
func (a *AddrBook) Stop() { func (a *AddrBook) Stop() {
if atomic.CompareAndSwapUint32(&a.stopped, 0, 1) { if atomic.CompareAndSwapUint32(&a.stopped, 0, 1) {
log.Info("Stopping AddrBook") log.Notice("Stopping AddrBook")
close(a.quit) close(a.quit)
a.wg.Wait() a.wg.Wait()
} }
@ -144,7 +144,7 @@ func (a *AddrBook) Stop() {
func (a *AddrBook) AddOurAddress(addr *NetAddress) { func (a *AddrBook) AddOurAddress(addr *NetAddress) {
a.mtx.Lock() a.mtx.Lock()
defer a.mtx.Unlock() defer a.mtx.Unlock()
log.Debug("Add our address to book", "addr", addr) log.Info("Add our address to book", "addr", addr)
a.ourAddrs[addr.String()] = addr a.ourAddrs[addr.String()] = addr
} }
@ -159,7 +159,7 @@ func (a *AddrBook) OurAddresses() []*NetAddress {
func (a *AddrBook) AddAddress(addr *NetAddress, src *NetAddress) { func (a *AddrBook) AddAddress(addr *NetAddress, src *NetAddress) {
a.mtx.Lock() a.mtx.Lock()
defer a.mtx.Unlock() defer a.mtx.Unlock()
log.Debug("Add address to book", "addr", addr, "src", src) log.Info("Add address to book", "addr", addr, "src", src)
a.addAddress(addr, src) a.addAddress(addr, src)
} }
@ -379,7 +379,7 @@ out:
for { for {
select { select {
case <-dumpAddressTicker.C: case <-dumpAddressTicker.C:
log.Debug("Saving AddrBook to file", "size", a.Size()) log.Info("Saving AddrBook to file", "size", a.Size())
a.saveToFile(a.filePath) a.saveToFile(a.filePath)
case <-a.quit: case <-a.quit:
break out break out
@ -388,7 +388,7 @@ out:
dumpAddressTicker.Stop() dumpAddressTicker.Stop()
a.saveToFile(a.filePath) a.saveToFile(a.filePath)
a.wg.Done() a.wg.Done()
log.Info("Address handler done") log.Notice("Address handler done")
} }
func (a *AddrBook) getBucket(bucketType byte, bucketIdx int) map[string]*knownAddress { func (a *AddrBook) getBucket(bucketType byte, bucketIdx int) map[string]*knownAddress {
@ -421,7 +421,7 @@ func (a *AddrBook) addToNewBucket(ka *knownAddress, bucketIdx int) bool {
// Enforce max addresses. // Enforce max addresses.
if len(bucket) > newBucketSize { if len(bucket) > newBucketSize {
log.Info("new bucket is full, expiring old ") log.Notice("new bucket is full, expiring old ")
a.expireNew(bucketIdx) a.expireNew(bucketIdx)
} }
@ -549,7 +549,7 @@ func (a *AddrBook) addAddress(addr, src *NetAddress) {
bucket := a.calcNewBucket(addr, src) bucket := a.calcNewBucket(addr, src)
a.addToNewBucket(ka, bucket) a.addToNewBucket(ka, bucket)
log.Info("Added new address", "address", addr, "total", a.size()) log.Notice("Added new address", "address", addr, "total", a.size())
} }
// Make space in the new buckets by expiring the really bad entries. // Make space in the new buckets by expiring the really bad entries.
@ -558,7 +558,7 @@ func (a *AddrBook) expireNew(bucketIdx int) {
for addrStr, ka := range a.addrNew[bucketIdx] { for addrStr, ka := range a.addrNew[bucketIdx] {
// If an entry is bad, throw it away // If an entry is bad, throw it away
if ka.isBad() { if ka.isBad() {
log.Info(Fmt("expiring bad address %v", addrStr)) log.Notice(Fmt("expiring bad address %v", addrStr))
a.removeFromBucket(ka, bucketTypeNew, bucketIdx) a.removeFromBucket(ka, bucketTypeNew, bucketIdx)
return return
} }

28
p2p/connection.go
View File

@ -124,7 +124,7 @@ func NewMConnection(conn net.Conn, chDescs []*ChannelDescriptor, onReceive recei
// .Start() begins multiplexing packets to and from "channels". // .Start() begins multiplexing packets to and from "channels".
func (c *MConnection) Start() { func (c *MConnection) Start() {
if atomic.CompareAndSwapUint32(&c.started, 0, 1) { if atomic.CompareAndSwapUint32(&c.started, 0, 1) {
log.Debug("Starting MConnection", "connection", c) log.Info("Starting MConnection", "connection", c)
go c.sendRoutine() go c.sendRoutine()
go c.recvRoutine() go c.recvRoutine()
} }
@ -132,7 +132,7 @@ func (c *MConnection) Start() {
func (c *MConnection) Stop() { func (c *MConnection) Stop() {
if atomic.CompareAndSwapUint32(&c.stopped, 0, 1) { if atomic.CompareAndSwapUint32(&c.stopped, 0, 1) {
log.Debug("Stopping MConnection", "connection", c) log.Info("Stopping MConnection", "connection", c)
close(c.quit) close(c.quit)
c.conn.Close() c.conn.Close()
c.flushTimer.Stop() c.flushTimer.Stop()
@ -151,7 +151,7 @@ func (c *MConnection) String() string {
} }
func (c *MConnection) flush() { func (c *MConnection) flush() {
log.Debug("Flush", "conn", c) log.Info("Flush", "conn", c)
err := c.bufWriter.Flush() err := c.bufWriter.Flush()
if err != nil { if err != nil {
log.Warn("MConnection flush failed", "error", err) log.Warn("MConnection flush failed", "error", err)
@ -182,7 +182,7 @@ func (c *MConnection) Send(chId byte, msg interface{}) bool {
return false return false
} }
log.Debug("Send", "channel", chId, "connection", c, "msg", msg) //, "bytes", binary.BinaryBytes(msg)) log.Info("Send", "channel", chId, "connection", c, "msg", msg) //, "bytes", binary.BinaryBytes(msg))
// Send message to channel. // Send message to channel.
channel, ok := c.channelsIdx[chId] channel, ok := c.channelsIdx[chId]
@ -211,7 +211,7 @@ func (c *MConnection) TrySend(chId byte, msg interface{}) bool {
return false return false
} }
log.Debug("TrySend", "channel", chId, "connection", c, "msg", msg) log.Info("TrySend", "channel", chId, "connection", c, "msg", msg)
// Send message to channel. // Send message to channel.
channel, ok := c.channelsIdx[chId] channel, ok := c.channelsIdx[chId]
@ -263,12 +263,12 @@ FOR_LOOP:
channel.updateStats() channel.updateStats()
} }
case <-c.pingTimer.Ch: case <-c.pingTimer.Ch:
log.Debug("Send Ping") log.Info("Send Ping")
binary.WriteByte(packetTypePing, c.bufWriter, &n, &err) binary.WriteByte(packetTypePing, c.bufWriter, &n, &err)
c.sendMonitor.Update(int(n)) c.sendMonitor.Update(int(n))
c.flush() c.flush()
case <-c.pong: case <-c.pong:
log.Debug("Send Pong") log.Info("Send Pong")
binary.WriteByte(packetTypePong, c.bufWriter, &n, &err) binary.WriteByte(packetTypePong, c.bufWriter, &n, &err)
c.sendMonitor.Update(int(n)) c.sendMonitor.Update(int(n))
c.flush() c.flush()
@ -339,7 +339,7 @@ func (c *MConnection) sendMsgPacket() bool {
if leastChannel == nil { if leastChannel == nil {
return true return true
} else { } else {
// log.Debug("Found a msgPacket to send") // log.Info("Found a msgPacket to send")
} }
// Make & send a msgPacket from this channel // Make & send a msgPacket from this channel
@ -368,7 +368,7 @@ FOR_LOOP:
/* /*
// Peek into bufReader for debugging // Peek into bufReader for debugging
if numBytes := c.bufReader.Buffered(); numBytes > 0 { if numBytes := c.bufReader.Buffered(); numBytes > 0 {
log.Debug("Peek connection buffer", "numBytes", numBytes, "bytes", log15.Lazy{func() []byte { log.Info("Peek connection buffer", "numBytes", numBytes, "bytes", log15.Lazy{func() []byte {
bytes, err := c.bufReader.Peek(MinInt(numBytes, 100)) bytes, err := c.bufReader.Peek(MinInt(numBytes, 100))
if err == nil { if err == nil {
return bytes return bytes
@ -397,11 +397,11 @@ FOR_LOOP:
switch pktType { switch pktType {
case packetTypePing: case packetTypePing:
// TODO: prevent abuse, as they cause flush()'s. // TODO: prevent abuse, as they cause flush()'s.
log.Debug("Receive Ping") log.Info("Receive Ping")
c.pong <- struct{}{} c.pong <- struct{}{}
case packetTypePong: case packetTypePong:
// do nothing // do nothing
log.Debug("Receive Pong") log.Info("Receive Pong")
case packetTypeMsg: case packetTypeMsg:
pkt, n, err := msgPacket{}, int64(0), error(nil) pkt, n, err := msgPacket{}, int64(0), error(nil)
binary.ReadBinaryPtr(&pkt, c.bufReader, &n, &err) binary.ReadBinaryPtr(&pkt, c.bufReader, &n, &err)
@ -426,7 +426,7 @@ FOR_LOOP:
break FOR_LOOP break FOR_LOOP
} }
if msgBytes != nil { if msgBytes != nil {
log.Debug("Received bytes", "chId", pkt.ChannelId, "msgBytes", msgBytes) log.Info("Received bytes", "chId", pkt.ChannelId, "msgBytes", msgBytes)
c.onReceive(pkt.ChannelId, msgBytes) c.onReceive(pkt.ChannelId, msgBytes)
} }
default: default:
@ -565,7 +565,7 @@ func (ch *Channel) nextMsgPacket() msgPacket {
// Not goroutine-safe // Not goroutine-safe
func (ch *Channel) writeMsgPacketTo(w io.Writer) (n int64, err error) { func (ch *Channel) writeMsgPacketTo(w io.Writer) (n int64, err error) {
packet := ch.nextMsgPacket() packet := ch.nextMsgPacket()
log.Debug("Write Msg Packet", "conn", ch.conn, "packet", packet) log.Info("Write Msg Packet", "conn", ch.conn, "packet", packet)
binary.WriteByte(packetTypeMsg, w, &n, &err) binary.WriteByte(packetTypeMsg, w, &n, &err)
binary.WriteBinary(packet, w, &n, &err) binary.WriteBinary(packet, w, &n, &err)
if err != nil { if err != nil {
@ -577,7 +577,7 @@ func (ch *Channel) writeMsgPacketTo(w io.Writer) (n int64, err error) {
// Handles incoming msgPackets. Returns a msg bytes if msg is complete. // Handles incoming msgPackets. Returns a msg bytes if msg is complete.
// Not goroutine-safe // Not goroutine-safe
func (ch *Channel) recvMsgPacket(packet msgPacket) ([]byte, error) { func (ch *Channel) recvMsgPacket(packet msgPacket) ([]byte, error) {
log.Debug("Read Msg Packet", "conn", ch.conn, "packet", packet) log.Info("Read Msg Packet", "conn", ch.conn, "packet", packet)
if binary.MaxBinaryReadSize < len(ch.recving)+len(packet.Bytes) { if binary.MaxBinaryReadSize < len(ch.recving)+len(packet.Bytes) {
return nil, binary.ErrBinaryReadSizeOverflow return nil, binary.ErrBinaryReadSizeOverflow
} }

12
p2p/listener.go
View File

@ -55,7 +55,7 @@ func NewDefaultListener(protocol string, lAddr string, requireUPNPHairpin bool)
} }
// Actual listener local IP & port // Actual listener local IP & port
listenerIP, listenerPort := splitHostPort(listener.Addr().String()) listenerIP, listenerPort := splitHostPort(listener.Addr().String())
log.Debug("Local listener", "ip", listenerIP, "port", listenerPort) log.Info("Local listener", "ip", listenerIP, "port", listenerPort)
// Determine internal address... // Determine internal address...
var intAddr *NetAddress = NewNetAddressString(lAddr) var intAddr *NetAddress = NewNetAddressString(lAddr)
@ -157,16 +157,16 @@ func (l *DefaultListener) String() string {
// UPNP external address discovery & port mapping // UPNP external address discovery & port mapping
func getUPNPExternalAddress(externalPort, internalPort int) *NetAddress { func getUPNPExternalAddress(externalPort, internalPort int) *NetAddress {
log.Debug("Getting UPNP external address") log.Info("Getting UPNP external address")
nat, err := upnp.Discover() nat, err := upnp.Discover()
if err != nil { if err != nil {
log.Debug("Could not perform UPNP discover", "error", err) log.Info("Could not perform UPNP discover", "error", err)
return nil return nil
} }
ext, err := nat.GetExternalAddress() ext, err := nat.GetExternalAddress()
if err != nil { if err != nil {
log.Debug("Could not get UPNP external address", "error", err) log.Info("Could not get UPNP external address", "error", err)
return nil return nil
} }
@ -177,11 +177,11 @@ func getUPNPExternalAddress(externalPort, internalPort int) *NetAddress {
externalPort, err = nat.AddPortMapping("tcp", externalPort, internalPort, "tendermint", 0) externalPort, err = nat.AddPortMapping("tcp", externalPort, internalPort, "tendermint", 0)
if err != nil { if err != nil {
log.Debug("Could not add UPNP port mapping", "error", err) log.Info("Could not add UPNP port mapping", "error", err)
return nil return nil
} }
log.Debug("Got UPNP external address", "address", ext) log.Info("Got UPNP external address", "address", ext)
return NewNetAddressIPPort(ext, uint16(externalPort)) return NewNetAddressIPPort(ext, uint16(externalPort))
} }

6
p2p/peer.go
View File

@ -35,7 +35,7 @@ func peerHandshake(conn net.Conn, ourNodeInfo *types.NodeInfo) (*types.NodeInfo,
func() { func() {
var n int64 var n int64
binary.ReadBinary(peerNodeInfo, conn, &n, &err2) binary.ReadBinary(peerNodeInfo, conn, &n, &err2)
log.Info("Peer handshake", "peerNodeInfo", peerNodeInfo) log.Notice("Peer handshake", "peerNodeInfo", peerNodeInfo)
}) })
if err1 != nil { if err1 != nil {
return nil, err1 return nil, err1
@ -74,14 +74,14 @@ func newPeer(conn net.Conn, peerNodeInfo *types.NodeInfo, outbound bool, reactor
func (p *Peer) start() { func (p *Peer) start() {
if atomic.CompareAndSwapUint32(&p.running, 0, 1) { if atomic.CompareAndSwapUint32(&p.running, 0, 1) {
log.Debug("Starting Peer", "peer", p) log.Info("Starting Peer", "peer", p)
p.mconn.Start() p.mconn.Start()
} }
} }
func (p *Peer) stop() { func (p *Peer) stop() {
if atomic.CompareAndSwapUint32(&p.running, 1, 0) { if atomic.CompareAndSwapUint32(&p.running, 1, 0) {
log.Debug("Stopping Peer", "peer", p) log.Info("Stopping Peer", "peer", p)
p.mconn.Stop() p.mconn.Stop()
} }
} }

14
p2p/pex_reactor.go
View File

@ -48,7 +48,7 @@ func NewPEXReactor(book *AddrBook) *PEXReactor {
// Implements Reactor // Implements Reactor
func (pexR *PEXReactor) Start(sw *Switch) { func (pexR *PEXReactor) Start(sw *Switch) {
if atomic.CompareAndSwapUint32(&pexR.started, 0, 1) { if atomic.CompareAndSwapUint32(&pexR.started, 0, 1) {
log.Info("Starting PEXReactor") log.Notice("Starting PEXReactor")
pexR.sw = sw pexR.sw = sw
go pexR.ensurePeersRoutine() go pexR.ensurePeersRoutine()
} }
@ -57,7 +57,7 @@ func (pexR *PEXReactor) Start(sw *Switch) {
// Implements Reactor // Implements Reactor
func (pexR *PEXReactor) Stop() { func (pexR *PEXReactor) Stop() {
if atomic.CompareAndSwapUint32(&pexR.stopped, 0, 1) { if atomic.CompareAndSwapUint32(&pexR.stopped, 0, 1) {
log.Info("Stopping PEXReactor") log.Notice("Stopping PEXReactor")
close(pexR.quit) close(pexR.quit)
} }
} }
@ -103,7 +103,7 @@ func (pexR *PEXReactor) Receive(chId byte, src *Peer, msgBytes []byte) {
log.Warn("Error decoding message", "error", err) log.Warn("Error decoding message", "error", err)
return return
} }
log.Info("Received message", "msg", msg) log.Notice("Received message", "msg", msg)
switch msg := msg.(type) { switch msg := msg.(type) {
case *pexRequestMessage: case *pexRequestMessage:
@ -160,7 +160,7 @@ FOR_LOOP:
func (pexR *PEXReactor) ensurePeers() { func (pexR *PEXReactor) ensurePeers() {
numOutPeers, _, numDialing := pexR.sw.NumPeers() numOutPeers, _, numDialing := pexR.sw.NumPeers()
numToDial := minNumOutboundPeers - (numOutPeers + numDialing) numToDial := minNumOutboundPeers - (numOutPeers + numDialing)
log.Debug("Ensure peers", "numOutPeers", numOutPeers, "numDialing", numDialing, "numToDial", numToDial) log.Info("Ensure peers", "numOutPeers", numOutPeers, "numDialing", numDialing, "numToDial", numToDial)
if numToDial <= 0 { if numToDial <= 0 {
return return
} }
@ -183,14 +183,14 @@ func (pexR *PEXReactor) ensurePeers() {
alreadyConnected := pexR.sw.Peers().Has(try.IP.String()) alreadyConnected := pexR.sw.Peers().Has(try.IP.String())
if alreadySelected || alreadyDialing || alreadyConnected { if alreadySelected || alreadyDialing || alreadyConnected {
/* /*
log.Debug("Cannot dial address", "addr", try, log.Info("Cannot dial address", "addr", try,
"alreadySelected", alreadySelected, "alreadySelected", alreadySelected,
"alreadyDialing", alreadyDialing, "alreadyDialing", alreadyDialing,
"alreadyConnected", alreadyConnected) "alreadyConnected", alreadyConnected)
*/ */
continue continue
} else { } else {
log.Debug("Will dial address", "addr", try) log.Info("Will dial address", "addr", try)
picked = try picked = try
break break
} }
@ -216,7 +216,7 @@ func (pexR *PEXReactor) ensurePeers() {
if peers := pexR.sw.Peers().List(); len(peers) > 0 { if peers := pexR.sw.Peers().List(); len(peers) > 0 {
i := rand.Int() % len(peers) i := rand.Int() % len(peers)
peer := peers[i] peer := peers[i]
log.Debug("No addresses to dial. Sending pexRequest to random peer", "peer", peer) log.Info("No addresses to dial. Sending pexRequest to random peer", "peer", peer)
pexR.RequestPEX(peer) pexR.RequestPEX(peer)
} }
} }

24
p2p/switch.go
View File

@ -223,7 +223,7 @@ func (sw *Switch) AddPeerWithConnection(conn net.Conn, outbound bool) (*Peer, er
// Add the peer to .peers // Add the peer to .peers
// ignore if duplicate or if we already have too many for that IP range // ignore if duplicate or if we already have too many for that IP range
if err := sw.peers.Add(peer); err != nil { if err := sw.peers.Add(peer); err != nil {
log.Info("Ignoring peer", "error", err, "peer", peer) log.Notice("Ignoring peer", "error", err, "peer", peer)
peer.mconn.Stop() peer.mconn.Stop()
return nil, err return nil, err
} }
@ -234,7 +234,7 @@ func (sw *Switch) AddPeerWithConnection(conn net.Conn, outbound bool) (*Peer, er
sw.startInitPeer(peer) sw.startInitPeer(peer)
} }
log.Info("Added peer", "peer", peer) log.Notice("Added peer", "peer", peer)
return peer, nil return peer, nil
} }
@ -244,20 +244,20 @@ func (sw *Switch) startInitPeer(peer *Peer) {
} }
func (sw *Switch) DialPeerWithAddress(addr *NetAddress) (*Peer, error) { func (sw *Switch) DialPeerWithAddress(addr *NetAddress) (*Peer, error) {
log.Debug("Dialing address", "address", addr) log.Info("Dialing address", "address", addr)
sw.dialing.Set(addr.IP.String(), addr) sw.dialing.Set(addr.IP.String(), addr)
conn, err := addr.DialTimeout(peerDialTimeoutSeconds * time.Second) conn, err := addr.DialTimeout(peerDialTimeoutSeconds * time.Second)
sw.dialing.Delete(addr.IP.String()) sw.dialing.Delete(addr.IP.String())
if err != nil { if err != nil {
log.Debug("Failed dialing address", "address", addr, "error", err) log.Info("Failed dialing address", "address", addr, "error", err)
return nil, err return nil, err
} }
peer, err := sw.AddPeerWithConnection(conn, true) peer, err := sw.AddPeerWithConnection(conn, true)
if err != nil { if err != nil {
log.Debug("Failed adding peer", "address", addr, "conn", conn, "error", err) log.Info("Failed adding peer", "address", addr, "conn", conn, "error", err)
return nil, err return nil, err
} }
log.Info("Dialed and added peer", "address", addr, "peer", peer) log.Notice("Dialed and added peer", "address", addr, "peer", peer)
return peer, nil return peer, nil
} }
@ -270,7 +270,7 @@ func (sw *Switch) IsDialing(addr *NetAddress) bool {
// which receives success values for each attempted send (false if times out) // which receives success values for each attempted send (false if times out)
func (sw *Switch) Broadcast(chId byte, msg interface{}) chan bool { func (sw *Switch) Broadcast(chId byte, msg interface{}) chan bool {
successChan := make(chan bool, len(sw.peers.List())) successChan := make(chan bool, len(sw.peers.List()))
log.Debug("Broadcast", "channel", chId, "msg", msg) log.Info("Broadcast", "channel", chId, "msg", msg)
for _, peer := range sw.peers.List() { for _, peer := range sw.peers.List() {
go func(peer *Peer) { go func(peer *Peer) {
success := peer.Send(chId, msg) success := peer.Send(chId, msg)
@ -302,7 +302,7 @@ func (sw *Switch) Peers() IPeerSet {
// Disconnect from a peer due to external error. // Disconnect from a peer due to external error.
// TODO: make record depending on reason. // TODO: make record depending on reason.
func (sw *Switch) StopPeerForError(peer *Peer, reason interface{}) { func (sw *Switch) StopPeerForError(peer *Peer, reason interface{}) {
log.Info("Stopping peer for error", "peer", peer, "error", reason) log.Notice("Stopping peer for error", "peer", peer, "error", reason)
sw.peers.Remove(peer) sw.peers.Remove(peer)
peer.stop() peer.stop()
sw.removePeerFromReactors(peer, reason) sw.removePeerFromReactors(peer, reason)
@ -311,7 +311,7 @@ func (sw *Switch) StopPeerForError(peer *Peer, reason interface{}) {
// Disconnect from a peer gracefully. // Disconnect from a peer gracefully.
// TODO: handle graceful disconnects. // TODO: handle graceful disconnects.
func (sw *Switch) StopPeerGracefully(peer *Peer) { func (sw *Switch) StopPeerGracefully(peer *Peer) {
log.Info("Stopping peer gracefully") log.Notice("Stopping peer gracefully")
sw.peers.Remove(peer) sw.peers.Remove(peer)
peer.stop() peer.stop()
sw.removePeerFromReactors(peer, nil) sw.removePeerFromReactors(peer, nil)
@ -338,20 +338,20 @@ func (sw *Switch) listenerRoutine(l Listener) {
// ignore connection if we already have enough // ignore connection if we already have enough
if maxNumPeers <= sw.peers.Size() { if maxNumPeers <= sw.peers.Size() {
log.Debug("Ignoring inbound connection: already have enough peers", "address", inConn.RemoteAddr().String(), "numPeers", sw.peers.Size(), "max", maxNumPeers) log.Info("Ignoring inbound connection: already have enough peers", "address", inConn.RemoteAddr().String(), "numPeers", sw.peers.Size(), "max", maxNumPeers)
continue continue
} }
// Ignore connections from IP ranges for which we have too many // Ignore connections from IP ranges for which we have too many
if sw.peers.HasMaxForIPRange(inConn) { if sw.peers.HasMaxForIPRange(inConn) {
log.Debug("Ignoring inbound connection: already have enough peers for that IP range", "address", inConn.RemoteAddr().String()) log.Info("Ignoring inbound connection: already have enough peers for that IP range", "address", inConn.RemoteAddr().String())
continue continue
} }
// New inbound connection! // New inbound connection!
_, err := sw.AddPeerWithConnection(inConn, false) _, err := sw.AddPeerWithConnection(inConn, false)
if err != nil { if err != nil {
log.Info("Ignoring inbound connection: error on AddPeerWithConnection", "address", inConn.RemoteAddr().String(), "error", err) log.Notice("Ignoring inbound connection: error on AddPeerWithConnection", "address", inConn.RemoteAddr().String(), "error", err)
continue continue
} }

22
p2p/upnp/probe.go
View File

@ -19,19 +19,19 @@ func makeUPNPListener(intPort int, extPort int) (NAT, net.Listener, net.IP, erro
if err != nil { if err != nil {
return nil, nil, nil, errors.New(fmt.Sprintf("NAT upnp could not be discovered: %v", err)) return nil, nil, nil, errors.New(fmt.Sprintf("NAT upnp could not be discovered: %v", err))
} }
log.Debug(Fmt("ourIP: %v", nat.(*upnpNAT).ourIP)) log.Info(Fmt("ourIP: %v", nat.(*upnpNAT).ourIP))
ext, err := nat.GetExternalAddress() ext, err := nat.GetExternalAddress()
if err != nil { if err != nil {
return nat, nil, nil, errors.New(fmt.Sprintf("External address error: %v", err)) return nat, nil, nil, errors.New(fmt.Sprintf("External address error: %v", err))
} }
log.Debug(Fmt("External address: %v", ext)) log.Info(Fmt("External address: %v", ext))
port, err := nat.AddPortMapping("tcp", extPort, intPort, "Tendermint UPnP Probe", 0) port, err := nat.AddPortMapping("tcp", extPort, intPort, "Tendermint UPnP Probe", 0)
if err != nil { if err != nil {
return nat, nil, ext, errors.New(fmt.Sprintf("Port mapping error: %v", err)) return nat, nil, ext, errors.New(fmt.Sprintf("Port mapping error: %v", err))
} }
log.Debug(Fmt("Port mapping mapped: %v", port)) log.Info(Fmt("Port mapping mapped: %v", port))
// also run the listener, open for all remote addresses. // also run the listener, open for all remote addresses.
listener, err := net.Listen("tcp", fmt.Sprintf(":%v", intPort)) listener, err := net.Listen("tcp", fmt.Sprintf(":%v", intPort))
@ -46,17 +46,17 @@ func testHairpin(listener net.Listener, extAddr string) (supportsHairpin bool) {
go func() { go func() {
inConn, err := listener.Accept() inConn, err := listener.Accept()
if err != nil { if err != nil {
log.Info(Fmt("Listener.Accept() error: %v", err)) log.Notice(Fmt("Listener.Accept() error: %v", err))
return return
} }
log.Debug(Fmt("Accepted incoming connection: %v -> %v", inConn.LocalAddr(), inConn.RemoteAddr())) log.Info(Fmt("Accepted incoming connection: %v -> %v", inConn.LocalAddr(), inConn.RemoteAddr()))
buf := make([]byte, 1024) buf := make([]byte, 1024)
n, err := inConn.Read(buf) n, err := inConn.Read(buf)
if err != nil { if err != nil {
log.Info(Fmt("Incoming connection read error: %v", err)) log.Notice(Fmt("Incoming connection read error: %v", err))
return return
} }
log.Debug(Fmt("Incoming connection read %v bytes: %X", n, buf)) log.Info(Fmt("Incoming connection read %v bytes: %X", n, buf))
if string(buf) == "test data" { if string(buf) == "test data" {
supportsHairpin = true supportsHairpin = true
return return
@ -66,16 +66,16 @@ func testHairpin(listener net.Listener, extAddr string) (supportsHairpin bool) {
// Establish outgoing // Establish outgoing
outConn, err := net.Dial("tcp", extAddr) outConn, err := net.Dial("tcp", extAddr)
if err != nil { if err != nil {
log.Info(Fmt("Outgoing connection dial error: %v", err)) log.Notice(Fmt("Outgoing connection dial error: %v", err))
return return
} }
n, err := outConn.Write([]byte("test data")) n, err := outConn.Write([]byte("test data"))
if err != nil { if err != nil {
log.Info(Fmt("Outgoing connection write error: %v", err)) log.Notice(Fmt("Outgoing connection write error: %v", err))
return return
} }
log.Debug(Fmt("Outgoing connection wrote %v bytes", n)) log.Info(Fmt("Outgoing connection wrote %v bytes", n))
// Wait for data receipt // Wait for data receipt
time.Sleep(1 * time.Second) time.Sleep(1 * time.Second)
@ -83,7 +83,7 @@ func testHairpin(listener net.Listener, extAddr string) (supportsHairpin bool) {
} }
func Probe() (caps UPNPCapabilities, err error) { func Probe() (caps UPNPCapabilities, err error) {
log.Debug("Probing for UPnP!") log.Info("Probing for UPnP!")
intPort, extPort := 8001, 8001 intPort, extPort := 8001, 8001

4
rpc/client/client.go
View File

@ -22,7 +22,7 @@ func Call(remote string, method string, params []interface{}, dest interface{})
} }
requestBytes := binary.JSONBytes(request) requestBytes := binary.JSONBytes(request)
requestBuf := bytes.NewBuffer(requestBytes) requestBuf := bytes.NewBuffer(requestBytes)
log.Debug(Fmt("RPC request to %v: %v", remote, string(requestBytes))) log.Info(Fmt("RPC request to %v: %v", remote, string(requestBytes)))
httpResponse, err := http.Post(remote, "text/json", requestBuf) httpResponse, err := http.Post(remote, "text/json", requestBuf)
if err != nil { if err != nil {
return dest, err return dest, err
@ -32,7 +32,7 @@ func Call(remote string, method string, params []interface{}, dest interface{})
if err != nil { if err != nil {
return dest, err return dest, err
} }
log.Debug(Fmt("RPC response: %v", string(responseBytes))) log.Info(Fmt("RPC response: %v", string(responseBytes)))
// Parse response into JSONResponse // Parse response into JSONResponse
response := RPCResponse{} response := RPCResponse{}

2
rpc/core/blocks.go
View File

@ -18,7 +18,7 @@ func BlockchainInfo(minHeight, maxHeight int) (*ctypes.ResponseBlockchainInfo, e
if minHeight == 0 { if minHeight == 0 {
minHeight = MaxInt(1, maxHeight-20) minHeight = MaxInt(1, maxHeight-20)
} }
log.Debug("BlockchainInfoHandler", "maxHeight", maxHeight, "minHeight", minHeight) log.Info("BlockchainInfoHandler", "maxHeight", maxHeight, "minHeight", minHeight)
blockMetas := []*types.BlockMeta{} blockMetas := []*types.BlockMeta{}
for height := maxHeight; height >= minHeight; height-- { for height := maxHeight; height >= minHeight; height-- {

8
rpc/server/handlers.go
View File

@ -114,7 +114,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc) http.HandlerFunc {
return return
} }
returns := rpcFunc.f.Call(args) returns := rpcFunc.f.Call(args)
log.Debug("HTTPJSONRPC", "method", request.Method, "args", args, "returns", returns) log.Info("HTTPJSONRPC", "method", request.Method, "args", args, "returns", returns)
response, err := unreflectResponse(returns) response, err := unreflectResponse(returns)
if err != nil { if err != nil {
WriteRPCResponse(w, NewRPCResponse(nil, err.Error())) WriteRPCResponse(w, NewRPCResponse(nil, err.Error()))
@ -166,7 +166,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc) func(http.ResponseWriter, *http.Request)
return return
} }
returns := rpcFunc.f.Call(args) returns := rpcFunc.f.Call(args)
log.Debug("HTTPRestRPC", "method", r.URL.Path, "args", args, "returns", returns) log.Info("HTTPRestRPC", "method", r.URL.Path, "args", args, "returns", returns)
response, err := unreflectResponse(returns) response, err := unreflectResponse(returns)
if err != nil { if err != nil {
WriteRPCResponse(w, NewRPCResponse(nil, err.Error())) WriteRPCResponse(w, NewRPCResponse(nil, err.Error()))
@ -312,7 +312,7 @@ func (con *WSConnection) read() {
} }
switch req.Type { switch req.Type {
case "subscribe": case "subscribe":
log.Info("New event subscription", "con id", con.id, "event", req.Event) log.Notice("New event subscription", "con id", con.id, "event", req.Event)
con.evsw.AddListenerForEvent(con.id, req.Event, func(msg interface{}) { con.evsw.AddListenerForEvent(con.id, req.Event, func(msg interface{}) {
resp := WSResponse{ resp := WSResponse{
Event: req.Event, Event: req.Event,
@ -388,7 +388,7 @@ func (wm *WebsocketManager) websocketHandler(w http.ResponseWriter, r *http.Requ
// register connection // register connection
con := NewWSConnection(wsConn) con := NewWSConnection(wsConn)
log.Info("New websocket connection", "origin", con.id) log.Notice("New websocket connection", "origin", con.id)
con.Start(wm.evsw) con.Start(wm.evsw)
} }

4
rpc/server/http_server.go
View File

@ -17,7 +17,7 @@ import (
) )
func StartHTTPServer(listenAddr string, handler http.Handler) (net.Listener, error) { func StartHTTPServer(listenAddr string, handler http.Handler) (net.Listener, error) {
log.Info(Fmt("Starting RPC HTTP server on %v", listenAddr)) log.Notice(Fmt("Starting RPC HTTP server on %v", listenAddr))
listener, err := net.Listen("tcp", listenAddr) listener, err := net.Listen("tcp", listenAddr)
if err != nil { if err != nil {
return nil, fmt.Errorf("Failed to listen to %v", listenAddr) return nil, fmt.Errorf("Failed to listen to %v", listenAddr)
@ -84,7 +84,7 @@ func RecoverAndLogHandler(handler http.Handler) http.Handler {
if rww.Status == -1 { if rww.Status == -1 {
rww.Status = 200 rww.Status = 200
} }
log.Debug("Served RPC HTTP response", log.Info("Served RPC HTTP response",
"method", r.Method, "url", r.URL, "method", r.Method, "url", r.URL,
"status", rww.Status, "duration", durationMS, "status", rww.Status, "duration", durationMS,
"remoteAddr", r.RemoteAddr, "remoteAddr", r.RemoteAddr,

58
state/execution.go
View File

@ -119,7 +119,7 @@ func execBlock(s *State, block *types.Block, blockPartsHeader types.PartSetHeade
s.BondedValidators.Iterate(func(index int, val *Validator) bool { s.BondedValidators.Iterate(func(index int, val *Validator) bool {
lastActivityHeight := MaxInt(val.BondHeight, val.LastCommitHeight) lastActivityHeight := MaxInt(val.BondHeight, val.LastCommitHeight)
if lastActivityHeight+validatorTimeoutBlocks < block.Height { if lastActivityHeight+validatorTimeoutBlocks < block.Height {
log.Info("Validator timeout", "validator", val, "height", block.Height) log.Notice("Validator timeout", "validator", val, "height", block.Height)
toTimeout = append(toTimeout, val) toTimeout = append(toTimeout, val)
} }
return false return false
@ -359,7 +359,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
// Validate input // Validate input
inAcc = blockCache.GetAccount(tx.Input.Address) inAcc = blockCache.GetAccount(tx.Input.Address)
if inAcc == nil { if inAcc == nil {
log.Debug(Fmt("Can't find in account %X", tx.Input.Address)) log.Info(Fmt("Can't find in account %X", tx.Input.Address))
return types.ErrTxInvalidAddress return types.ErrTxInvalidAddress
} }
@ -376,24 +376,24 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
// pubKey should be present in either "inAcc" or "tx.Input" // pubKey should be present in either "inAcc" or "tx.Input"
if err := checkInputPubKey(inAcc, tx.Input); err != nil { if err := checkInputPubKey(inAcc, tx.Input); err != nil {
log.Debug(Fmt("Can't find pubkey for %X", tx.Input.Address)) log.Info(Fmt("Can't find pubkey for %X", tx.Input.Address))
return err return err
} }
signBytes := acm.SignBytes(_s.ChainID, tx) signBytes := acm.SignBytes(_s.ChainID, tx)
err := validateInput(inAcc, signBytes, tx.Input) err := validateInput(inAcc, signBytes, tx.Input)
if err != nil { if err != nil {
log.Debug(Fmt("validateInput failed on %X: %v", tx.Input.Address, err)) log.Info(Fmt("validateInput failed on %X: %v", tx.Input.Address, err))
return err return err
} }
if tx.Input.Amount < tx.Fee { if tx.Input.Amount < tx.Fee {
log.Debug(Fmt("Sender did not send enough to cover the fee %X", tx.Input.Address)) log.Info(Fmt("Sender did not send enough to cover the fee %X", tx.Input.Address))
return types.ErrTxInsufficientFunds return types.ErrTxInsufficientFunds
} }
if !createAccount { if !createAccount {
// Validate output // Validate output
if len(tx.Address) != 20 { if len(tx.Address) != 20 {
log.Debug(Fmt("Destination address is not 20 bytes %X", tx.Address)) log.Info(Fmt("Destination address is not 20 bytes %X", tx.Address))
return types.ErrTxInvalidAddress return types.ErrTxInvalidAddress
} }
// this may be nil if we are still in mempool and contract was created in same block as this tx // this may be nil if we are still in mempool and contract was created in same block as this tx
@ -403,7 +403,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
outAcc = blockCache.GetAccount(tx.Address) outAcc = blockCache.GetAccount(tx.Address)
} }
log.Debug(Fmt("Out account: %v", outAcc)) log.Info(Fmt("Out account: %v", outAcc))
// Good! // Good!
value := tx.Input.Amount - tx.Fee value := tx.Input.Amount - tx.Fee
@ -445,22 +445,22 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
inAcc.Balance -= tx.Fee inAcc.Balance -= tx.Fee
blockCache.UpdateAccount(inAcc) blockCache.UpdateAccount(inAcc)
if outAcc == nil { if outAcc == nil {
log.Debug(Fmt("Cannot find destination address %X. Deducting fee from caller", tx.Address)) log.Info(Fmt("Cannot find destination address %X. Deducting fee from caller", tx.Address))
} else { } else {
log.Debug(Fmt("Attempting to call an account (%X) with no code. Deducting fee from caller", tx.Address)) log.Info(Fmt("Attempting to call an account (%X) with no code. Deducting fee from caller", tx.Address))
} }
return types.ErrTxInvalidAddress return types.ErrTxInvalidAddress
} }
} }
callee = toVMAccount(outAcc) callee = toVMAccount(outAcc)
code = callee.Code code = callee.Code
log.Debug(Fmt("Calling contract %X with code %X", callee.Address, callee.Code)) log.Info(Fmt("Calling contract %X with code %X", callee.Address, callee.Code))
} else { } else {
callee = txCache.CreateAccount(caller) callee = txCache.CreateAccount(caller)
log.Debug(Fmt("Created new account %X", callee.Address)) log.Info(Fmt("Created new account %X", callee.Address))
code = tx.Data code = tx.Data
} }
log.Debug(Fmt("Code for this contract: %X", code)) log.Info(Fmt("Code for this contract: %X", code))
txCache.UpdateAccount(caller) // because we bumped nonce txCache.UpdateAccount(caller) // because we bumped nonce
txCache.UpdateAccount(callee) // so the txCache knows about the callee and the create and/or transfer takes effect txCache.UpdateAccount(callee) // so the txCache knows about the callee and the create and/or transfer takes effect
@ -474,12 +474,12 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
if err != nil { if err != nil {
exception = err.Error() exception = err.Error()
// Failure. Charge the gas fee. The 'value' was otherwise not transferred. // Failure. Charge the gas fee. The 'value' was otherwise not transferred.
log.Debug(Fmt("Error on execution: %v", err)) log.Info(Fmt("Error on execution: %v", err))
inAcc.Balance -= tx.Fee inAcc.Balance -= tx.Fee
blockCache.UpdateAccount(inAcc) blockCache.UpdateAccount(inAcc)
// Throw away 'txCache' which holds incomplete updates (don't sync it). // Throw away 'txCache' which holds incomplete updates (don't sync it).
} else { } else {
log.Debug("Successful execution") log.Info("Successful execution")
// Success // Success
if createAccount { if createAccount {
callee.Code = ret callee.Code = ret
@ -488,7 +488,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
txCache.Sync() txCache.Sync()
} }
// Create a receipt from the ret and whether errored. // Create a receipt from the ret and whether errored.
log.Info("VM call complete", "caller", caller, "callee", callee, "return", ret, "err", err) log.Notice("VM call complete", "caller", caller, "callee", callee, "return", ret, "err", err)
// Fire Events for sender and receiver // Fire Events for sender and receiver
// a separate event will be fired from vm for each additional call // a separate event will be fired from vm for each additional call
@ -516,7 +516,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
// Validate input // Validate input
inAcc = blockCache.GetAccount(tx.Input.Address) inAcc = blockCache.GetAccount(tx.Input.Address)
if inAcc == nil { if inAcc == nil {
log.Debug(Fmt("Can't find in account %X", tx.Input.Address)) log.Info(Fmt("Can't find in account %X", tx.Input.Address))
return types.ErrTxInvalidAddress return types.ErrTxInvalidAddress
} }
// check permission // check permission
@ -525,24 +525,24 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
} }
// pubKey should be present in either "inAcc" or "tx.Input" // pubKey should be present in either "inAcc" or "tx.Input"
if err := checkInputPubKey(inAcc, tx.Input); err != nil { if err := checkInputPubKey(inAcc, tx.Input); err != nil {
log.Debug(Fmt("Can't find pubkey for %X", tx.Input.Address)) log.Info(Fmt("Can't find pubkey for %X", tx.Input.Address))
return err return err
} }
signBytes := acm.SignBytes(_s.ChainID, tx) signBytes := acm.SignBytes(_s.ChainID, tx)
err := validateInput(inAcc, signBytes, tx.Input) err := validateInput(inAcc, signBytes, tx.Input)
if err != nil { if err != nil {
log.Debug(Fmt("validateInput failed on %X: %v", tx.Input.Address, err)) log.Info(Fmt("validateInput failed on %X: %v", tx.Input.Address, err))
return err return err
} }
// fee is in addition to the amount which is used to determine the TTL // fee is in addition to the amount which is used to determine the TTL
if tx.Input.Amount < tx.Fee { if tx.Input.Amount < tx.Fee {
log.Debug(Fmt("Sender did not send enough to cover the fee %X", tx.Input.Address)) log.Info(Fmt("Sender did not send enough to cover the fee %X", tx.Input.Address))
return types.ErrTxInsufficientFunds return types.ErrTxInsufficientFunds
} }
// validate the input strings // validate the input strings
if err := tx.ValidateStrings(); err != nil { if err := tx.ValidateStrings(); err != nil {
log.Debug(err.Error()) log.Info(err.Error())
return types.ErrTxInvalidString return types.ErrTxInvalidString
} }
@ -553,7 +553,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
expiresIn := int(value / costPerBlock) expiresIn := int(value / costPerBlock)
lastBlockHeight := _s.LastBlockHeight lastBlockHeight := _s.LastBlockHeight
log.Debug("New NameTx", "value", value, "costPerBlock", costPerBlock, "expiresIn", expiresIn, "lastBlock", lastBlockHeight) log.Info("New NameTx", "value", value, "costPerBlock", costPerBlock, "expiresIn", expiresIn, "lastBlock", lastBlockHeight)
// check if the name exists // check if the name exists
entry := blockCache.GetNameRegEntry(tx.Name) entry := blockCache.GetNameRegEntry(tx.Name)
@ -564,7 +564,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
if entry.Expires > lastBlockHeight { if entry.Expires > lastBlockHeight {
// ensure we are owner // ensure we are owner
if bytes.Compare(entry.Owner, tx.Input.Address) != 0 { if bytes.Compare(entry.Owner, tx.Input.Address) != 0 {
log.Debug(Fmt("Sender %X is trying to update a name (%s) for which he is not owner", tx.Input.Address, tx.Name)) log.Info(Fmt("Sender %X is trying to update a name (%s) for which he is not owner", tx.Input.Address, tx.Name))
return types.ErrIncorrectOwner return types.ErrIncorrectOwner
} }
} else { } else {
@ -575,7 +575,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
if value == 0 && len(tx.Data) == 0 { if value == 0 && len(tx.Data) == 0 {
// maybe we reward you for telling us we can delete this crap // maybe we reward you for telling us we can delete this crap
// (owners if not expired, anyone if expired) // (owners if not expired, anyone if expired)
log.Debug("Removing namereg entry", "name", entry.Name) log.Info("Removing namereg entry", "name", entry.Name)
blockCache.RemoveNameRegEntry(entry.Name) blockCache.RemoveNameRegEntry(entry.Name)
} else { } else {
// update the entry by bumping the expiry // update the entry by bumping the expiry
@ -586,7 +586,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
} }
entry.Expires = lastBlockHeight + expiresIn entry.Expires = lastBlockHeight + expiresIn
entry.Owner = tx.Input.Address entry.Owner = tx.Input.Address
log.Debug("An old namereg entry has expired and been reclaimed", "name", entry.Name, "expiresIn", expiresIn, "owner", entry.Owner) log.Info("An old namereg entry has expired and been reclaimed", "name", entry.Name, "expiresIn", expiresIn, "owner", entry.Owner)
} else { } else {
// since the size of the data may have changed // since the size of the data may have changed
// we use the total amount of "credit" // we use the total amount of "credit"
@ -597,7 +597,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
return errors.New(Fmt("Names must be registered for at least %d blocks", types.MinNameRegistrationPeriod)) return errors.New(Fmt("Names must be registered for at least %d blocks", types.MinNameRegistrationPeriod))
} }
entry.Expires = lastBlockHeight + expiresIn entry.Expires = lastBlockHeight + expiresIn
log.Debug("Updated namereg entry", "name", entry.Name, "expiresIn", expiresIn, "oldCredit", oldCredit, "value", value, "credit", credit) log.Info("Updated namereg entry", "name", entry.Name, "expiresIn", expiresIn, "oldCredit", oldCredit, "value", value, "credit", credit)
} }
entry.Data = tx.Data entry.Data = tx.Data
blockCache.UpdateNameRegEntry(entry) blockCache.UpdateNameRegEntry(entry)
@ -613,7 +613,7 @@ func ExecTx(blockCache *BlockCache, tx types.Tx, runCall bool, evc events.Fireab
Data: tx.Data, Data: tx.Data,
Expires: lastBlockHeight + expiresIn, Expires: lastBlockHeight + expiresIn,
} }
log.Debug("Creating namereg entry", "name", entry.Name, "expiresIn", expiresIn) log.Info("Creating namereg entry", "name", entry.Name, "expiresIn", expiresIn)
blockCache.UpdateNameRegEntry(entry) blockCache.UpdateNameRegEntry(entry)
} }
@ -824,14 +824,14 @@ func HasPermission(state AccountGetter, acc *acm.Account, perm ptypes.PermFlag)
v, err := acc.Permissions.Base.Get(perm) v, err := acc.Permissions.Base.Get(perm)
if _, ok := err.(ptypes.ErrValueNotSet); ok { if _, ok := err.(ptypes.ErrValueNotSet); ok {
log.Debug("Account does not have permission", "account", acc, "accPermissions", acc.Permissions, "perm", perm) log.Info("Account does not have permission", "account", acc, "accPermissions", acc.Permissions, "perm", perm)
if state == nil { if state == nil {
panic("All known global permissions should be set!") panic("All known global permissions should be set!")
} }
log.Debug("Querying GlobalPermissionsAddress") log.Info("Querying GlobalPermissionsAddress")
return HasPermission(nil, state.GetAccount(ptypes.GlobalPermissionsAddress), perm) return HasPermission(nil, state.GetAccount(ptypes.GlobalPermissionsAddress), perm)
} else { } else {
log.Debug("Account has permission", "account", acc, "accPermissions", acc.Permissions, "perm", perm) log.Info("Account has permission", "account", acc, "accPermissions", acc.Permissions, "perm", perm)
} }
return v return v
} }