Logs

A Etn-sc node continually reports messages to the console allowing users to monitor Etn-sc's current status in real-time. The logs indicate when Etn-sc is running normally and indicates when some attention is required. However, reading these logs can be difficult for new users. This page will help to interpret the log messages to better understand what Etn-sc is doing.

Note that there are a large number of log messages covering a wide range of possible scenarios for a Etn-sc node. This page will only address a subset of commonly seen messages. For more, see the Etn-sc GitHub. Log messages are usually sufficiently self-describing that they do not require additional explanation.

Configuring log messages

Log messages are displayed to the console by default. The messages can be tuned to be more or less detailed by passing --verbosity and a value between 0 and 5 to Etn-sc at startup:

0 = silent (no log messages)
1 = error (error messages only)
2 = warn (error messages and warnings only)
3 = info (error messages, warnings and normal activity logs)
4 = debug (all info plus additional messages for debugging)
5 = detail (all info plus detailed debugging messages)

The default is --verbosity 3.

Log messages can also be redirected so they are saved to a text file instead of being displayed in the console. In Linux the syntax >> <path> 2>&1 redirects both stdout and stderr messages to <path>. For example:

# saves detailed logs to path/etn-sc.log
etn-sc --verbosity 5 >> /path/etn-sc.log 2>&1

Startup

When Etn-sc starts up it immediately reports a fairly long page of configuration details and status reports that allow the user to confirm Etn-sc is on the right network and operating in its intended modes. The basic structure of a log message is as follows:

MESSAGE_TYPE [MONTH-DAY][TIME] MESSAGE VALUE

Where MESSAGE_TYPE can be INFO, WARN, ERROR or DEBUG. These tags categorize log messages according to their purpose. INFO messages inform the user about Etn-sc's current configuration and status. WARN messages are for alerting the user to details that affect the way Etn-sc is running. ERROR messages are for alerting the user to problems. DEBUG is for messages that are relevant to troubleshooting or for developers working on Etn-sc.

The messages displayed on startup break down as follows:

INFO [07-25|15:50:01.128] Starting etn-sc on Electroneum testnet...
INFO [07-25|15:50:01.129] Maximum peer count                       ETH=50 LES=0 total=50
INFO [07-25|15:50:01.131] Set global gas cap                       cap=50,000,000
INFO [07-25|15:50:01.131] Allocated trie memory caches             clean=154.00MiB dirty=256.00MiB
INFO [07-25|15:50:01.131] Allocated cache and file handles         database=/Users/andrepatta/Library/Electroneum-sc/testnet/etn-sc/chaindata cache=512.00MiB handles=5120
INFO [07-25|15:50:01.309] Opened ancient database                  database=/Users/andrepatta/Library/Electroneum-sc/testnet/etn-sc/chaindata/ancient readonly=false
INFO [07-25|15:50:01.313] Persisted trie from memory database      nodes=3 size=415.00B time="17.084µs" gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B
INFO [07-25|15:50:01.314] Initialised chain configuration          config="{ChainID: 5201420 Homestead: 0 DAO: <nil> DAOSupport: true EIP150: 0 EIP155: 0 EIP158: 0 Byzantium: 0 Constantinople: 0 Petersburg: 0 Istanbul: 0, Muir Glacier: <nil>, Berlin: 0, London: 0, Arrow Glacier: <nil>, MergeFork: <nil>, Terminal TD: <nil>, Engine: IBFT}"
INFO [07-25|15:50:01.319] Initialising Electroneum Protocol        name=etn-istanbul versions=[100] network=5,201,420 dbversion=8
INFO [07-25|15:50:01.613] Loaded most recent local header          number=2,669,522 hash=6b1a52..7fadf7 td=2,669,523 age=5d3h58m
INFO [07-25|15:50:01.613] Loaded most recent local full block      number=2,669,522 hash=6b1a52..7fadf7 td=2,669,523 age=5d3h58m
INFO [07-25|15:50:01.613] Loaded most recent local fast block      number=2,669,522 hash=6b1a52..7fadf7 td=2,669,523 age=5d3h58m
INFO [07-25|15:50:01.613] Loaded last fast-sync pivot marker       number=2,645,471
INFO [07-25|15:50:01.643] Loaded local transaction journal         transactions=0 dropped=0
INFO [07-25|15:50:01.646] Regenerated local transaction journal    transactions=0 accounts=0

The logs above show the user that the node is connecting to Electroneum Smart Chain Testnet and some low level configuration details. The cache size is bumped to the Testnet default (4096). The maximum peer count is the highest number of peers this node is allowed to connect to and can be used to control the bandwidth requirements of the node.

INFO [07-25|15:50:01.650] Starting peer-to-peer node               instance=etn-sc/v1.0.0-stable-5be45479/darwin-arm64/go1.20.6
INFO [07-25|15:50:01.701] New local node record                    seq=1,689,703,084,530 id=695cfb779e4be582 ip=127.0.0.1 udp=41300 tcp=41300
INFO [07-25|15:50:01.701] Started P2P networking                   self=enode://666e25ebd14912ab79dd9bdf547bdb17981ab328f79517b0f8191109daaeef7c54f4dead8fb7777726dd7a599cedc16cf006961716be181ee37efddb47ef0383@127.0.0.1:41300
INFO [07-25|15:50:01.701] IPC endpoint opened                      url=/Users/andrepatta/Library/Electroneum-sc/testnet/etn-sc.ipc
INFO [07-25|15:50:01.702] HTTP server started                      endpoint=127.0.0.1:8545 auth=false prefix= cors= vhosts=localhost
INFO [07-25|15:50:01.702] WebSocket enabled                        url=ws://127.0.0.1:8546

Syncing

The default for Etn-sc is to sync in snap mode. Etn-sc requests block headers from its peers that are parents of the target until there is a continuous chain of sequential headers of sufficient length. Then, Etn-sc requests block bodies and receipts for each header and simultaneously starts downloading state data. This state data is stored in the form of a Patricia Merkle Trie. Only the leaves of the trie are downloaded, the full trie structure is then locally regenerated from the leaves up. Meanwhile, the blockchain continues to progress and the target header is updated. This means some of the regenerated state data need to be updated. This is known as healing.

Assuming Etn-sc has some peers it will start importing headers, block bodies and receipts. The log messages for data downloading look as follows:

INFO [07-28|10:29:49.681] Block synchronisation started
INFO [07-28|10:29:50.427] Imported new block headers               count=1    elapsed=253.434ms number=12,914,945 hash=ee1a08..9ce38a
INFO [07-28|10:30:00.224] Imported new block receipts              count=64   elapsed=13.703s   number=12,914,881 hash=fef964..d789fc age=18m5s     size=7.69MiB
INFO [07-28|10:30:18.658] Imported new block headers               count=1    elapsed=46.715ms  number=12,914,946 hash=7b24c8..2d8006
INFO [07-28|10:30:21.665] Imported new state entries

For state sync, Etn-sc reports when the state heal is in progress. This can take a long time. The log message includes values for the number of accounts, slots, codes and nodes that were downloaded in the current healing phase, and the pending field is the number of state entires waiting to be downloaded. The pending value is not necessarily the number of state entries remaining until the healing is finished. As the blockchain progresses the state trie is updated and therefore the data that need to be downloaded to heal the trie can increase as well as decrease over time. Ultimately, the state should heal faster than the blockchain progresses so the node can get in sync. When the state healing is finished there is a post-sync snapshot generation phase. The node is not in sync until the state healing phase is over. If the node is still regularly reporting State heal in progress it is not yet in sync - the state healing is still ongoing.

INFO [07-28|10:30:21.965] State heal in progress                   accounts=169,633@7.48MiB  slots=57314@4.17MiB    codes=4895@38.14MiB nodes=43,293,196@11.70GiB pending=112,626
INFO [09-06|01:31:59.885] Rebuilding state snapshot
INFO [09-06|01:31:59.910] Resuming state snapshot generation root=bc64d4..fc1edd accounts=0 slots=0 storage=0.00B dangling=0 elapsed=18.838ms

The sync can be confirmed using eth.syncing - it will return false if the node is in sync. If eth.syncing returns anything other than false it has not finished syncing. Generally, if syncing is still ongoing, eth.syncing will return block info that looks as follows:

> eth.syncing
{
  currentBlock: 15285946,
  healedBytecodeBytes: 991164713,
  healedBytecodes: 130880,
  healedTrienodeBytes: 489298493475,
  healedTrienodes: 1752917331,
  healingBytecode: 0,
  healingTrienodes: 1745,
  highestBlock: 16345003,
  startingBlock: 12218525,
  syncedAccountBytes: 391561544809,
  syncedAccounts: 136498212,
  syncedBytecodeBytes: 2414143936,
  syncedBytecodes: 420599,
  syncedStorage: 496503178,
  syncedStorageBytes: 103368240246
}

There are other log messages that are commonly seen during syncing. For example:

WARN [09-28|11:06:01.363] Snapshot extension registration failed

This warning is nothing to worry about - it is reporting a configuration mismatch between the node and a peer. It does not mean syncing is stalling or failing, it simply results in the peer being dropped and replaced.

Transaction logs

Transactions submitted over local IPC, Websockets or HTTP connections are reported in the console logs. For example, a simple ETN transaction appears in the console logs as follows:

INFO [09-06|01:31:59.910] Submitted transaction             hash=0x2893b70483bf1791b550e5a93763058b0abf7c6d9e6201e07212dbc64d4764532 from: 0xFB48587362536C606d6e89f717Fsd229673246e6 nonce: 43 recipient: 0x7C60662d63536e89f717F9673sd22246F6eB4858 value: 100,000,000,000,000,000

Other user actions have similar log messages that are displayed to the console.

Common warnings

There are many warnings that can be emitted by Etn-sc as part of its normal operation.

WARN [10-03|18:00:40.413] Unexpected trienode heal packet          peer=9f0e8fbf         reqid=6,915,308,639,612,522,441

The above is often seen and misinterpreted as a problem with snap sync. In reality, it indicates a request timeout that may be because I/O speed is low. It is usually not an issue, but if this message is seen very often over prolonged periods of time it might be rooted in a local connectivity or hardware issue.

WARN [10-03 | 13:15:56.543] Dropping unsynced node during sync    id = e2fdc0d92d70953 conn = ...

This message indicates that a peer is being dropped because it is not fully synced. This is normal - the necessary data will be requested from an alternative peer instead.

Summary

There are a wide range of log messages that are emitted while Etn-sc is running. The level of detail in the logs can be configured using the verbosity flag at startup. This page has outlined some of the common messages users can expect to see when Etn-sc is run with default verbosity, without attempting to be comprehensive.

Last updated