As a developer, I need to implement custom logging in node

[binier]

tracing library is used for logging in Openmina.

Implement custom subscriber which will process those logs and print to terminal.

• Instead of current time, logger should use passed time.
• Have an ENV var which can customize whether we log details or not. If not we should only display summary part of the log.

[akoptelov]

@binier Hi Zura, I can handle this one. Some comments/questions.

1. With relation to time, I guess you want to have a timestamp of an event, right? Shouldn't we instead have it as an additional log entry property? Otherwise we can end up in a situation where we have strange order of timestamps in logs.
2. I think verbosity should be based on entry kind, instead of printing the same log entry differently depending on requested level. As an example, consider a log entry on a huge message reception. If there is a single log entry with both summary and message content, it would be quite hard to analyze the log with its content included. On the other hand, if verbosity is decreased, then there would be no way of getting that content. Instead, we can have an entry containing a summary, with e.g. debug level, and another one with e.g. trace level containing the message itself. That way we can just use grep/awk to read high-level logs, and then focus on specific data.

[binier]

@akoptelov

Otherwise we can end up in a situation where we have strange order of timestamps in logs.

Yes if we mix usage of monotonic time and system time like it's done now. But if we store these two as a static vars: https://github.com/openmina/redux-rs/blob/155f8208f3105174cbd32172e7580b164d772349/src/store.rs#L56-L57
We could use just monotonic time everywhere.

---

I think verbosity should be based on entry kind, instead of printing the same log entry differently depending on requested level

I had in mind additional flag plus verbosity level.

If there is a single log entry with both summary and message content, it would be quite hard to analyze the log with its content included

I'd say it's mostly useful if we will use some tool to process those logs. Basically what we had for webnode in FE.

On the other hand, if verbosity is decreased, then there would be no way of getting that content

True, but same is the case with low verbosity logging as well. It's a tradeoff. In general summary should contain enough info to somewhat reason about the thing.
Still you might be right. I don't really have a preference for that. One thing to keep in mind though is that existing logs were written for webnode to be viewed in the frontend. So many of them include big data like full blocks as a log entry fields.

[akoptelov]

@akoptelov

Otherwise we can end up in a situation where we have strange order of timestamps in logs.

Yes if we mix usage of monotonic time and system time like it's done now. But if we store these two as a static vars: https://github.com/openmina/redux-rs/blob/155f8208f3105174cbd32172e7580b164d772349/src/store.rs#L56-L57 We could use just monotonic time everywhere.

I think verbosity should be based on entry kind, instead of printing the same log entry differently depending on requested level

I had in mind additional flag plus verbosity level.

Yeah, I understood that. I'm just trying to expand on the problem according to my experience working with desktop version of openmina.

If there is a single log entry with both summary and message content, it would be quite hard to analyze the log with its content included

I'd say it's mostly useful if we will use some tool to process those logs. Basically what we had for webnode in FE.

Totally agree with you. But still we need to cover the use-case when we just have a plain log.

For example, this configuration works fine for me during dev stage:

• max verbosity level
• single-line log entry
• for an event with some huge amount of data involved, there are two entries, one containing the summary, and another one containing the data itself (that later one with higher level of verbosity)
• the full log is stored, but it can be easily filtered so no data entries are printed. That way the whole flow can be easily seen and not cluttered with big messages.
• if there is an issue, it is quite easy to navigate to the whole log using summary entries, to fetch the whole data.

And then we have an option to completely avoid dumping tracing data, e.g. in production.

To my feeling, this way it is just a bit easier to use terminal utilities to view logs.

On the other hand, if verbosity is decreased, then there would be no way of getting that content

True, but same is the case with low verbosity logging as well. It's a tradeoff. In general summary should contain enough info to somewhat reason about the thing. Still you might be right. I don't really have a preference for that. One thing to keep in mind though is that existing logs were written for webnode to be viewed in the frontend. So many of them include big data like full blocks as a log entry fields.

OK, let's see as it goes :)