No feeler connection is made when our tip is stale #15484

<!-- This issue tracker is only for technical issues related to Bitcoin Core. General bitcoin questions and/or support requests are best directed to the Bitcoin StackExchange at https://bitcoin.stackexchange.com. For reporting security issues, please read instructions at https://bitcoincore.org/en/contact/. If the node is "stuck" during sync or giving "block checksum mismatch" errors, please ensure your hardware is stable by running memtest and observe CPU temperature with a load-test tool such as linpack before creating an issue! -->

<!-- Describe the issue -->

I run several Bitcoin nodes on Amazon EC2 and notice some of them stop making feeler connections after a while. I checked the debug.log of the nodes and see that "Potential stale tip detected, will try using extra outbound peer" messages are printed out frequently, up to 10+ per day. The messages appear more frequently when the feeler connections disappear.

<!--- What behavior did you expect? -->

I expect the nodes still make feeler connections in between events of the 9th outgoing connection made because of the stale tip. I presume SetTryNewOutboundPeer() incorrectly set the flags somewhere so that fFeeler is always false.

<!--- What was the actual behavior (provide screenshots if the issue is GUI-related)? -->

<!--- How reliably can you reproduce the issue, what are the steps to do so? -->

The problem happens naturally for some nodes after running 20-30 days. All nodes are running Bitcoin core 0.17.0 by default non-stop on Ubuntu 18.04 LTS and with some minimal logging messages I added myself.
I tried to restart one node and the problem is gone. I guess because outgoing peers have been chosen again when node restarts.

<!-- What version of Bitcoin Core are you using, where did you get it (website, self-compiled, etc)? -->

<!-- What type of machine are you observing the error on (OS/CPU and disk type)? -->

<!-- For the GUI-related issue on Linux provide names and versions of a distro, a desktop environment and a graphical shell (if relevant). -->

<!-- Any extra information that might be useful in the debugging process. -->

<!--- This is normally the contents of a `debug.log` or `config.log` file. Raw text or a link to a pastebin type site are preferred. -->

Thanks for the bug report. Can you share a debug.log from a node affected by the issue? If there might be sensitive information in it (wallet-related logs, IP addresses, etc) I am mostly interested in the debug messages around the relevant networking code, consisting of lines that include: UpdateTip, Potential stale tip, disconnecting extra outbound peer, keeping outbound peer, setting try another outbound peer, and Making feeler connection.

Thanks for the response. As I described in the issue, I only run the default client only with some additional logging messages. I didn't turn on the debug=net, unfortunately. I was looking for how IPs are inserted into new and tried table, actually, hence the logging messages are quite different. My logging messages include almost all messages you requested actually, except "setting try another outbound peer". Here is the link to the shortened debug.log: https://www.dropbox.com/s/769tyk1ftfpv3yh/shortened_debug.log?dl=0

I don't see any UpdateTip messages in there, could you please re-post with those included?

I checked the original debug.log. There is no "UpdateTip" message. Do you expect to see log message record by the following line? https://github.com/bitcoin/bitcoin/blob/master/src/validation.cpp#L2263 If so, there is no such message in the original debug.log as well.

Could you please include the Bitcoin Core commit you built from and what local changes you made?

I think whatever bug is going on here is occurring on my own node as well; thanks again for this report, I'll take a look at my local logs and see what I can find.

Great, thanks! FYI, I built from 0.17.0 release: https://github.com/bitcoin/bitcoin/archive/v0.17.0.zip I only added a few logging messages in addrman.cpp, net_processing.cpp and net.cpp.

ping @EthanHeilman

I think this is a buggy interaction between addrman and net relating to collisions and feelers. If we encounter a collision in the tried table with something in a network group that we already have an outbound connection to, then we can get stuck with an entry in m_tried_collisions that will never be resolved.

In the debug.log you posted, I noticed that the feelers stopped regularly happening when the addrman encountered a collision in the tried table:

2019-01-30T18:43:09Z ResolveCollisions_, 78.108.187.246:8333, Collision with 35.178.76.8:8333 in tried table at Bucket = 181 and Slot = 28

At the time that this collision with 35.178.76.8 occurred, your node was already connected outbound to another node with the same network group:

2019-01-27T02:17:23Z ProcessMessage, VERACK, New outgoing connection: peeraddr=35.178.95.164:8333 , number of incoming: 68 , number of outgoing: 8 

Here's the relevant code snippet from CConnMan::ThreadOpenConnections() that shows what happens:

https://github.com/bitcoin/bitcoin/blob/master/src/net.cpp#L1755-L1801

In particular, in our loop where we try to send a feeler connection to something that had a collision, we break if the address is to something in a network group we're already connected to. However the collision cannot be resolved until we try to connect to the ip address and fail; here is the relevant code from the addrman's ResolveCollisions():

https://github.com/bitcoin/bitcoin/blob/master/src/addrman.cpp#L551-L571

So we get stuck, with no way to try more feelers, and no way to connect to the one the feeler code would like to test.

I'm not sure what the best fix is; I think we could either connect a feeler anyway to things in the same network group, or we could make it so that nothing stays in the m_tried_collisions set for too long before being resolved somehow, or both... @muoitranduc Your debug.log that shows both colliding entries was very helpful for tracking this down!

I think we could either connect a feeler anyway to things in the same network group, or we could make it so that nothing stays in the m_tried_collisions set for too long before being resolved somehow, or both...

I agree with doing both fixes:

1. Having it ignore groups is the right behavior.
2. However we need a way to clear out an addr that is repeatedly being test and not being resolved.

Following up on whether #15486 resolved this issue or if additional logic to ResolveCollisions() is needed as per @sdaftuar's comment. cc @muoitranduc

From email with @muoitranduc:

"...we couldn't reproduce the corner cases that we faced with our newly-spawned nodes. I understand that the logic has been modified even further with the anchor connections. Hence, I guess it is safe to close the issue because its only purpose is to guarantee feeler connections can be established."

This looks like it can be closed.