premise: backoff keeps growing after a quick off/on during sleep
there is a subtle gap in how ThreadControl handles backoff timeouts during rapid state toggles i.e. something that could happen when automated scripts or tests issue setnetworkactive false followed immediately by setnetworkactive true
if the node is currently in a backoff sleep (say, waiting 30 seconds after several failed Tor connection attempts) and a script toggles the network off and back on within that single sleep window, SleepWithNetworkPolling wakes up early due to the change count. however, because the script already flipped network activity back to true, the live if (!m_network_active) check evaluates to false. execution then falls through directly into growing the backoff delay (m_reconnect_timeout *= RECONNECT_TIMEOUT_EXP), punishing the node with a longer reconnect delay instead of resetting it back to 1.0s despite a fresh reactivation occurring
the test below reproduces this by doing the off/on calls back-to-back while the node is inside a reconnect sleep. the next retry incorrectly gets the grown delay (1.5s) instead of starting again at 1.0s:
<details>
<summary>diff
</summary>
diff --git a/test/functional/feature_torcontrol.py b/test/functional/feature_torcontrol.py
index 7a6fc4e6c0..053fc65b3f 100755
--- a/test/functional/feature_torcontrol.py
+++ b/test/functional/feature_torcontrol.py
@@ -313,6 +313,40 @@ class TorControlTest(BitcoinTestFramework):
], timeout=2):
node.setnetworkactive(state=True)
+ def test_networkactive_race_during_backoff(self):
+ self.log.info("Test that a rapid off->on cycle during a reconnect backoff sleep still resets the backoff")
+
+ node = self.nodes[0]
+
+ # nothing listens on 127.0.0.1:1, so every connection attempt fails
+ # immediately thus the retry/backoff cycle is predictable: the first
+ # retry is always logged at RECONNECT_TIMEOUT_START (1.0s)
+ with node.assert_debug_log(expected_msgs=["Retrying in 1.0 seconds"], timeout=10):
+ self.restart_node(0, extra_args=[
+ "-torcontrol=127.0.0.1:1",
+ "-listenonion=1",
+ "-debug=tor",
+ ])
+
+ # we are now inside that first ~1.0s backoff sleep. toggle the network
+ # off then immediately back on, as quick as possible, so the whole
+ # round trip lands inside this single sleep window rather than
+ # spanning two separate ThreadControl loop iterations
+ node.setnetworkactive(state=False)
+ node.setnetworkactive(state=True)
+
+ # a reactivation should always reset the backoff to
+ # RECONNECT_TIMEOUT_START, regardless of whether the deactivate/
+ # reactivate pair happened between loop iterations or inside one
+ # backoff sleep. so the *next* retry should again log 1.0s, not a
+ # grown value (i.e. 1.5s) carried over from before the toggle
+ with node.assert_debug_log(
+ expected_msgs=["Retrying in 1.0 seconds"],
+ unexpected_msgs=["Retrying in 1.5 seconds"],
+ timeout=3,
+ ):
+ pass
+
def run_test(self):
self.test_basic()
self.test_partial_data()
@@ -321,6 +355,7 @@ class TorControlTest(BitcoinTestFramework):
self.test_overmany_lines()
self.test_networkactive()
self.test_networkactive_reactivation_resets_backoff()
+ self.test_networkactive_race_during_backoff()
if __name__ == '__main__':
</details>
potential fix
the fix is to check whether the network-active change count changed during the sleep itself. if it did and the network is active again, treat that as a fresh reactivation & reset the backoff:
<details open>
<summary>diff
</summary>
diff --git a/src/torcontrol.cpp b/src/torcontrol.cpp
index dfded42746..5cfaaad515 100644
--- a/src/torcontrol.cpp
+++ b/src/torcontrol.cpp
@@ -447,11 +447,14 @@ void TorController::ThreadControl()
LogDebug(BCLog::TOR, "Retrying in %.1f seconds", m_reconnect_timeout.count());
const auto change_count{m_network_active_change_count.load()};
if (!SleepWithNetworkPolling(std::chrono::duration_cast<std::chrono::milliseconds>(m_reconnect_timeout), change_count) && m_interrupt) {
break;
}
- if (!m_network_active) {
+ if (change_count != m_network_active_change_count.load()) {
+ if (m_network_active) {
+ m_reconnect_timeout = RECONNECT_TIMEOUT_START;
+ }
continue;
}
m_reconnect_timeout = std::min(m_reconnect_timeout * RECONNECT_TIMEOUT_EXP, RECONNECT_TIMEOUT_MAX);
continue;
}
</details>
[!NOTE]
this gap will not crash the node. it quietly increases the delay before Tor Control reconnects, which can be annoying and surprising, but it is not dangerous. if it happens repeatedly, the delay can compound noticeably, but the node will eventually reconnect once the delay elapses
thoughts ?
