Logging guidelines

Logs are primarily for users of the cardano-wallet, not its developers. Such users could be:

• Engineers who will be running the cardano-wallet in production.
• Developers integrating cardano-wallet into their own software.
• Technical support staff who need to help solve end users’ problems.

Users of logging will have a reasonable understanding of how the cardano-wallet works, but won’t be familiar with the code. They need enough information to be able scan the logs and see if the application is running normally, or if they need to do some action to fix their problem.

Logging levels

The iohk-monitoring-framework defines a number of severity levels:

This design was influenced by the syslog severity level taxonomy.

These are probably more than we need. To keep things simple, we usually only log with the first 5:

Debug

Debug logging will not be enabled by default in production. Therefore, you should not log information directly relevant to production operations at this level.

However, the technical support desk may request users enable debug logging for certain components to get more detail while trying to diagnose problems in the field.

Such logging might contain:

• Information about which program decisions were made and why.

Don’t debug log too much rubbish because somebody will need to read it. Don’t log so much data that the program will malfunction if debug logging has been enabled.

It is useful to have debug logging of about how the wallet interacts with other systems. Examples of such logs:

• Network requests made to node backend.
• SQL query logs – log the queries but not the values.

Note from Alexander Diemand:

Another feature that might help reduce logging volume: monitoring can watch an observable and compare it to a set threshold. Once this is exceeded it can create an action: i.e. an alert message or change the severity filter of a named context or globally. So one would start up the node with logging filter set to “Warning” and only change it to “Info” when some monitored observable has exceeded its threshold

For an exchange that runs the node for ages: another monitor could also restore the severity filter to e.g. “Warning” if the observed values return into a normal behaviour range of values.

Info

Normal activity within the application. We do need to ensure that INFO logs are pertinent, and there are not pages and pages of logs per slot.

Examples:

• HTTP requests
• Wallet-related events
  • A block was applied
  • New wallet was created
  • Wallet restoration status
  • Payment was sent
  • Payment was received
• Network-related events
  • Sync state
• Information about the configuration, such as config file location, or how the wallet was started.

Notice

These are occasional messages about significant events for the program.

Examples:

• The start up message, including the application version.
• What TCP port the API server is listening on.
• Normal shut down.
• Creating a new database file or migrating data.

Warning

A warning situation could lead to a future error, or other undesirable behaviour. The user should be able to do something to make the warning go away.

Examples:

• NTP drift?
• Low disk space?

Error

This is a serious system problem. It should not happen under normal circumstances. Some action is required to rectify the situation. The wallet might well exit after logging an error message.

Examples:

• Unexpected error communicating with node backend.
• IO error writing database or other state.
• Bad user input which means that the action cannot complete.
• Unhandled exception.

Mapping of log levels to appearance

CLI tools

Logging from the CLI should not be cluttered with timestamps and other metadata. It should just look like a normal print statements in a program. Nonetheless, using the logging framework for CLI output helps because error messages can be automatically coloured.

Server

The server will support also support a log config file where the output location and format can be fully customised.

Colour

If the log output file is not a terminal, do not output ANSI colour codes. These escape codes make it difficult to analyse log files.

JSON

JSON (one object per line) is an OK format for log files, but it’s pretty bad for printing the terminal. For example, consider how difficult it would be to read through JSON messages within journalctl -u cardano-wallet.service. Therefore, log messages to stdout/stderr should be formatted as text, unless otherwise configured by the user.

Context

Some context may be applicable to log events:

• Current slot number.
• Wallet ID.
• A request ID for the API, so that requests, their handlers, and responses can be cross-referenced.

Logging Hierarchy

Log Traces can have context added such as a new name. Different subsystems of the wallet (such as network, database, api) should use appendName to create subtraces.

Observables

The following are examples of things which should be easy and useful to log as micro-benchmarks (bracketObserveIO).

• Time taken for API to respond to request.
• Time taken to execute SQL query.
• Time taken for node backend to respond to request.

Privacy

iohk-monitoring-framework provides “sensitive” variants of log functions (e.g. logInfoS). These allow sensitive information to be logged into separate files. Then users may send their logs to the technical support desk with a reasonable assurance of privacy.

Note: The privacy guidelines are under discussion. We are considering making it simpler and only having two classifications: “Log” or “Do Not Log”.

Public information

• Wallet ID.
• Dates and times that events occurred.
• Total number of addresses/transactions/UTxOs/etc.
• IP addresses of other nodes that network nodes are communicating with.

Private information

• Transaction ID.
• Address.
• Public key material.
• Quantities of Ada.

Unknown

Undecided about which category these fall into.

• Wallet name

Never log

This information should never be included in log messages (including DEBUG messages):

• Private key material.
• Mnemonic sentences.
• Passphrases.
• The values used or returned by SQL queries.
• Raw data sent to or received from the network backend.
• Raw, un-filtered API request or response bodies.

Increasing logging detail

iohk-monitoring-framework provides a facility for adjusting log levels at runtime on a component by component basis.

However it’s probably OK for now to change log levels by restarting cardano-wallet with different command-line options.

Structured logging tutorial

Rather than logging unstructured text, define a type for log messages of a module.

data FooMsg
    = LogFooInit
    | LogFooError FooError
    | LogFooIncomingEvent Int
    deriving (Show, Eq)

Then for human-readable logs use our ToText class.

import Data.Text.Class
    ( ToText (..) )

instance ToText FooMsg where
    toText msg = case msg of
        LogFooInit -> "The foo has started"
        LogFooError e -> "foo error: " <> T.pack (show e)
        LogFooIncomingEvent -> "Incoming foo event " <>  T.pack (show e)

Finally, define the metadata which the switchboard needs to route these traces.

import Cardano.BM.Data.LogItem
    ( LoggerName, PrivacyAnnotation (..) )
import Cardano.BM.Data.Severity
    ( Severity (..) )
import Cardano.BM.Data.Tracer
    ( DefinePrivacyAnnotation (..), DefineSeverity (..) )

-- Everything is public by default
instance DefinePrivacyAnnotation FooMsg

instance DefineSeverity FooMsg
    defineSeverity msg = case msg of
        LogFooInit -> Debug
        LogFooError _ -> Error
        LogFooIncomingEvent -> Info

To use the logging in the doFoo function:

import Cardano.BM.Trace
    ( Trace )
import Cardano.Wallet.Logging
    ( logTrace )

doFoo :: Trace IO FooMsg -> IO ()
doFoo tr = do
    logTrace tr LogFooInit
    onFooEvent $ \ev -> case ev of
       Right n -> logTrace tr $ LogFooIncomingEvent n
       Left e -> logTrace tr $ LogFooError e

To convert to Trace m FooMsg to Trace m Text (well actually - the other way around), use Cardano.Wallet.Logging.transformTextTrace, like so:

import Control.Tracer
    ( contramap )
import Cardano.Wallet.Logging
    ( transformTextTrace )
import Foo (doFoo)

mainApp :: Trace IO Text -> IO ()
mainApp tr = doFoo (transformTextTrace tr)

To convert a Trace m FooMsg to anything else, use contramap.

data AppMsg
    = FooMsg FooMsg
    | BarMsg BarMsg
    | TextMsg Text

mainApp :: Trace IO AppMsg -> IO ()
mainApp tr = doFoo (contramap (fmap FooMsg) tr)