Add logging

[danwt]

Problem

We need logging to understand the running system.

Closing criteria

Add

• provider module logging
• consumer module logging
• provider module logging - game of chains (high prio)
• consumer module logging - game of chains (high prio)

TODOs

• Labels have been added for issue
• Issue has been added to the ICS project

# Other

Ill add logging for goc-december first, and then we can worry about getting it on main.

Note, the logger only has debug, info and error, and doesn't have warn.

https://github.com/tendermint/tendermint/blob/v0.34.23/libs/log/logger.go#L10-L16

Related issue

• Confirm logging behavior #541

Shawns MVP logging branch

• goc-december...goc-dec-8-debug

I will take inspiration from the tips here

• https://tuhrig.de/my-logging-best-practices/

[danwt]

Here's some additional advice from @greg-szabo and @mircea-c

Hi Dan! I think network node logging is usually similar. Hermes is the outstanding "other project" that improved it's logging twofold as we went through some feedback.
A few general takeaways for logging:
Have JSON output as an alternative
If you can't have JSON output, define the log line strictly, so it can be cut up and mangled with string-mangling functions
One line per entry. Multiline log entries (like panics dumped into the log) create havoc and they are hard to manage outside of the casual developer execution.
Try to make atomic entries: the entry fully says when, what happened, to whom in a standardized, detailed format. Time is well-defined and either in UTC or in the local time of the server. (I prefer the latter.) If a packet was involved, the packet number is mentioned. The log severity indicates how bad it is what happened. If there are only a limited amount of error types, there is an error type mentioned so the operator doesn't have to rely on the plain text error message.
If the entry is part of a set of entries (for example you dump multiple thread's logs into one logfile), there is an identifier for log entry sets so it's easy to filter for entry groups. (thread ID, request ID, etc)
Causality is hard to represent in logs. Developers tend to look at a page of logs and find relations in the order of the entries. In operations, the logs entries might be vastly more and the processing of them might be line-by-line. If there is an order to things, the order is indicated in the entry. (Step 1, step 2, step 3 or similar of a logic, or like PreVote, PreCommit, etc.)

As an add-on to this, would be nice if the types that are output are consistent.
For example, the node software logs a height field that would be expected to be a float. But the ibc module logs it as 1-xxxx or 2-xxxx I am guessing based on which chain it's logged from. This breaks automatic type detection in log analysis software.