diff --git a/common/dag/dispatcher.go b/common/dag/dispatcher.go index 6b56e30fa..d3761617e 100644 --- a/common/dag/dispatcher.go +++ b/common/dag/dispatcher.go @@ -19,6 +19,7 @@ import ( "time" "github.com/nebulasio/go-nebulas/util/logging" + "github.com/sirupsen/logrus" ) //type value interface{} @@ -76,7 +77,7 @@ func NewDispatcher(dag *Dag, concurrency int, elapseInMs int64, context interfac // Run dag dispatch goroutine. func (dp *Dispatcher) Run() error { - logging.VLog().Info("Starting Dag Dispatcher...") + logging.VLog().Debug("Starting Dag Dispatcher...") vertices := dp.dag.GetNodes() @@ -132,6 +133,9 @@ func (dp *Dispatcher) execute() error { } else { isFinish, err := dp.onCompleteParentTask(msg) if err != nil { + logging.VLog().WithFields(logrus.Fields{ + "err": err, + }).Debug("Stoped Dag Dispatcher.") dp.Stop() } if isFinish { diff --git a/core/block.go b/core/block.go index ac6764145..bc8eb6d89 100644 --- a/core/block.go +++ b/core/block.go @@ -198,7 +198,7 @@ func (block *Block) FromProto(msg proto.Message) error { logging.VLog().WithFields(logrus.Fields{ "blockHeight": msg.Height, "compatibleHeight": RandomAvailableHeight, - }).Debug("No random found in block header.") + }).Info("No random found in block header.") return ErrInvalidProtoToBlockHeader } block.transactions = make(Transactions, len(msg.Transactions)) @@ -552,7 +552,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to giveback the tx.") + }).Info("Failed to giveback the tx.") } return } @@ -566,7 +566,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to prepare tx.") + }).Info("Failed to prepare tx.") failed++ if err := pool.Push(tx); err != nil { @@ -574,7 +574,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to giveback the tx.") + }).Info("Failed to giveback the tx.") } fromBlacklist.Delete(tx.from.address.Hex()) @@ -592,7 +592,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to close tx.") + }).Info("Failed to close tx.") } }() @@ -624,7 +624,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to giveback the tx.") + }).Info("Failed to giveback the tx.") } } if err == ErrLargeTransactionNonce { @@ -656,7 +656,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to giveback the tx.") + }).Info("Failed to giveback the tx.") } return } @@ -670,7 +670,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "err": err, "giveback": giveback, "dependency": dependency, - }).Debug("CheckAndUpdate invalid tx.") + }).Info("CheckAndUpdate invalid tx.") unpacked++ conflict++ @@ -679,7 +679,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "block": block, "tx": tx, "err": err, - }).Debug("Failed to giveback the tx.") + }).Info("Failed to giveback the tx.") } fromBlacklist.Delete(tx.from.address.Hex()) @@ -753,7 +753,7 @@ func (block *Block) CollectTransactions(deadlineInMs int64) { "core-packing": execute + prepare + update, "packed": len(block.transactions), "dag": block.dependency, - }).Debug("CollectTransactions") + }).Info("CollectTransactions") } // Sealed return true if block seals. Otherwise return false. @@ -861,7 +861,7 @@ func (block *Block) VerifyExecution() error { "diff-verify": commitAt - executedAt, "block": block, "txs": len(block.Transactions()), - }).Debug("Verify txs.") + }).Info("Verify txs.") return nil } @@ -878,7 +878,7 @@ func (block *Block) VerifyIntegrity(chainID uint32, consensus Consensus) error { logging.VLog().WithFields(logrus.Fields{ "expect": chainID, "actual": block.header.chainID, - }).Debug("Failed to check chainid.") + }).Info("Failed to check chainid.") metricsInvalidBlock.Inc(1) return ErrInvalidChainID } @@ -889,7 +889,7 @@ func (block *Block) VerifyIntegrity(chainID uint32, consensus Consensus) error { logging.VLog().WithFields(logrus.Fields{ "tx": tx, "err": err, - }).Debug("Failed to verify tx's integrity.") + }).Info("Failed to verify tx's integrity.") metricsInvalidBlock.Inc(1) return err } @@ -905,7 +905,7 @@ func (block *Block) VerifyIntegrity(chainID uint32, consensus Consensus) error { "expect": wantedHash, "actual": block.Hash(), "err": err, - }).Debug("Failed to check block's hash.") + }).Info("Failed to check block's hash.") metricsInvalidBlock.Inc(1) return ErrInvalidBlockHash } @@ -915,7 +915,7 @@ func (block *Block) VerifyIntegrity(chainID uint32, consensus Consensus) error { logging.VLog().WithFields(logrus.Fields{ "block": block, "err": err, - }).Debug("Failed to verify block.") + }).Info("Failed to verify block.") metricsInvalidBlock.Inc(1) return err } @@ -930,7 +930,7 @@ func (block *Block) verifyState() error { logging.VLog().WithFields(logrus.Fields{ "expect": block.StateRoot(), "actual": block.WorldState().AccountsRoot(), - }).Debug("Failed to verify state.") + }).Info("Failed to verify state.") return ErrInvalidBlockStateRoot } @@ -939,7 +939,7 @@ func (block *Block) verifyState() error { logging.VLog().WithFields(logrus.Fields{ "expect": block.TxsRoot(), "actual": block.WorldState().TxsRoot(), - }).Debug("Failed to verify txs.") + }).Info("Failed to verify txs.") return ErrInvalidBlockTxsRoot } @@ -948,7 +948,7 @@ func (block *Block) verifyState() error { logging.VLog().WithFields(logrus.Fields{ "expect": block.EventsRoot(), "actual": block.WorldState().EventsRoot(), - }).Debug("Failed to verify events.") + }).Info("Failed to verify events.") return ErrInvalidBlockEventsRoot } @@ -957,7 +957,7 @@ func (block *Block) verifyState() error { logging.VLog().WithFields(logrus.Fields{ "expect": block.ConsensusRoot(), "actual": block.WorldState().ConsensusRoot(), - }).Debug("Failed to verify dpos context.") + }).Info("Failed to verify dpos context.") return ErrInvalidBlockConsensusRoot } return nil @@ -990,6 +990,11 @@ func (block *Block) execute() error { return ErrInvalidDagBlock } tx := block.transactions[idx] + + logging.VLog().WithFields(logrus.Fields{ + "tx.hash": tx.hash, + }).Debug("execute tx.") + metricsTxExecute.Mark(1) mergeCh <- true @@ -1024,7 +1029,7 @@ func (block *Block) execute() error { "dag": block.dependency.String(), "txs": transactions, "err": err, - }).Debug("Failed to verify txs in block.") + }).Info("Failed to verify txs in block.") return err } end := time.Now().UnixNano() @@ -1094,7 +1099,7 @@ func (block *Block) FetchExecutionResultEvent(txHash byteutils.Hash) (*state.Eve logging.VLog().WithFields(logrus.Fields{ "tx": txHash, "events": events, - }).Debug("Failed to locate the result event") + }).Info("Failed to locate the result event") return nil, ErrInvalidTransactionResultEvent } return event, nil @@ -1158,7 +1163,7 @@ func (block *Block) ExecuteTransaction(tx *Transaction, ws WorldState) (bool, er logging.VLog().WithFields(logrus.Fields{ "tx": tx, "err": err, - }).Debug("Failed to check transaction") + }).Info("Failed to check transaction") return giveback, err } @@ -1166,7 +1171,7 @@ func (block *Block) ExecuteTransaction(tx *Transaction, ws WorldState) (bool, er logging.VLog().WithFields(logrus.Fields{ "tx": tx, "err": err, - }).Debug("Failed to verify transaction execution") + }).Info("Failed to verify transaction execution") return giveback, err } @@ -1174,7 +1179,7 @@ func (block *Block) ExecuteTransaction(tx *Transaction, ws WorldState) (bool, er logging.VLog().WithFields(logrus.Fields{ "tx": tx, "err": err, - }).Debug("Failed to accept transaction") + }).Info("Failed to accept transaction") return giveback, err } diff --git a/core/transaction.go b/core/transaction.go index 21dbe0d46..a20acf9bd 100644 --- a/core/transaction.go +++ b/core/transaction.go @@ -265,6 +265,22 @@ func (tx *Transaction) String() string { ) } +func (tx *Transaction) StringWithoutData() string { + return fmt.Sprintf(`{"chainID":%d, "hash":"%s", "from":"%s", "to":"%s", "nonce":%d, "value":"%s", "timestamp":%d, "gasprice": "%s", "gaslimit":"%s", "type":"%s"}`, + tx.chainID, + tx.hash.String(), + tx.from.String(), + tx.to.String(), + tx.nonce, + tx.value.String(), + tx.timestamp, + tx.gasPrice.String(), + tx.gasLimit.String(), + tx.Data(), + tx.Type(), + ) +} + // JSONString of transaction func (tx *Transaction) JSONString() string { txJSONObj := make(map[string]interface{}) @@ -391,7 +407,7 @@ func submitTx(tx *Transaction, block *Block, ws WorldState, "err": exeErr, "block": block, "transaction": tx, - }).Debug(exeErrTy) + }).Info(exeErrTy) metricsTxExeFailed.Mark(1) } else { metricsTxExeSuccess.Mark(1) diff --git a/core/transaction_pool.go b/core/transaction_pool.go index d73ed668b..1d237f55f 100644 --- a/core/transaction_pool.go +++ b/core/transaction_pool.go @@ -226,7 +226,7 @@ func (pool *TransactionPool) GetTransaction(hash byteutils.Hash) *Transaction { func (pool *TransactionPool) PushAndRelay(tx *Transaction) error { if err := pool.Push(tx); err != nil { logging.VLog().WithFields(logrus.Fields{ - "tx": tx, + "tx": tx.StringWithoutData(), "err": err, }).Debug("Failed to push tx") return err @@ -241,7 +241,7 @@ func (pool *TransactionPool) PushAndRelay(tx *Transaction) error { func (pool *TransactionPool) PushAndBroadcast(tx *Transaction) error { if err := pool.Push(tx); err != nil { logging.VLog().WithFields(logrus.Fields{ - "tx": tx, + "tx": tx.StringWithoutData(), "err": err, }).Debug("Failed to push tx") return err @@ -271,7 +271,7 @@ func (pool *TransactionPool) Push(tx *Transaction) error { keyword = strings.ToLower(keyword) if strings.Contains(data, keyword) { logging.VLog().WithFields(logrus.Fields{ - "tx": tx, + "tx.hash": tx.hash, "unsupportedKeyword": keyword, }).Debug("transaction data has unsupported keyword") unsupportedKeywordError := fmt.Sprintf("transaction data has unsupported keyword(keyword: %s)", keyword) @@ -316,7 +316,7 @@ func (pool *TransactionPool) Push(tx *Transaction) error { pool.dropTx() logging.VLog().WithFields(logrus.Fields{ - "tx": tx, + "tx": tx.StringWithoutData(), "size": pool.size, "bpoolsize": poollen, "apoolsize": len(pool.all), @@ -524,7 +524,7 @@ func (pool *TransactionPool) evictExpiredTransactions() { "size": pool.size, "poolsize": len(pool.all), "bucketsize": len(pool.buckets), - "tx": tx, + "tx": tx.StringWithoutData(), }).Debug("Remove expired transactions.") // trigger pending transaction event := &state.Event{ diff --git a/rpc/api_service.go b/rpc/api_service.go index df5ce25b8..24648740f 100644 --- a/rpc/api_service.go +++ b/rpc/api_service.go @@ -256,16 +256,18 @@ func handleTransactionResponse(neb core.Neblet, tx *core.Transaction) (resp *rpc } // check Balance Simulate - if tx.Nonce() == (acc.Nonce() + 1) { - result, err := neb.BlockChain().SimulateTransactionExecution(tx) - if err != nil { - return nil, err - } + /* + if tx.Nonce() == (acc.Nonce() + 1) { + result, err := neb.BlockChain().SimulateTransactionExecution(tx) + if err != nil { + return nil, err + } - if result.Err != nil { - return nil, result.Err + if result.Err != nil { + return nil, result.Err + } } - } + */ if tx.Type() == core.TxPayloadDeployType { if !tx.From().Equals(tx.To()) { diff --git a/rpc/log_interceptor.go b/rpc/log_interceptor.go index 5b42cb180..f711be7e1 100644 --- a/rpc/log_interceptor.go +++ b/rpc/log_interceptor.go @@ -37,6 +37,7 @@ func loggingStream(srv interface{}, ss grpc.ServerStream, info *grpc.StreamServe func loggingUnary(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (resp interface{}, err error) { logging.VLog().WithFields(logrus.Fields{ "method": info.FullMethod, + "params": req, }).Info("Rpc request.") metricsRPCCounter.Mark(1)