# Logging

Logging adds detail and allows the node operator to better identify what they are looking for. Tendermint supports log levels on a global and per-module basis. This allows the node operator to see only the information they need and the developer to hone in on specific changes they are working on.

# Configuring Log Levels

There are three log levels, info, debug and error. These can be configured either through the command line via tendermint start --log-level "" or within the config.toml file.

  • info Info represents an informational message. It is used to show that modules have started, stopped and how they are functioning.
  • debug Debug is used to trace various calls or problems. Debug is used widely throughout a codebase and can lead to overly verbose logging.
  • error Error represents something that has gone wrong. An error log can represent a potential problem that can lead to a node halt.

Within the config.toml:

Copy # Output level for logging, including package level options log-level = "info"

Via the command line:

Copy tendermint start --log-level "info"

# List of modules

Here is the list of modules you may encounter in Tendermint's log and a little overview what they do.

  • abci-client As mentioned in Application Architecture Guide, Tendermint acts as an ABCI client with respect to the application and maintains 3 connections: mempool, consensus and query. The code used by Tendermint Core can be found here (opens new window).
  • blockchain Provides storage, pool (a group of peers), and reactor for both storing and exchanging blocks between peers.
  • consensus The heart of Tendermint core, which is the implementation of the consensus algorithm. Includes two "submodules": wal (write-ahead logging) for ensuring data integrity and replay to replay blocks and messages on recovery from a crash. here (opens new window). You can subscribe to them by calling subscribe RPC method. Refer to RPC docs for additional information.
  • mempool Mempool module handles all incoming transactions, whenever they are coming from peers or the application.
  • p2p Provides an abstraction around peer-to-peer communication. For more details, please check out the README (opens new window).
  • rpc-server RPC server. For implementation details, please read the doc.go (opens new window).
  • state Represents the latest state and execution submodule, which executes blocks against the application.
  • statesync Provides a way to quickly sync a node with pruned history.

# Walkabout example

We first create three connections (mempool, consensus and query) to the application (running kvstore locally in this case).

Copy I[10-04|13:54:27.364] Starting multiAppConn module=proxy impl=multiAppConn I[10-04|13:54:27.366] Starting localClient module=abci-client connection=query impl=localClient I[10-04|13:54:27.366] Starting localClient module=abci-client connection=mempool impl=localClient I[10-04|13:54:27.367] Starting localClient module=abci-client connection=consensus impl=localClient

Then Tendermint Core and the application perform a handshake.

Copy I[10-04|13:54:27.367] ABCI Handshake module=consensus appHeight=90 appHash=E0FBAFBF6FCED8B9786DDFEB1A0D4FA2501BADAD I[10-04|13:54:27.368] ABCI Replay Blocks module=consensus appHeight=90 storeHeight=90 stateHeight=90 I[10-04|13:54:27.368] Completed ABCI Handshake - Tendermint and App are synced module=consensus appHeight=90 appHash=E0FBAFBF6FCED8B9786DDFEB1A0D4FA2501BADAD

After that, we start a few more things like the event switch, reactors, and perform UPNP discover in order to detect the IP address.

