Skip to content
This repository was archived by the owner on Aug 18, 2020. It is now read-only.

[CSL-1822] Refine logging #2055

Merged
merged 8 commits into from
Dec 7, 2017
Merged

Conversation

gromakovsky
Copy link
Contributor

There are various changes related to logging: what we log, which severity messages have, how logging is configured, etc.
Commit history is descriptive, imo. Most commits have few sentences of explanation.

I've almost finished, the only missing thing is to review middleware logs, will do it soon.

It was used by `updateScenario.sh' script, but this script was removed long
ago, so we don't need this config anymore.
Copy link
Contributor

@volhovm volhovm left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok. BTW, can you remind what is the motivation behind default logger name? It's not obvious for me anymore.

import Repl (WithCommandAction(..), withAuxxRepl)
import Repl (WithCommandAction (..), withAuxxRepl)

loggerName :: LoggerName
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I believe that defining a top level function that is used once only doesn't make any sense.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh, I forgot to use it in another place where we still have "auxx" hardcoded. Will fix.

@@ -319,7 +319,7 @@ createKademliaInstance ::
-> Word16 -- ^ Default port to bind to.
-> m KademliaDHTInstance
createKademliaInstance BaseParams {..} kp defaultPort =
usingLoggerName (lpRunnerTag bpLoggingParams) (startDHTInstance instConfig defaultBindAddress)
usingLoggerName (lpDefaultName bpLoggingParams) (startDHTInstance instConfig defaultBindAddress)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think that it'd better use a dedicated kademlia logging name instead.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I preserved existing logic, but ok, I think it makes sense indeed.

@@ -98,13 +97,6 @@ runNode' NodeResources {..} workers' plugins' = ActionSpec $ \vI sendActions ->
firstGenesisHash
(gdFtsSeed genesisData)

lastKnownEpoch <- LrcDB.getEpoch
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why don't we print leaders on start now?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Read vatnik.

@@ -1,18 +1,9 @@
rotation:
logLimit: 5242880 # 5MB
keepFiles: 20
severity: Info
severity: Debug
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are you sure? 🤔

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Previously we had Debug for node (where almost all messages go) and Info for the rest (where ε messages go). Now we have Debug for all. It's quite minor.

logLimit: 2097152 # 2MB
keepFiles: 20
logLimit: 104857600 # 100MB
keepFiles: 2
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If it's for qa only, i would suggest something in between. Say, 50mb and 10 files.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

QA is confusing name. It's for developers who use mainnet.sh and similar stuff.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yep, I know (I'm using it), the point was "we don't care about space since it's for devs/testing only".

@gromakovsky
Copy link
Contributor Author

BTW, can you remind what is the motivation behind default logger name?

Do you mean lpDefaultName? Well, maybe we can just use mempty by default. I think it's quite minor.

1. I deleted all obsolete stuff, e. g. `comm', `dht' logger names.
2. I renamed 'lpRunnerTag' to 'lpDefaultName', I think this name is more clear
appropriate.
3. `defaultLoggerConfig' is now `productionB' for simplicity. In practice all
our scripts pass custom configs anyway.
4. "node" is no longer hardcoded as logger name in libraries, only in
executables.
Before this change only `node` logger (and its successors) had logging to
files. However, some messages might be printed to different logger, at least
accidentially (e. g. if one uses `instance HasLoggerName Production').
Number of these messages is small, but they might be useful, so it's better
to have them in log files.
When log files are bigger, it's easier to review them.
Also I believe people can afford 200 MB of logs.
@gromakovsky gromakovsky force-pushed the gromak/csl1822-refine-logging branch from 2d10ae5 to 3ec8385 Compare December 6, 2017 19:13
@volhovm
Copy link
Contributor

volhovm commented Dec 6, 2017

Do you mean lpDefaultName? Well, maybe we can just use mempty by default. I think it's quite minor.

If we can delete a useless field from node context, i think we should. Anyway, I'm looking at this again.

Now *all* slot leaders are printed only once per epoch: after they are
calculated. Printing all leaders takes a lot of place in logs, so we don't
want to do it more often.
Also they are printed prettier, in chunks.
Copy link
Contributor

@volhovm volhovm left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

Before this commit online and up-to-date node was printing header of a
newly created block received from the network 5 times. It's quite a lot,
especially considering that each header takes about 9 lines.

Few observations:
1. Printing header in 'handleUnsolicitedHeader' makes more sense than
in 'addHeaderToBlockRequestQueue', because it's called earlier
and allows us to inspect header before we do something with it.
2. Printing header after we processed it is not useful, because we must
have printed it already. Printing hash is enough.
3. 'handleContinues' and 'handleAlternative' are called after we receive an
unsolicited header. It implies that we have printed it already, so we can
print its hash.
@gromakovsky gromakovsky force-pushed the gromak/csl1822-refine-logging branch from 3ec8385 to 627a2de Compare December 6, 2017 20:59
@gromakovsky
Copy link
Contributor Author

If we can delete a useless field from node context, i think we should.

I think we can't. Even if we use mempty by default, we have modifyLoggerName.

@gromakovsky gromakovsky merged commit d598003 into master Dec 7, 2017
@gromakovsky gromakovsky deleted the gromak/csl1822-refine-logging branch December 7, 2017 10:20
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants