net: Log to net category for exceptions in ProcessMessages

laanwj commented at 3:09 pm on December 17, 2019: member

Remove the forest of special exceptions based on string matching, and simply log a short message to the NET logging category when an exception happens during packet processing. It is not good to panick end users with verbose errors (let alone writing to stderr) when any peer can generate them.

Remove the forest of special exceptions, and simply log a short
message to the NET logging category when an exception happens during
packet processing. It is not good to panick end users with errors
that any peer can generate (let alone writing to stderr).

4d88c3dcb6

laanwj added the label P2P on Dec 17, 2019

practicalswift commented at 3:31 pm on December 17, 2019: contributor

Tested ACK 4d88c3dcb61e7c075ed3dd442044e0eff4e3c8de

MarcoFalke commented at 3:54 pm on December 17, 2019: member

Concept ACK. I probably should have done this in #16021.

in src/net_processing.cpp:3339 in 4d88c3dcb6 outdated

3359-        PrintExceptionContinue(&e, "ProcessMessages()");
3360+    } catch (const std::exception& e) {
3361+        LogPrint(BCLog::NET, "%s(%s, %u bytes): Exception '%s' (%s) caught\n", __func__, SanitizeString(strCommand), nMessageSize, e.what(), typeid(e).name());
3362     } catch (...) {
3363-        PrintExceptionContinue(nullptr, "ProcessMessages()");
3364+        LogPrint(BCLog::NET, "%s(%s, %u bytes): Unknown exception caught\n", __func__, SanitizeString(strCommand), nMessageSize);

promag commented at 11:44 am on December 20, 2019:

nit, unexpected or unhandled instead or unknown?

laanwj commented at 7:43 pm on January 2, 2020:

It’s really unknown. All known exceptions go to the other path. If it ends up here, some really weird code (maybe in a dependency?) threw an integer or bare string or such.

promag commented at 11:45 am on December 20, 2019: member

ACK 4d88c3dcb61e7c075ed3dd442044e0eff4e3c8de.

in src/net_processing.cpp:3337 in 4d88c3dcb6 outdated

3356-        }
3357-    }
3358-    catch (const std::exception& e) {
3359-        PrintExceptionContinue(&e, "ProcessMessages()");
3360+    } catch (const std::exception& e) {
3361+        LogPrint(BCLog::NET, "%s(%s, %u bytes): Exception '%s' (%s) caught\n", __func__, SanitizeString(strCommand), nMessageSize, e.what(), typeid(e).name());

jnewbery commented at 4:55 pm on December 20, 2019:

What is typeid(e).name() for here? Here’s what an example log looks like:

[msghand] ProcessMessages(tx, 85 bytes): Exception 'Superfluous witness record: iostream error' (NSt8ios_base7failureB5cxx11E) caught

Does that (NSt8ios_base7failureB5cxx11E) add any helpful information to the user?

According to https://en.cppreference.com/w/cpp/language/typeid, you need to include <typeinfo> to use typeid():

The header <typeinfo> must be included before using typeid (if the header is not included, every use of the keyword typeid makes the program ill-formed.)

hebasto commented at 7:50 pm on December 20, 2019:

And name():

Returns an implementation defined null-terminated character string containing the name of the type. No guarantees are given; in particular, the returned string can be identical for several types and change between invocations of the same program.

On Linux Mint 19.3 (GCC 7.4.0) with included <typeinfo> the output remains the same: something like ...(NSt8ios_base7failureB5cxx11E)....

hebasto commented at 7:59 pm on December 20, 2019:

Also we use the same approach here (line 544): https://github.com/bitcoin/bitcoin/blob/0cda5573405d75d695aba417e8f22f1301ded001/src/util/system.cpp#L542-L547

laanwj commented at 7:40 pm on January 2, 2020:

This was simply borrowed from the exception logging function that we’ve already used since Satoshi’s days. I think the idea is that it shows the type in case the exception message is not informative, I’m ok with removing it, no opinion, but I don’t think it hurts…

laanwj commented at 7:46 pm on January 2, 2020:

I’ll add a commit that adds #include <typeinfo> to here and system.cpp. I think that’s a good point, though no C++ compiler seems to have stumbled over it.

jnewbery commented at 5:02 pm on December 20, 2019: member

Concept ACK. One question about typeid() inline.

MarcoFalke commented at 5:04 pm on December 20, 2019: member

ACK 4d88c3dcb61e7c075ed3dd442044e0eff4e3c8de 👃

Tested both cases:

Normal exception:

2019-12-20T16:50:10.551972Z [msghand] received: tx (85 bytes) peer=2
2019-12-20T16:50:10.552100Z [msghand] ProcessMessages(tx, 85 bytes): Exception ‘Superfluous witness record: iostream error’ (NSt8ios_base7failureB5cxx11E) caught
2019-12-20T16:50:10.552120Z [msghand] ProcessMessages(tx, 85 bytes) FAILED peer=2

Something else:

2019-12-20T17:03:18.898307Z [msghand] received: tx (85 bytes) peer=2
2019-12-20T17:03:18.898406Z [msghand] ProcessMessages(tx, 85 bytes): Unknown exception caught
2019-12-20T17:03:18.898421Z [msghand] ProcessMessages(tx, 85 bytes) FAILED peer=2

Signature:

 0-----BEGIN PGP SIGNED MESSAGE-----
 1Hash: SHA512
 2
 3ACK 4d88c3dcb61e7c075ed3dd442044e0eff4e3c8de 👃
 4
 5Tested both cases:
 6
 7* Normal exception:
 8
 9 - 2019-12-20T16:50:10.551972Z [msghand] received: tx (85 bytes) peer=2
10 - 2019-12-20T16:50:10.552100Z [msghand] ProcessMessages(tx, 85 bytes): Exception 'Superfluous witness record: iostream error' (NSt8ios_base7failureB5cxx11E) caught
11 - 2019-12-20T16:50:10.552120Z [msghand] ProcessMessages(tx, 85 bytes) FAILED peer=2
12
13* Something else:
14
15 - 2019-12-20T17:03:18.898307Z [msghand] received: tx (85 bytes) peer=2
16 - 2019-12-20T17:03:18.898406Z [msghand] ProcessMessages(tx, 85 bytes): Unknown exception caught
17 - 2019-12-20T17:03:18.898421Z [msghand] ProcessMessages(tx, 85 bytes) FAILED peer=2
18-----BEGIN PGP SIGNATURE-----
19
20iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
21pUjeMwwArad7Z2G99LooWjtt7/fr7X2kNavsjZh1YvI8AytS/9uZkURdVFg96geY
22Q3jJqisfbeNTwJm0zsNbSWChN5OlWrZ8naGMDfyALM0oQXzj5rgCZM5WIZta4Me9
23XDFq4upRfvg5QhmFI1feGX4mIYqdf2YlxYjkLz293rvTRTnQsEJ655tk1uWrm1jK
24SnGKtv29IKNO0yEb4WOE4pB7muzlf3mXVO9K+21HglK5qY3Opy7hkO8NsJSpilvz
25Gr4Y8yJFhJMWL8gG3fZb/YaViDzcNanbjMNXTUHIwMQZ6sQhOpDvXKYNvyNJG8Di
261xleSq1lEHp/nAdPor29fMCLVaSi7EY7A32LetW7SE30I6zbqlbH3XW4rg/mgiHr
27bzoz/yJT6vrxRm8BOLYu9PjQLhKOVeDL0iGmxQaHxUdnpDdlQUYgjTeCcGUFMptB
28vwD7xTEfgFdeBQuDjwFccpDDgUdUO8FBtFBHxxOEa1VVHtEvteRRvMzXCnJFaR0K
29NONhQti2
30=lSTE
31-----END PGP SIGNATURE-----

Timestamp of file with hash df6e3a596aced982ab075caecb0b392dea1ae5573fef22c74d4cdd198ffc188c -

hebasto commented at 7:22 pm on December 20, 2019: member

Concept ACK.

Add missing typeinfo includes

The use of `typeid()` for logging exception types requires this include
according to https://en.cppreference.com/w/cpp/language/typeid.

4bdd68f301

MarcoFalke commented at 8:15 pm on January 2, 2020: member

re-ACK 4bdd68f301a9cee3360deafc7531c638e923226b (only change is adding includes) 🕕

Signature:

 0-----BEGIN PGP SIGNED MESSAGE-----
 1Hash: SHA512
 2
 3re-ACK 4bdd68f301a9cee3360deafc7531c638e923226b (only change is adding includes) 🕕
 4-----BEGIN PGP SIGNATURE-----
 5
 6iQGzBAEBCgAdFiEE+rVPoUahrI9sLGYTzit1aX5ppUgFAlwqrYAACgkQzit1aX5p
 7pUguNgwAoLtUwlt9Rl8Fd4Kkhw+iyyVzIoIfk+HL6LcG9BqfDfttfcijBiynEtNV
 829HzFgff3tiBWuYeN013IqeW1rE3MYxI4pDpGqeaWKkoj9YA6PW/jPWj8okAGzAC
 9aYsI/2cT/H6Ea/WL7foSeMejRryRLQfD8Jg241g4Rm8iPEm0U0Tqgk5s9oqzDfMi
10J1R8Et1yDZo6+enk03ytF1WW3X+SN5PkI6M4CfShnf4ZxRyQ8atYUhRMOfOb8xFA
11vu2HKtYE+oWmFTfR1j6k5A9VO5ezOeL24nF8XP8FV+bcH7evzMOvudwdNMVuKag/
12giW1i/ElaqHLZvTXxV1jGcu4/Vu1NfvylHQLuOft8H2BORe+OBrXAXT+qIpG5DtA
13q2xyhHCfkJwItwQAMGYhauHISq93NA77CNENxyxKPvupAMfwuViYYYG+gQ8cOXg9
145YQ7GhkTFtCrTqU7abF/66XU62NKAEXvzJCjlF+/WzILoPncYAjTQcNO71pHMKYL
15lM2l3l5j
16=8t8Y
17-----END PGP SIGNATURE-----

Timestamp of file with hash f5a70ac73ac8d01fd424479a9ace0934a6de8392add537503e92e054731e2b32 -

promag commented at 8:18 pm on January 2, 2020: member

ACK 4bdd68f301a9cee3360deafc7531c638e923226b, could squash.

laanwj referenced this in commit 190a4051fd on Jan 2, 2020

laanwj merged this on Jan 2, 2020

laanwj closed this on Jan 2, 2020

sidhujag referenced this in commit 6cfd75fa22 on Jan 4, 2020

laanwj added the label Needs backport (0.19) on Jan 4, 2020

fanquake referenced this in commit 1a6a534665 on Jan 4, 2020

fanquake referenced this in commit 112144dc52 on Jan 4, 2020

fanquake removed the label Needs backport (0.19) on Jan 5, 2020

fanquake commented at 11:59 pm on January 5, 2020: member

Being backported in 17858.

laanwj referenced this in commit bb123c6527 on Jan 8, 2020

instagibbs referenced this in commit c89611ebd3 on Jan 22, 2020

practicalswift commented at 5:32 pm on January 22, 2020: contributor

Reviewers of this PR might want to review the somewhat related PR #17828 (“net: Use log categories when logging events that P2P peers can trigger arbitrarily”).

fanquake referenced this in commit 8b67698420 on Jan 23, 2020

fanquake commented at 2:08 am on January 23, 2020: member

This was backported to the 0.18 branch in #17974.

MarkLTZ referenced this in commit 2e6abb1507 on Mar 13, 2020

MarkLTZ referenced this in commit ece88bae51 on Mar 13, 2020

sidhujag referenced this in commit 1e6107c1d1 on Nov 10, 2020

jasonbcox referenced this in commit 39bcc7aeb4 on Nov 13, 2020

Munkybooty referenced this in commit 861ef02929 on Dec 9, 2021

Munkybooty referenced this in commit fc6f77f098 on Dec 9, 2021

Munkybooty referenced this in commit e32f0d5d86 on Dec 9, 2021

Munkybooty referenced this in commit 16f7583e71 on Dec 23, 2021

DrahtBot locked this on Feb 15, 2022

net: Log to net category for exceptions in ProcessMessages #17762