Skip to content

Conversation

jonatack
Copy link
Member

@jonatack jonatack commented Dec 10, 2021

Use the LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE macro to improve the logging of ChainstateManager snapshot persistance, log task start and completion separately and no longer manually track the duration, as suggested by Marco Falke in #22872 (comment).

Extract the flushing into one function, which clarifies the logic, extends the improved logging to both flushing call sites, and allows logging the prefix FlushSnapshotToDisk, which is similar to FlushStateToDisk.

before

[snapshot] flushing coins cache (0 MB)... done (0.00ms)

[snapshot] flushing snapshot chainstate to disk

after

FlushSnapshotToDisk: flushing coins cache (0 MB) started
...
FlushSnapshotToDisk: completed (0.00ms)

FlushSnapshotToDisk: saving snapshot chainstate (0 MB) started
...
FlushSnapshotToDisk: completed (0.00ms)

The logging can be observed in the output of

./src/test/test_bitcoin -t validation_chainstate_tests -- DEBUG_LOG_OUT

This moves the flushing and logging into one method and adds logging
of time duration and memory for the snapshot chainstate flushing.
Use the `LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE` macro to improve the
logging of snapshot persistance and no longer manually track the duration.

before

[snapshot] flushing coins cache (0 MB)... done (0.00ms)

[snapshot] flushing snapshot chainstate to disk (0 MB)... done (0.00ms)

after

FlushSnapshotToDisk: flushing coins cache (0 MB) started
FlushSnapshotToDisk: completed (0.00ms)

FlushSnapshotToDisk: saving snapshot chainstate (0 MB) started
FlushSnapshotToDisk: completed (0.00ms)

The logging can be observed in the output of

./src/test/test_bitcoin -t validation_chainstate_tests -- DEBUG_LOG_OUT

const int64_t flush_now{GetTimeMillis()};

// TODO: if #17487 is merged, add erase=false here if snapshot is loaded, for better performance.
Copy link
Member

Choose a reason for hiding this comment

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

unrelated: Wouldn't it be better to remove this comment and just do this in 17487?

Copy link
Member Author

@jonatack jonatack Dec 11, 2021

Choose a reason for hiding this comment

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

Thanks, done (I had removed it in the first push but wasn't sure). Made a note in that PR: #17487 (comment).

@DrahtBot
Copy link
Contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #23545 (scripted-diff: Use clang-tidy syntax for C++ named arguments by MarcoFalke)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

It would make for sense for the TODO to be done in PR 17487
(or noted in the review feedback for a follow-up),
no need to continue maintaining the TODO in the codebase.
@jamesob
Copy link
Contributor

jamesob commented Dec 13, 2021

Code review ACK 8e37fa8

@maflcko maflcko merged commit 767c012 into bitcoin:master Dec 13, 2021
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Dec 13, 2021
…nager snapshot persistance

50209a4 validation, doc: remove TODO comment (Jon Atack)
8e37fa8 validation, log: improve logging in FlushSnapshotToDisk() (Jon Atack)
271252c validation, log: extract FlushSnapshotToDisk() function (Jon Atack)

Pull request description:

  Use the `LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE` macro to improve the logging of ChainstateManager snapshot persistance, log task start and completion separately and no longer manually track the duration, as suggested by Marco Falke in bitcoin#22872 (comment).

  Extract the flushing into one function, which clarifies the logic, extends the improved logging to both flushing call sites, and allows logging the prefix `FlushSnapshotToDisk`, which is similar to `FlushStateToDisk`.

  before
  ```
  [snapshot] flushing coins cache (0 MB)... done (0.00ms)

  [snapshot] flushing snapshot chainstate to disk
  ```
  after
  ```
  FlushSnapshotToDisk: flushing coins cache (0 MB) started
  ...
  FlushSnapshotToDisk: completed (0.00ms)

  FlushSnapshotToDisk: saving snapshot chainstate (0 MB) started
  ...
  FlushSnapshotToDisk: completed (0.00ms)
  ```
  The logging can be observed in the output of
  ```
  ./src/test/test_bitcoin -t validation_chainstate_tests -- DEBUG_LOG_OUT
  ```

Top commit has no ACKs.

Tree-SHA512: 5d954cd8c7455f8625152a43663a237f04717bb834aed62925a56e17c711fca6ccfc03783970b6b0bde44f64617d804b423a7048287c06ee816db36247acf272
@jonatack jonatack deleted the refactor-and-improve-snapshot-persistance-logging branch December 13, 2021 23:45
Fabcien pushed a commit to Bitcoin-ABC/bitcoin-abc that referenced this pull request Nov 11, 2022
…tance

Summary:
Use the LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE macro to improve the logging of ChainstateManager snapshot persistance, log task start and completion separately and no longer manually track the duration, as suggested by Marco Falke.

Extract the flushing into one function, which clarifies the logic, extends the improved logging to both flushing call sites, and allows logging the prefix FlushSnapshotToDisk, which is similar to FlushStateToDisk.

before
```
[snapshot] flushing coins cache (0 MB)... done (0.00ms)

[snapshot] flushing snapshot chainstate to disk
```
after
```
FlushSnapshotToDisk: flushing coins cache (0 MB) started
...
FlushSnapshotToDisk: completed (0.00ms)

FlushSnapshotToDisk: saving snapshot chainstate (0 MB) started
...
FlushSnapshotToDisk: completed (0.00ms)
```

This is a backport of [[bitcoin/bitcoin#23738 | core#23738]]

Depends on D12469

Test Plan: `ninja all check-all`

Reviewers: #bitcoin_abc, Fabien

Reviewed By: #bitcoin_abc, Fabien

Differential Revision: https://reviews.bitcoinabc.org/D12470
@bitcoin bitcoin locked and limited conversation to collaborators Dec 13, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants