New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log/report in 10% steps during VerifyDB #8136

Merged
merged 1 commit into from Jun 7, 2016

Conversation

Projects
None yet
4 participants
@jonasschnelli
Member

jonasschnelli commented Jun 2, 2016

By default Bitcoin-Core does verify the last 288 blocks. This can take a couple of minutes on slow systems.

This PR adds a simple progress report during VerifyDB in 10% steps into the debug log.
I think misusing the debug.log for this – relatively long taking process – is okay.

Example:

2016-06-02 11:56:01 init message: Verifying blocks...
2016-06-02 11:56:01 Verifying last 288 blocks at level 3
[0%]...[10%]...[20%]...[30%]...[40%]...[50%]...[60%]...[70%]...[80%]...[90%]...[DONE].
No coin database inconsistencies in last 289 blocks (68239 transactions)

@jonasschnelli jonasschnelli added the Docs label Jun 2, 2016

@sipa

This comment has been minimized.

Show comment
Hide comment
@sipa

sipa Jun 2, 2016

Member

Perhaps we should also reduce the number 288. Maybe a limit specified in number of transactions is better?

Member

sipa commented Jun 2, 2016

Perhaps we should also reduce the number 288. Maybe a limit specified in number of transactions is better?

@jonasschnelli

This comment has been minimized.

Show comment
Hide comment
@jonasschnelli

jonasschnelli Jun 2, 2016

Member

Agree with @sipa, but could be a different PR (very likely more controversial).

Member

jonasschnelli commented Jun 2, 2016

Agree with @sipa, but could be a different PR (very likely more controversial).

@sipa

This comment has been minimized.

Show comment
Hide comment
@sipa

sipa Jun 2, 2016

Member
Member

sipa commented Jun 2, 2016

@dcousens

This comment has been minimized.

Show comment
Hide comment
@dcousens

dcousens Jun 2, 2016

Contributor

concept ACK

Contributor

dcousens commented Jun 2, 2016

concept ACK

@dcousens

This comment has been minimized.

Show comment
Hide comment
@dcousens

dcousens Jun 2, 2016

Contributor

edit: moved comment to #8138 (comment)

Contributor

dcousens commented Jun 2, 2016

edit: moved comment to #8138 (comment)

int percentageDone = std::max(1, std::min(99, (int)(((double)(chainActive.Height() - pindex->nHeight)) / (double)nCheckDepth * (nCheckLevel >= 4 ? 50 : 100))));
if (reportDone < percentageDone/10) {
// report every 10% step
LogPrintf("[%d%%]...", percentageDone);

This comment has been minimized.

@laanwj

laanwj Jun 6, 2016

Member

It's inventive to print a partial line here instead of a full line - however this can only work if there is nothing else happening in the background, otherwise partial log messages will mix.
As this is only called during AppInit2 I suppose it's safe.

@laanwj

laanwj Jun 6, 2016

Member

It's inventive to print a partial line here instead of a full line - however this can only work if there is nothing else happening in the background, otherwise partial log messages will mix.
As this is only called during AppInit2 I suppose it's safe.

This comment has been minimized.

@jonasschnelli

jonasschnelli Jun 6, 2016

Member

I think its fragile but okay as long as it is somewhere on the upper section of AppInit2(). :-)

@jonasschnelli

jonasschnelli Jun 6, 2016

Member

I think its fragile but okay as long as it is somewhere on the upper section of AppInit2(). :-)

@laanwj

View changes

Show outdated Hide outdated src/main.cpp
@jonasschnelli

This comment has been minimized.

Show comment
Hide comment
@jonasschnelli

jonasschnelli Jun 6, 2016

Member

Fixed @laanwj nit.

Member

jonasschnelli commented Jun 6, 2016

Fixed @laanwj nit.

@laanwj

This comment has been minimized.

Show comment
Hide comment
@laanwj

laanwj Jun 7, 2016

Member

Tested with -printtoconsole:

