Introducing new Octez node logs for better UX

Future versions of the Octez node will only output essential information, while a more detailed log is written to disk in the background

Originally published at Nomadic Labs blog


800 words, 4 minute read

A faster and more scalable Tezos A sneak peak at the Mumbai proposal image 1

TL;DR: Future versions of the Octez node will only output essential information, while a more detailed log is written to disk in the background.

Core developers and users of the Octez software suite know it well: the Octez node is pretty verbose.

For every block, the node yells out a whole series of steps taken:

Jan  6 14:33:10.879 - validator.block: prechecked block BLkhtA81uak1SxxCDCVMXEnXCKsJcFLajVT84ZjrFKbxAaJUL4E
Jan  6 14:33:10.900 - validator.block: block BLkhtA81uak1SxxCDCVMXEnXCKsJcFLajVT84ZjrFKbxAaJUL4E validated
Jan  6 14:33:10.900 - validator.block:   Request pushed on 2023-01-06T13:33:10.853-00:00, treated in 153us, completed in 45.531ms
Jan  6 14:33:10.920 - prevalidator: switching to new head BLkhtA81uak1SxxCDCVMXEnXCKsJcFLajVT84ZjrFKbxAaJUL4E
Jan  6 14:33:10.920 - prevalidator:   Request pushed on 2023-01-06T13:33:10.900-00:00, treated in 308us, completed in 19.333ms
Jan  6 14:33:10.920 - validator.chain: Update current head to BLkhtA81uak1SxxCDCVMXEnXCKsJcFLajVT84ZjrFKbxAaJUL4E
Jan  6 14:33:10.920 - validator.chain:   (level 462824, timestamp 2023-01-06T13:33:10-00:00, fitness
Jan  6 14:33:10.920 - validator.chain:   02::00070fe8::::ffffffff::00000000), same branch

To improve the user experience, we’ve decided to make a significant change to these logs. In the next major version of Octez (17.0), the node will output ONE SINGLE LINE for each new block, plus for injected operations and baked blocks (if running a baker). But don’t worry, all the nitty gritty technical information remains available.

Read on to learn what we did and why.

What a node log should do #

Logs are a way to communicate information on the state of some software. In the context of the Octez node, the goal is to keep the user aware of the interaction between local Octez software and the Tezos blockchain.

Some examples of what could be going on:

When everything goes well, a new head appears regularly with every new block. Or the node reports receiving new operations. During these peaceful times there is really no need to be verbose.

Still, at every new block, the node is yelling the eight lines in the introduction of this post. These lines contain what to most users must seem like dark magic incantations, like prevalidator and Request pushed or timing in micro-seconds.

Is that interesting for a user? We don’t believe it is. The only pertinent information for a user is :

Hey, it's going well, the level is now 462824 and the most recent head has the hash BLkhtA81uak1SxxCDCVMXEnXCKsJcFLajVT84ZjrFKbxAaJUL4E.

Wait, I want the juicy details! #

On the other hand, when issues arise, we want users to be able to communicate errors to relevant people, such as the developer team and incident managers.

In fact, it’s not only the errors we need, but also the state of the node during the last few hours or days. This information can sometimes be even more important than the error itself.

To make the logs less of a pain to read for a user, we need to remove information. But if we want logs to stay useful enough for a developer to fix issues after an incident, we need to keep this information somewhere, and even add more!

So, we’ve split logs into two channels:

For internal logs, we added a new node configuration option (as specified in the documentation), daily-logs, to create a log file every day, which is kept during a user-defined number of days.

Users can find these log files at the path <node-data-dir>/daily-logs/. By default, the daily log files will be kept for seven days, in which case the directory shouldn’t exceed 500MB.

Stripping down the node output #

Now that the important debugging logs are stored elsewhere, we can safely remove information from the user logs. At each block, we now have only one line:

Jan  6 14:33:10.879: head is now BLkhtA81uak1SxxCDCVMXEnXCKsJcFLajVT84ZjrFKbxAaJUL4E (462824)

In short, we

Most of this work is expected to appear in Octez suite v17.

What’s next? #

The next step is mostly a refactoring of the node logging engine, and hopefully removing a deprecated library, lwt_log. This work will allow us to have colors in the logs to emphasize specific information, like when your baker baked a block, or when an error is shown.