Copy I[10-04|13:54:27.374] Starting EventSwitch module=types impl=EventSwitch I[10-04|13:54:27.375] This node is a validator module=consensus I[10-04|13:54:27.379] Starting Node module=main impl=Node I[10-04|13:54:27.381] Local listener module=p2p ip=:: port=26656 I[10-04|13:54:27.382] Getting UPNP external address module=p2p I[10-04|13:54:30.386] Could not perform UPNP discover module=p2p err="write udp4> i/o timeout" I[10-04|13:54:30.386] Starting DefaultListener module=p2p impl=Listener(@ I[10-04|13:54:30.387] Starting P2P Switch module=p2p impl="P2P Switch" I[10-04|13:54:30.387] Starting MempoolReactor module=mempool impl=MempoolReactor I[10-04|13:54:30.387] Starting BlockchainReactor module=blockchain impl=BlockchainReactor I[10-04|13:54:30.387] Starting ConsensusReactor module=consensus impl=ConsensusReactor I[10-04|13:54:30.387] ConsensusReactor module=consensus fastSync=false I[10-04|13:54:30.387] Starting ConsensusState module=consensus impl=ConsensusState I[10-04|13:54:30.387] Starting WAL module=consensus wal=/home/vagrant/.tendermint/data/cs.wal/wal impl=WAL I[10-04|13:54:30.388] Starting TimeoutTicker module=consensus impl=TimeoutTicker

Notice the second row where Tendermint Core reports that "This node is a validator". It also could be just an observer (regular node).

Next we replay all the messages from the WAL.

Copy I[10-04|13:54:30.390] Catchup by replaying consensus messages module=consensus height=91 I[10-04|13:54:30.390] Replay: New Step module=consensus height=91 round=0 step=RoundStepNewHeight I[10-04|13:54:30.390] Replay: Done module=consensus

"Started node" message signals that everything is ready for work.

Copy I[10-04|13:54:30.391] Starting RPC HTTP server on tcp socket module=rpc-server I[10-04|13:54:30.392] Started node module=main nodeInfo="NodeInfo{id: DF22D7C92C91082324A1312F092AA1DA197FA598DBBFB6526E, moniker: anonymous, network: test-chain-3MNw2N [remote , listen], version: 0.11.0-10f361fc ([wire_version=0.6.2 p2p_version=0.5.0 consensus_version=v1/0.2.2 rpc_version=0.7.0/3 tx_index=on rpc_addr=tcp://])}"

Next follows a standard block creation cycle, where we enter a new round, propose a block, receive more than 2/3 of prevotes, then precommits and finally have a chance to commit a block. For details, please refer to Byzantine Consensus Algorithm (opens new window).

Copy I[10-04|13:54:30.393] enterNewRound(91/0). Current: 91/0/RoundStepNewHeight module=consensus I[10-04|13:54:30.393] enterPropose(91/0). Current: 91/0/RoundStepNewRound module=consensus I[10-04|13:54:30.393] enterPropose: Our turn to propose module=consensus proposer=125B0E3C5512F5C2B0E1109E31885C4511570C42 privValidator="PrivValidator{125B0E3C5512F5C2B0E1109E31885C4511570C42 LH:90, LR:0, LS:3}" I[10-04|13:54:30.394] Signed proposal module=consensus height=91 round=0 proposal="Proposal{91/0 1:21B79872514F (-1,:0:000000000000) {/10EDEDD7C84E.../}}" I[10-04|13:54:30.397] Received complete proposal block module=consensus height=91 hash=F671D562C7B9242900A286E1882EE64E5556FE9E I[10-04|13:54:30.397] enterPrevote(91/0). Current: 91/0/RoundStepPropose module=consensus I[10-04|13:54:30.397] enterPrevote: ProposalBlock is valid module=consensus height=91 round=0 I[10-04|13:54:30.398] Signed and pushed vote module=consensus height=91 round=0 vote="Vote{0:125B0E3C5512 91/00/1(Prevote) F671D562C7B9 {/89047FFC21D8.../}}" err=null I[10-04|13:54:30.401] Added to prevote module=consensus vote="Vote{0:125B0E3C5512 91/00/1(Prevote) F671D562C7B9 {/89047FFC21D8.../}}" prevotes="VoteSet{H:91 R:0 T:1 +2/3:F671D562C7B9242900A286E1882EE64E5556FE9E:1:21B79872514F BA{1:X} map[]}" I[10-04|13:54:30.401] enterPrecommit(91/0). Current: 91/0/RoundStepPrevote module=consensus I[10-04|13:54:30.401] enterPrecommit: +2/3 prevoted proposal block. Locking module=consensus hash=F671D562C7B9242900A286E1882EE64E5556FE9E I[10-04|13:54:30.402] Signed and pushed vote module=consensus height=91 round=0 vote="Vote{0:125B0E3C5512 91/00/2(Precommit) F671D562C7B9 {/80533478E41A.../}}" err=null I[10-04|13:54:30.404] Added to precommit module=consensus vote="Vote{0:125B0E3C5512 91/00/2(Precommit) F671D562C7B9 {/80533478E41A.../}}" precommits="VoteSet{H:91 R:0 T:2 +2/3:F671D562C7B9242900A286E1882EE64E5556FE9E:1:21B79872514F BA{1:X} map[]}" I[10-04|13:54:30.404] enterCommit(91/0). Current: 91/0/RoundStepPrecommit module=consensus I[10-04|13:54:30.405] Finalizing commit of block with 0 txs module=consensus height=91 hash=F671D562C7B9242900A286E1882EE64E5556FE9E root=E0FBAFBF6FCED8B9786DDFEB1A0D4FA2501BADAD I[10-04|13:54:30.405] Block{ Header{ ChainID: test-chain-3MNw2N Height: 91 Time: 2017-10-04 13:54:30.393 +0000 UTC NumTxs: 0 LastBlockID: F15AB8BEF9A6AAB07E457A6E16BC410546AA4DC6:1:D505DA273544 LastCommit: 56FEF2EFDB8B37E9C6E6D635749DF3169D5F005D Data: Validators: CE25FBFF2E10C0D51AA1A07C064A96931BC8B297 App: E0FBAFBF6FCED8B9786DDFEB1A0D4FA2501BADAD }#F671D562C7B9242900A286E1882EE64E5556FE9E Data{ }# Commit{ BlockID: F15AB8BEF9A6AAB07E457A6E16BC410546AA4DC6:1:D505DA273544 Precommits: Vote{0:125B0E3C5512 90/00/2(Precommit) F15AB8BEF9A6 {/FE98E2B956F0.../}} }#56FEF2EFDB8B37E9C6E6D635749DF3169D5F005D }#F671D562C7B9242900A286E1882EE64E5556FE9E module=consensus I[10-04|13:54:30.408] Executed block module=state height=91 validTxs=0 invalidTxs=0 I[10-04|13:54:30.410] Committed state module=state height=91 txs=0 hash=E0FBAFBF6FCED8B9786DDFEB1A0D4FA2501BADAD I[10-04|13:54:30.410] Recheck txs module=mempool numtxs=0 height=91