2016-06-07 07:16:19 [0%%]...[10%]...[20%]...[30%]...[40%]...[50%]...[60%]...[70%]...[80%]...[90%]...[DONE].
No coin database inconsistencies in last 21 blocks (30100 transactions)
2016-06-07 07:20:17  block index          242905ms
  • For some reason the second line doesn't get a time/date header. This seems like a bug in LogPrintf. To work around maybe use a separate LogPrintf line there same as you did for the 0%.
  • Also: the first is %%, the second and latter are %. This is an effect of a printf without argument being not a printf at all but a literal string print. https://github.com/bitcoin/bitcoin/blob/master/src/util.h#L94
Member

laanwj commented Jun 7, 2016

Tested with -printtoconsole:

2016-06-07 07:16:19 [0%%]...[10%]...[20%]...[30%]...[40%]...[50%]...[60%]...[70%]...[80%]...[90%]...[DONE].
No coin database inconsistencies in last 21 blocks (30100 transactions)
2016-06-07 07:20:17  block index          242905ms
  • For some reason the second line doesn't get a time/date header. This seems like a bug in LogPrintf. To work around maybe use a separate LogPrintf line there same as you did for the 0%.
  • Also: the first is %%, the second and latter are %. This is an effect of a printf without argument being not a printf at all but a literal string print. https://github.com/bitcoin/bitcoin/blob/master/src/util.h#L94
@jonasschnelli

This comment has been minimized.

Show comment
Hide comment
@jonasschnelli

jonasschnelli Jun 7, 2016

Member

Thanks for testing!
Fixed the 0%% text typo as well as the missing time/date header (switched to a single line for the [DONE] part.

Member

jonasschnelli commented Jun 7, 2016

Thanks for testing!
Fixed the 0%% text typo as well as the missing time/date header (switched to a single line for the [DONE] part.

@laanwj

This comment has been minimized.

Show comment
Hide comment
@laanwj

laanwj Jun 7, 2016

Member

Tested ACK 8b78486

2016-06-07 13:21:01 Verifying last 288 blocks at level 3
2016-06-07 13:21:01 [0%]...[10%]...[20%]...[30%]...[40%]...[50%]...[60%]...[70%]...[80%]...[90%]...[DONE].
2016-06-07 13:23:39 No coin database inconsistencies in last 23 blocks (35781 transactions)

Slightly tangential: the progress reporting is quite distorted, by far most of the time is spent at 0%, then it seems to take a sprint for 100%.

Member

laanwj commented Jun 7, 2016

Tested ACK 8b78486

2016-06-07 13:21:01 Verifying last 288 blocks at level 3
2016-06-07 13:21:01 [0%]...[10%]...[20%]...[30%]...[40%]...[50%]...[60%]...[70%]...[80%]...[90%]...[DONE].
2016-06-07 13:23:39 No coin database inconsistencies in last 23 blocks (35781 transactions)

Slightly tangential: the progress reporting is quite distorted, by far most of the time is spent at 0%, then it seems to take a sprint for 100%.

@laanwj laanwj merged commit 8b78486 into bitcoin:master Jun 7, 2016

1 check passed

continuous-integration/travis-ci/pr The Travis CI build passed
Details

laanwj added a commit that referenced this pull request Jun 7, 2016

Merge #8136: Log/report in 10% steps during VerifyDB
8b78486 Log/report in 10% steps during VerifyDB (Jonas Schnelli)

codablock added a commit to codablock/dash that referenced this pull request Sep 16, 2017

Merge #8136: Log/report in 10% steps during VerifyDB
8b78486 Log/report in 10% steps during VerifyDB (Jonas Schnelli)

codablock added a commit to codablock/dash that referenced this pull request Sep 19, 2017

Merge #8136: Log/report in 10% steps during VerifyDB
8b78486 Log/report in 10% steps during VerifyDB (Jonas Schnelli)

codablock added a commit to codablock/dash that referenced this pull request Dec 22, 2017

Merge #8136: Log/report in 10% steps during VerifyDB
8b78486 Log/report in 10% steps during VerifyDB (Jonas Schnelli)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment