Cardano-wallet: Log of severity "DEBUG" shows up as "INFO"

Created on 16 Jan 2020  路  7Comments  路  Source: input-output-hk/cardano-wallet

Context

The network chain follower still uses and "old" Trace IO Text

follow
    :: forall target block e. (Show e)
    => NetworkLayer IO target block
    -- ^ The @NetworkLayer@ used to poll for new blocks.
    -> Trace IO Text
    -- ^ Logger trace
...

This trace is then captured in a log object as plain text as MsgFollow

data StakePoolMonitorLog
    = MsgStartMonitoring [BlockHeader]
    | MsgFollow Text
    | MsgStakeDistribution EpochNo
    | MsgStakePoolRegistration PoolRegistrationCertificate
    | MsgApplyError ErrMonitorStakePools
    deriving (Show, Eq)

during this transformation, it seems that we loose track of the severity information.

| Information | - |
| --- | --- |
| Version | 17edc2a10 |
| Platform | All |
| Installation | Sources |

Steps to Reproduce

  1. Start the wallet backend with default parameters
  2. Observe the logs

Expected behavior

  1. Lines with severity debug are not shown.

Actual behavior

  1. Lines initially logged with severity "debug" are shown with severity "info"
[cardano-wallet.stake-pool-monitor:Info:372] [2020-01-16 14:07:29.40 UTC] In sync with the node.

while in code:

        Right AwaitReply -> do
            logDebug tr "In sync with the node."
            sleep delay0 cursor

or in the wallet engine:

[cardano-wallet.wallet-engine:Info:376] [2020-01-16 14:05:31.35 UTC] Coins selected for payment: 
inputs: - 1st c40e213a (~ 100000000000 @ 83e5b54d...70746bc1)
outputs: - 1339 @ 84cb4862...45a2197a
change: [99999998661]

while in code:

    liftIO . logDebug tr $ "Coins selected for payment: \n" <> pretty sel

Resolution

  1. defineSeverity (MsgFromWorker msg) needs to use the severity of the enclosed log message.
  2. So Trace IO Text needs to change to Trace IO msg.
  3. And then Trace IO can be converted to Tracer m.
  4. Wallet, Network, Registry modules need to be updated as a single chunk.

PR #1278


QA

  • Severity is now properly passed for the wallet engine and workers logs and can be observed when running manually.
  • An additional PR in the context of #1235 introduces some level of automated testing regarding the log tracers: #1257

All 7 comments

Drat, I thought I would not need to convert Wallet+Registry+Network from Trace to Tracer, which is a fair chunk of work.

@rvl note also that I didn't assign it to you on purpose ^.^
What has to be done is fairly clear and I think a nice exercise also do some knowledge sharing (i.e. leave it to someone else) on how the logging setup works with Tracers.

Oh I did not realise, was more worried about leaving a defect.
If someone could help finish the PR by getting typed log messages through the worker thread registry, that would be great!

Running 2020.1.14 (git revision: 81ca8e5c0cab59cdbb02427abdfd9acfab6014a9).

DEBUG lines (In sync with the node.) are not shown in the log while running default log level. OK.

cd ./lib/jormungandr/test/data/jormungandr/test_scripts
cardano-wallet-jormungandr launch \
       --genesis-block ../block0.bin \
       --node-port 8080 \
       --state-dir ./data_launch \
       -- --secret ../secret.yaml --config ../config.yaml

However running with DEBUG log level:

cd ./lib/jormungandr/test/data/jormungandr/test_scripts
cardano-wallet-jormungandr launch \
       --genesis-block ../block0.bin \
       --node-port 8080 \
       --state-dir ./data_launch \
       --log-level DEBUG \
       -- --secret ../secret.yaml --config ../config.yaml

Also does not show DEBUG lines, e.g. In sync with the node.

CC: @KtorZ, @rvl.

@piotr-iohk perhaps we need more explanations on how the logging now works with the wallet backend. We've recently switched to a per-component logging, meaning that each component has its own severity level, whereas the global --log-level adds an additional filter on top of all the individual severities. Thus, settings the general --log-level to DEBUG but, leaving all the component tracers to INFO (which is the default for all of them) should not show any debug-level log line.

However, if you'd do:

cardano-wallet-jormungandr launch \
       --genesis-block ../block0.bin \
       --node-port 8080 \
       --state-dir ./data_launch \
       --log-level DEBUG \
       --trace-api-server DEBUG \
       -- --secret ../secret.yaml --config ../config.yaml

you'd also get DEBUG traces for the API tracer. All tracers are documented behind cardano-wallet launch --help-tracing.

OK. Perhaps entry for --trace-COMPONENT could be added to Available options for launch and serve?

$ cardano-wallet launch
...
Available options:
...
  --trace-COMPONENT SEVERITY   Severity for a message to be logged per specific COMPONENT 
                               name. Full list of available components are  documented in 
                               `--help-tracing`.

OK.

Was this page helpful?
0 / 5 - 0 ratings