Skip to content

Conversation

@practicalswift
Copy link
Contributor

@practicalswift practicalswift commented Feb 28, 2018

Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s.

Before this patch:

$ src/bitcoind -printtoconsole
…
2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
2018-02-28 18:37:52 connect() 10.11.21.34:18333 failed after select(): Connection refused (111)
2018-02-28 18:43:22 connect() to 10.11.43.14:18333 failed after select(): Network is unreachable (101)
2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
2018-02-28 18:46:54 connect() to [2001:0:9d38:78ff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)

After this patch:

$ src/bitcoind -printtoconsole
…
2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)

Please note that "manual connect():s" (invoked via -connect, -proxy or addnode) are still reported at the default log level as these messages are likely to be relevant to end-users:

$ src/bitcoind -printtoconsole -connect=127.0.0.1:1234
…
2018-02-28 18:31:13 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

$ src/bitcoind -printtoconsole -proxy=127.0.0.1:1234
…
2018-02-28 18:32:32 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

$ src/bitcoind -printtoconsole &
$ src/bitcoin-cli addnode 127.0.0.1:1234 onetry
…
2018-02-28 18:33:40 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

@practicalswift practicalswift changed the title Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s net: Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s Feb 28, 2018
@randolf
Copy link
Contributor

randolf commented Feb 28, 2018

Just to confirm: With a higher debug level set, all those "connect" errors can still be logged?

@practicalswift
Copy link
Contributor Author

@randolf Exactly :-)

src/net.cpp Outdated
Copy link
Contributor

@Empact Empact Mar 1, 2018

Choose a reason for hiding this comment

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

FYI the style guide prefers the prior style:
"Variable and namespace names are all lowercase, and may use _ to separate words (snake_case)"

src/netbase.cpp Outdated
Copy link
Contributor

Choose a reason for hiding this comment

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

Maybe extract a LogConnectFailure method to DRY these two up?

@practicalswift practicalswift force-pushed the logging-signal-to-noise branch 2 times, most recently from 1bcdf2d to 84b4fe3 Compare March 9, 2018 15:15
@practicalswift
Copy link
Contributor Author

@Empact Thanks for reviewing. Updated in light of review. Please re-review :-)

src/netbase.cpp Outdated
Copy link
Member

@instagibbs instagibbs Mar 9, 2018

Choose a reason for hiding this comment

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

not totally clear to me this should be true?

I admit I don't know the networking code as well.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is the connection to the proxy server. Since the proxy server is specified by the user it is handled as a "manual" connection since any connection errors are likely of relevance to the end-user and thus should be logged. Makes sense? :-)

Copy link
Contributor

@eklitzke eklitzke left a comment

Choose a reason for hiding this comment

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

Concept ACK. Regarding argument forwarding, there's related code for FatalError() in #11857 that I think you could re-use here.

src/netbase.cpp Outdated
Copy link
Contributor

Choose a reason for hiding this comment

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

I know this is annoying, but can you use argument forwarding or make this variadic? That would avoid allocation when the message is not going to be logged.

…en logging failed non-manual connect():s

Before this patch:

```
$ src/bitcoind -printtoconsole
…
2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
2018-02-28T18:37:52Z connect() 10.11.21.34:18333 failed after select(): Connection refused (111)
2018-02-28 18:43:22 connect() to 10.11.43.14:18333 failed after select(): Network is unreachable (101)
2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
2018-02-28 18:46:54 connect() to [2001:0:9d38:78ff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
```

After this patch:

```
$ src/bitcoind -printtoconsole
…
2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
```

Please note that "manual connect():s" (invoked via `-connect`, `-proxy` or `addnode`) are still reported as usual:

```
$ src/bitcoind -printtoconsole -connect=10.11.12.13
…
2018-02-28 18:33:13 connect() to 10.11.12.13:18333 failed after select(): Connection refused (111)
$ src/bitcoind -printtoconsole -proxy=10.11.12.13
…
2018-02-28 18:32:32 connect() to 10.11.12.13:9050 failed after select(): Connection refused (111)
$ src/bitcoind -printtoconsole &
$ src/bitcoin-cli addnode "10.11.12.13" onetry
…
2018-02-28 18:34:40 connect() to 10.11.12.13:18333 failed after select(): Connection refused (111)
```
@practicalswift practicalswift force-pushed the logging-signal-to-noise branch from 84b4fe3 to cba2800 Compare March 11, 2018 09:49
@practicalswift
Copy link
Contributor Author

@eklitzke Good point! Updated. Please re-review :-)

@eklitzke
Copy link
Contributor

That change looks good, but one other thing occurred to me just now. I think we already have special logic for handling peers added using addnode, and that should definitely be treated as a "manual" connection case. Can you take a look at that?

@practicalswift
Copy link
Contributor Author

@eklitzke It already is:

$ src/bitcoind -printtoconsole &
$ src/bitcoin-cli addnode 127.0.0.1:1234 onetry
…
2018-02-28 18:33:40 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

:-)

@sipa
Copy link
Member

sipa commented Mar 17, 2018

utACK cba2800

1 similar comment
@eklitzke
Copy link
Contributor

utACK cba2800

Copy link

@minhhoang123 minhhoang123 left a comment

Choose a reason for hiding this comment

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

Good

@practicalswift
Copy link
Contributor Author

@laanwj Would it be possible to get this PR tagged with a 0.17.0 milestone? :-)

@ajtowns
Copy link
Contributor

ajtowns commented Apr 12, 2018

utACK cba2800

@laanwj laanwj merged commit cba2800 into bitcoin:master Apr 13, 2018
laanwj added a commit that referenced this pull request Apr 13, 2018
…usting log level when logging failed non-manual connect():s

cba2800 Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s (practicalswift)

Pull request description:

  Increase signal-to-noise ratio in `debug.log` by adjusting log level when logging failed non-manual `connect()`:s.

  Before this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:37:52 connect() 10.11.21.34:18333 failed after select(): Connection refused (111)
  2018-02-28 18:43:22 connect() to 10.11.43.14:18333 failed after select(): Network is unreachable (101)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:46:54 connect() to [2001:0:9d38:78ff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  After this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  Please note that "manual `connect()`:s" (invoked via `-connect`, `-proxy` or `addnode`) are still reported at the default log level as these messages are likely to be relevant to end-users:

  ```
  $ src/bitcoind -printtoconsole -connect=127.0.0.1:1234
  …
  2018-02-28 18:31:13 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole -proxy=127.0.0.1:1234
  …
  2018-02-28 18:32:32 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole &
  $ src/bitcoin-cli addnode 127.0.0.1:1234 onetry
  …
  2018-02-28 18:33:40 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)
  ```

Tree-SHA512: 92e3c1e4b54ce8ccdd7ec31de147c8505710cd799ceb2bbc8576a086709967802403c9184df364b3cfa59bd98859f6ac8feb27fb09b9324194c6c47a042fc6d3
PastaPastaPasta pushed a commit to PastaPastaPasta/dash that referenced this pull request Nov 17, 2020
… by adjusting log level when logging failed non-manual connect():s

cba2800 Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s (practicalswift)

Pull request description:

  Increase signal-to-noise ratio in `debug.log` by adjusting log level when logging failed non-manual `connect()`:s.

  Before this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:37:52 connect() 10.11.21.34:18333 failed after select(): Connection refused (111)
  2018-02-28 18:43:22 connect() to 10.11.43.14:18333 failed after select(): Network is unreachable (101)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:46:54 connect() to [2001:0:9d38:78ff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  After this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  Please note that "manual `connect()`:s" (invoked via `-connect`, `-proxy` or `addnode`) are still reported at the default log level as these messages are likely to be relevant to end-users:

  ```
  $ src/bitcoind -printtoconsole -connect=127.0.0.1:1234
  …
  2018-02-28 18:31:13 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole -proxy=127.0.0.1:1234
  …
  2018-02-28 18:32:32 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole &
  $ src/bitcoin-cli addnode 127.0.0.1:1234 onetry
  …
  2018-02-28 18:33:40 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)
  ```

Tree-SHA512: 92e3c1e4b54ce8ccdd7ec31de147c8505710cd799ceb2bbc8576a086709967802403c9184df364b3cfa59bd98859f6ac8feb27fb09b9324194c6c47a042fc6d3

fix compilation

Signed-off-by: pasta <[email protected]>
@practicalswift practicalswift deleted the logging-signal-to-noise branch April 10, 2021 19:33
furszy added a commit to PIVX-Project/PIVX that referenced this pull request Feb 20, 2022
…okup

95bb364 BugFix: activemasternode::init, DMN connectivity check was missing to set the error cause. (furszy)
6e9b6ee trivial: activemasternode clang-tidy cleanups (furszy)
6f4e17c increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s (practicalswift)
889ce4a Fix CActiveMasternodeManager connectivity test (furszy)
34363a5 Fix CActiveMasternodeManager::GetLocalAddress to prefer IPv4 if multiple local addresses are known (UdjinM6)

Pull request description:

  Correcting two issues on the Deterministic Masternode operator side:

  1) The DMN service address connectivity check was not being performed (due a non-initialized socket), failing all-the-time on testnet and mainnet. Erring out at startup.

  2) `CActiveMasternodeManager::GetLocalAddress` will prefer IPv4 if there are multiple addresses available locally. --> dashpay#3304.

  3)  `CActiveMasternodeManager::Init` connectivity check was missing to set the error cause.

  Plus, now that i'm here, ported bitcoin#12569 as well.

