util: Properly handle errors during log message formatting #9963

laanwj · 2017-03-09T10:42:14Z

Instead of having an exception propagate into the program (which at worst causes a crash) when an error happens while formatting a log message, just print a message to the log. This message clearly indicates what log message was formatted wrongly, and what error happened during formatting it.

Addresses #9423.

Before

2017-03-09 10:58:20 

************************
EXCEPTION: St13runtime_error       
tinyformat: Too many conversion specifiers in format string       
bitcoin in AppInit()       



************************
EXCEPTION: St13runtime_error       
tinyformat: Too many conversion specifiers in format string       
bitcoin in AppInit()       

2017-03-09 10:58:20 Shutdown: In progress...
2017-03-09 10:58:20 scheduler thread interrupt
2017-03-09 10:58:20 Shutdown: done

(and process exits)

After

2017-03-09 10:51:50 Error "tinyformat: Too many conversion specifiers in format string" while formatting log message: Erasing %s %s

(and process continues)

TheBlueMatt · 2017-03-10T17:52:49Z

Looks good, though I'd prefer if we narrow the catch and change TINYFORMAT_ERROR to throw a more narrow exception type. Not for any specific concern, but...man I hate C++ exceptions.

laanwj · 2017-03-10T18:20:21Z

So are there any errors during log message formatting that raise runtime_error that you'd want to escalate? We don't have any sensible/specific exception handling so personally I'd prefer to keep it like this.

laanwj · 2017-03-10T18:21:10Z

Ehh oops I guess it makes sense to have the catch() only around tfm::format, though, not LogPrintStr (which does I/O).

Instead of having an exception propagate into the program when an error happens while formatting a log message, just print a message to the log. Addresses bitcoin#9423.

laanwj · 2017-03-12T06:59:40Z

Okay, updated so that only the formatting is guarded and there is a single LogPrintStr call which can still fail for legit reasons such as disk full...

TheBlueMatt · 2017-03-12T23:46:01Z

Heh, I knew it needed a tighter catch somehow :P. Anyway, if you dont want to have something more specific that's fine.

utACK 3b092bd

Throw tinyformat::format_error on formatting error instead of the `std::runtime_error`.

laanwj · 2017-03-13T05:53:15Z

LIke this? I don't think this is a very interesting place to get started defining more specific exceptions, but we have to start somewhere...

TheBlueMatt · 2017-03-13T12:19:48Z

Yea, agreed. I do like that better, though I suppose we really need to come up with some kind of coherent exception-use design at some point.

…

On March 13, 2017 1:53:19 AM EDT, "Wladimir J. van der Laan" ***@***.***> wrote: LIke this? I don't think this is not a very interesting place to get started defining more specific exceptions, but we have to start somewhere... -- You are receiving this because you commented. Reply to this email directly or view it on GitHub: #9963 (comment)

b651270 util: Throw tinyformat::format_error on formatting error (Wladimir J. van der Laan) 3b092bd util: Properly handle errors during log message formatting (Wladimir J. van der Laan) Tree-SHA512: 85e3b7afec2255fc88034187f1abd6060e9421de17ed4e3d918416f393429a99cc2c974b362099aaaff6970549df47664bea4c857c4e46acc0789663201dc541

…ormatting b651270 util: Throw tinyformat::format_error on formatting error (Wladimir J. van der Laan) 3b092bd util: Properly handle errors during log message formatting (Wladimir J. van der Laan) Tree-SHA512: 85e3b7afec2255fc88034187f1abd6060e9421de17ed4e3d918416f393429a99cc2c974b362099aaaff6970549df47664bea4c857c4e46acc0789663201dc541

…ormatting (#2917) * Merge bitcoin#9963: util: Properly handle errors during log message formatting b651270 util: Throw tinyformat::format_error on formatting error (Wladimir J. van der Laan) 3b092bd util: Properly handle errors during log message formatting (Wladimir J. van der Laan) Tree-SHA512: 85e3b7afec2255fc88034187f1abd6060e9421de17ed4e3d918416f393429a99cc2c974b362099aaaff6970549df47664bea4c857c4e46acc0789663201dc541 * "cast" debugMsg to a c string Signed-off-by: Pasta <Pasta@dash.org> "cast" debugMsg to a c string pt 2 Signed-off-by: Pasta <Pasta@dash.org>

Summary: b651270 util: Throw tinyformat::format_error on formatting error (Wladimir J. van der Laan) 3b092bd util: Properly handle errors during log message formatting (Wladimir J. van der Laan) Tree-SHA512: 85e3b7afec2255fc88034187f1abd6060e9421de17ed4e3d918416f393429a99cc2c974b362099aaaff6970549df47664bea4c857c4e46acc0789663201dc541 Merge #10010: util: rename variable to avoid shadowing 9350e13 util: rename variable to avoid shadowing (Pavol Rusnak) Tree-SHA512: 8abc09fdb134c913e823754f3f02a4d8ef120a73f252fbc1217dbd2bdd4ed4fffce92d823a66d1fe51607dc021065df8826f21274ef26e55d82575e96d07224f Backport of Core PR9963 and PR10010 bitcoin/bitcoin#9963 bitcoin/bitcoin#10010 Also needed to pull a change from PR12954: https://github.com/bitcoin/bitcoin/pull/12954/files#diff-772f489c7d0a32de3badbfbcb5fd200dR69 Test Plan: Change line init.cpp line 1584 to `LogPrintf("Checkpoints will be verified.\n", fCheckpointsEnabled);` make check ./bitcoind Verify the following log message appears at start up: 2020-01-18T00:33:40Z Error "tinyformat: Not enough conversion specifiers in format string" while formatting log message: Checkpoints will be verified. Undo change to init.cpp and repeat above verifying normal, pre-patch behavior Reviewers: deadalnix, Fabien, jasonbcox, O1 Bitcoin ABC, #bitcoin_abc Reviewed By: deadalnix, O1 Bitcoin ABC, #bitcoin_abc Differential Revision: https://reviews.bitcoinabc.org/D5010

…ormatting (dashpay#2917) * Merge bitcoin#9963: util: Properly handle errors during log message formatting b651270 util: Throw tinyformat::format_error on formatting error (Wladimir J. van der Laan) 3b092bd util: Properly handle errors during log message formatting (Wladimir J. van der Laan) Tree-SHA512: 85e3b7afec2255fc88034187f1abd6060e9421de17ed4e3d918416f393429a99cc2c974b362099aaaff6970549df47664bea4c857c4e46acc0789663201dc541 * "cast" debugMsg to a c string Signed-off-by: Pasta <Pasta@dash.org> "cast" debugMsg to a c string pt 2 Signed-off-by: Pasta <Pasta@dash.org>

9fb0a43 util: Throw tinyformat::format_error on formatting error (random-zebra) 67eb699 util: Properly handle errors during log message formatting (random-zebra) 66ec97b Do not evaluate hidden LogPrint arguments (random-zebra) 2713458 util: Remove zero-argument versions of LogPrint and error (random-zebra) 500dfee util: Update tinyformat (random-zebra) 6837887 util: switch LogPrint and error to variadic templates (random-zebra) 0fa578f tinyformat: force USE_VARIADIC_TEMPLATES (random-zebra) Pull request description: this backports the following pull requests from upstream bitcoin: - bitcoin#8000 (0fa578f, 6837887) > Now that we started using c++11, force use of variadic templates. The autodetection may be wonky on some compilers, see discussion here and is unnecessary for us anyhow. - bitcoin#8274 (500dfee, 2713458) > Updates tinyformat.h to commit c42f/tinyformat@3a33bbf upstream. - bitcoin#9417 (66ec97b) > There are a few cases where hashes are computed inside LogPrint arguments - where they usually go unused. As LogPrint statements should never have side effects besides printing something, we can avoid the evaluation in this case. Advantage: perhaps a small performance improvement; I haven't benchmarked. Disadvantage: if we would have statements with side-effects, this could make this a bit harder to debug. - bitcoin#9963 (67eb699, 9fb0a43) > Instead of having an exception propagate into the program (which at worst causes a crash) when an error happens while formatting a log message, just print a message to the log. This message clearly indicates what log message was formatted wrongly, and what error happened during formatting it. ACKs for top commit: Fuzzbawls: ACK 9fb0a43 furszy: cool, utACK 9fb0a43 . Tree-SHA512: 29a902bb712612ca093a8fe863e9eff1c17d40955bbc37a5ceb6f057068ac6150dfcffd6836a6b0bd6295aa9bffd0925eb69e50f82ccaa7d84215efc274a59a4

laanwj added Docs Utils/log/libs labels Mar 9, 2017

util: Properly handle errors during log message formatting

3b092bd

Instead of having an exception propagate into the program when an error happens while formatting a log message, just print a message to the log. Addresses bitcoin#9423.

laanwj force-pushed the 2017_03_handle_exception_tinyformat branch from 9f51fe8 to 3b092bd Compare March 12, 2017 06:58

util: Throw tinyformat::format_error on formatting error

b651270

Throw tinyformat::format_error on formatting error instead of the `std::runtime_error`.

laanwj merged commit b651270 into bitcoin:master Mar 13, 2017

jnewbery mentioned this pull request Mar 31, 2017

Change LogAcceptCategory to use uint32_t rather than sets of strings. #9424

Merged

dagurval mentioned this pull request Jul 6, 2017

Don't throw LogPrint errors bitcoinxt/bitcoinxt#215

Merged

sickpig mentioned this pull request Jan 11, 2018

tinyformat.h upstream changes BitcoinUnlimited/BitcoinUnlimited#903

Merged

laanwj mentioned this pull request Jun 4, 2018

Make tinyformat noexcept: Use default error handling (assert(0 && reason)) on incorrect format strings #13391

Closed

random-zebra mentioned this pull request Mar 23, 2020

[Util] tinyformat / LogPrint backports PIVX-Project/PIVX#1449

Merged

bitcoin locked as resolved and limited conversation to collaborators Sep 8, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

util: Properly handle errors during log message formatting #9963

util: Properly handle errors during log message formatting #9963

Uh oh!

laanwj commented Mar 9, 2017 •

edited

Loading

Uh oh!

TheBlueMatt commented Mar 10, 2017

Uh oh!

laanwj commented Mar 10, 2017

Uh oh!

laanwj commented Mar 10, 2017

Uh oh!

laanwj commented Mar 12, 2017

Uh oh!

TheBlueMatt commented Mar 12, 2017

Uh oh!

laanwj commented Mar 13, 2017 •

edited

Loading

Uh oh!

TheBlueMatt commented Mar 13, 2017 via email

Uh oh!

Uh oh!

util: Properly handle errors during log message formatting #9963

util: Properly handle errors during log message formatting #9963

Uh oh!

Conversation

laanwj commented Mar 9, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Before

After

Uh oh!

TheBlueMatt commented Mar 10, 2017

Uh oh!

laanwj commented Mar 10, 2017

Uh oh!

laanwj commented Mar 10, 2017

Uh oh!

laanwj commented Mar 12, 2017

Uh oh!

TheBlueMatt commented Mar 12, 2017

Uh oh!

laanwj commented Mar 13, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

TheBlueMatt commented Mar 13, 2017 via email

Uh oh!

Uh oh!

laanwj commented Mar 9, 2017 •

edited

Loading

laanwj commented Mar 13, 2017 •

edited

Loading