ACKs for top commit:
  random-zebra:
    ACK 95bb364
  Fuzzbawls:
    ACK 95bb364

Tree-SHA512: 1b1616ddae8f73832d0e5d9b7a30714e2bee223a4348a453d8802371becab073421c105d47974698ddb19a087967892ac703a25413942139170e098f68827203
gades pushed a commit to cosanta/cosanta-core that referenced this pull request Mar 17, 2022
… by adjusting log level when logging failed non-manual connect():s

cba2800 Increase signal-to-noise ratio in debug.log by adjusting log level when logging failed non-manual connect():s (practicalswift)

Pull request description:

  Increase signal-to-noise ratio in `debug.log` by adjusting log level when logging failed non-manual `connect()`:s.

  Before this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:37:52 connect() 10.11.21.34:18333 failed after select(): Connection refused (111)
  2018-02-28 18:43:22 connect() to 10.11.43.14:18333 failed after select(): Network is unreachable (101)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:46:54 connect() to [2001:0:9d38:78ff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:48:56 connect() to [2001:0:9d38:6aff:1234:1234:1234:1234]:18333 failed: Network is unreachable (101)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  After this patch:

  ```
  $ src/bitcoind -printtoconsole
  …
  2018-02-28 18:42:51 UpdateTip: new best=0000000000005448b10a219683d34b770a28044e1cc421032dea1a79ff548948 height=1286903 version=0x20000000 log2_work=69.791313 tx=17408546 date='2018-02-28 18:42:46' progress=1.000000 cache=0.0MiB(173txo)
  2018-02-28 18:44:49 UpdateTip: new best=000000000000029a521ff2803e1441b09413b876accff5084a4cccf7747d798b height=1286904 version=0x20000000 log2_work=69.791345 tx=17408559 date='2018-02-28 18:44:51' progress=1.000000 cache=0.1MiB(502txo)
  2018-02-28 18:49:11 UpdateTip: new best=000000000000000206b79eb235e5dd907b6369de0e5d764330bf40ec0d460311 height=1286905 version=0x20000000 log2_work=69.791377 tx=17408577 date='2018-02-28 18:49:12' progress=1.000000 cache=1.0MiB(5245txo)
  ```

  Please note that "manual `connect()`:s" (invoked via `-connect`, `-proxy` or `addnode`) are still reported at the default log level as these messages are likely to be relevant to end-users:

  ```
  $ src/bitcoind -printtoconsole -connect=127.0.0.1:1234
  …
  2018-02-28 18:31:13 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole -proxy=127.0.0.1:1234
  …
  2018-02-28 18:32:32 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)

  $ src/bitcoind -printtoconsole &
  $ src/bitcoin-cli addnode 127.0.0.1:1234 onetry
  …
  2018-02-28 18:33:40 connect() to 127.0.0.1:1234 failed after select(): Connection refused (111)
  ```

Tree-SHA512: 92e3c1e4b54ce8ccdd7ec31de147c8505710cd799ceb2bbc8576a086709967802403c9184df364b3cfa59bd98859f6ac8feb27fb09b9324194c6c47a042fc6d3

fix compilation

Signed-off-by: pasta <[email protected]>
@bitcoin bitcoin locked as resolved and limited conversation to collaborators Aug 18, 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.

10 participants