Merge bitcoin#27622: Fee estimation: avoid serving stale fee estimate

d2b39e0 test: ensure old fee_estimate.dat not read on restart and flushed (ismaelsadeeq)
cf219f2 tx fees, policy: read stale fee estimates with a regtest-only option (ismaelsadeeq)
3eb241a tx fees, policy: do not read estimates of old fee_estimates.dat (ismaelsadeeq)
5b886f2 tx fees, policy: periodically flush fee estimates to fee_estimates.dat (ismaelsadeeq)

Pull request description:

  Fixes bitcoin#27555

  The issue arises when an old `fee_estimates.dat` file is sometimes read during initialization.
  Or after an unclean shutdown, the latest fee estimates are not flushed to `fee_estimates.dat`.
  If the fee estimates in the old file are old, they can cause transactions to become stuck in the mempool.
  This  PR ensures that nodes do not use stale estimates from the old file during initialization. If  `fee_estimates.dat`
  has not been updated for 60 hours or more, it is considered stale and will not be read during initialization. To avoid
  having old estimates, the `fee_estimates.dat` file will be flushed periodically every hour. As mentioned bitcoin#27555

  > "The immediate improvement would be to store fee estimates to disk once an hour or so to reduce the chance of having an old file. From there, this case could probably be detected, and refuse to serve estimates until we sync."

  In addition, I will follow-up PR to persist the `mempoolminfee` across restarts.

ACKs for top commit:
  willcl-ark:
    ACK d2b39e0
  instagibbs:
    reACK bitcoin@d2b39e0
  glozow:
    ACK d2b39e0. One nit if you follow up.

Tree-SHA512: 4f6e0c296995d0eea5cf80c6aefdd79b7295a6a0ba446f2166f32afc105fe4f831cfda1ad3abd13c5c752b4fbea982cf4b97eaeda2af1fd7184670d41edcfeec

Author: glozow

src/init.cpp

@@ -83,6 +83,7 @@
 #include <util/syserror.h>
 #include <util/thread.h>
 #include <util/threadnames.h>
+#include <util/time.h>
 #include <util/translation.h>
 #include <validation.h>
 #include <validationinterface.h>
@@ -586,6 +587,7 @@ void SetupServerArgs(ArgsManager& argsman)
     argsman.AddArg("-acceptnonstdtxn", strprintf("Relay and mine \"non-standard\" transactions (%sdefault: %u)", "testnet/regtest only; ", !testnetChainParams->RequireStandard()), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::NODE_RELAY);
     argsman.AddArg("-incrementalrelayfee=<amt>", strprintf("Fee rate (in %s/kvB) used to define cost of relay, used for mempool limiting and replacement policy. (default: %s)", CURRENCY_UNIT, FormatMoney(DEFAULT_INCREMENTAL_RELAY_FEE)), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::NODE_RELAY);
     argsman.AddArg("-dustrelayfee=<amt>", strprintf("Fee rate (in %s/kvB) used to define dust, the value of an output such that it will cost more than its value in fees at this fee rate to spend it. (default: %s)", CURRENCY_UNIT, FormatMoney(DUST_RELAY_TX_FEE)), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::NODE_RELAY);
+    argsman.AddArg("-acceptstalefeeestimates", strprintf("Read fee estimates even if they are stale (%sdefault: %u) fee estimates are considered stale if they are %s hours old", "regtest only; ", DEFAULT_ACCEPT_STALE_FEE_ESTIMATES, Ticks<std::chrono::hours>(MAX_FILE_AGE)), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::DEBUG_TEST);
     argsman.AddArg("-bytespersigop", strprintf("Equivalent bytes per sigop in transactions for relay and mining (default: %u)", DEFAULT_BYTES_PER_SIGOP), ArgsManager::ALLOW_ANY, OptionsCategory::NODE_RELAY);
     argsman.AddArg("-datacarrier", strprintf("Relay and mine data carrier transactions (default: %u)", DEFAULT_ACCEPT_DATACARRIER), ArgsManager::ALLOW_ANY, OptionsCategory::NODE_RELAY);
     argsman.AddArg("-datacarriersize", strprintf("Maximum size of data in data carrier transactions we relay and mine (default: %u)", MAX_OP_RETURN_RELAY), ArgsManager::ALLOW_ANY, OptionsCategory::NODE_RELAY);
@@ -1253,7 +1255,17 @@ bool AppInitMain(NodeContext& node, interfaces::BlockAndHeaderTipInfo* tip_info)
     assert(!node.fee_estimator);
     // Don't initialize fee estimation with old data if we don't relay transactions,
     // as they would never get updated.
-    if (!ignores_incoming_txs) node.fee_estimator = std::make_unique<CBlockPolicyEstimator>(FeeestPath(args));
+    if (!ignores_incoming_txs) {
+        bool read_stale_estimates = args.GetBoolArg("-acceptstalefeeestimates", DEFAULT_ACCEPT_STALE_FEE_ESTIMATES);
+        if (read_stale_estimates && (chainparams.GetChainType() != ChainType::REGTEST)) {
+            return InitError(strprintf(_("acceptstalefeeestimates is not supported on %s chain."), chainparams.GetChainTypeString()));
+        }
+        node.fee_estimator = std::make_unique<CBlockPolicyEstimator>(FeeestPath(args), read_stale_estimates);
+
+        // Flush estimates to disk periodically
+        CBlockPolicyEstimator* fee_estimator = node.fee_estimator.get();
+        node.scheduler->scheduleEvery([fee_estimator] { fee_estimator->FlushFeeEstimates(); }, FEE_FLUSH_INTERVAL);
+    }
 
     // Check port numbers
     for (const std::string port_option : {

src/policy/fees.cpp

@@ -24,6 +24,7 @@
 
 #include <algorithm>
 #include <cassert>
+#include <chrono>
 #include <cmath>
 #include <cstddef>
 #include <cstdint>
@@ -527,7 +528,7 @@ bool CBlockPolicyEstimator::_removeTx(const uint256& hash, bool inBlock)
     }
 }
 
-CBlockPolicyEstimator::CBlockPolicyEstimator(const fs::path& estimation_filepath)
+CBlockPolicyEstimator::CBlockPolicyEstimator(const fs::path& estimation_filepath, const bool read_stale_estimates)
     : m_estimation_filepath{estimation_filepath}
 {
     static_assert(MIN_BUCKET_FEERATE > 0, "Min feerate must be nonzero");
@@ -545,9 +546,22 @@ CBlockPolicyEstimator::CBlockPolicyEstimator(const fs::path& estimation_filepath
     shortStats = std::unique_ptr<TxConfirmStats>(new TxConfirmStats(buckets, bucketMap, SHORT_BLOCK_PERIODS, SHORT_DECAY, SHORT_SCALE));
     longStats = std::unique_ptr<TxConfirmStats>(new TxConfirmStats(buckets, bucketMap, LONG_BLOCK_PERIODS, LONG_DECAY, LONG_SCALE));
 
-    // If the fee estimation file is present, read recorded estimations
     AutoFile est_file{fsbridge::fopen(m_estimation_filepath, "rb")};
-    if (est_file.IsNull() || !Read(est_file)) {
+
+    // Whenever the fee estimation file is not present return early
+    if (est_file.IsNull()) {
+        LogPrintf("%s is not found. Continue anyway.\n", fs::PathToString(m_estimation_filepath));
+        return;
+    }
+
+    std::chrono::hours file_age = GetFeeEstimatorFileAge();
+    // fee estimate file must not be too old to avoid wrong fee estimates.
+    if (file_age > MAX_FILE_AGE && !read_stale_estimates) {
+        LogPrintf("Fee estimation file %s too old (age=%lld > %lld hours) and will not be used to avoid serving stale estimates.\n", fs::PathToString(m_estimation_filepath), Ticks<std::chrono::hours>(file_age), Ticks<std::chrono::hours>(MAX_FILE_AGE));
+        return;
+    }
+
+    if (!Read(est_file)) {
         LogPrintf("Failed to read fee estimates from %s. Continue anyway.\n", fs::PathToString(m_estimation_filepath));
     }
 }
@@ -903,10 +917,16 @@ CFeeRate CBlockPolicyEstimator::estimateSmartFee(int confTarget, FeeCalculation
 
 void CBlockPolicyEstimator::Flush() {
     FlushUnconfirmed();
+    FlushFeeEstimates();
+}
 
+void CBlockPolicyEstimator::FlushFeeEstimates()
+{
     AutoFile est_file{fsbridge::fopen(m_estimation_filepath, "wb")};
     if (est_file.IsNull() || !Write(est_file)) {
         LogPrintf("Failed to write fee estimates to %s. Continue anyway.\n", fs::PathToString(m_estimation_filepath));
+    } else {
+        LogPrintf("Flushed fee estimates to %s.\n", fs::PathToString(m_estimation_filepath.filename()));
     }
 }
 
@@ -1011,6 +1031,13 @@ void CBlockPolicyEstimator::FlushUnconfirmed()
     LogPrint(BCLog::ESTIMATEFEE, "Recorded %u unconfirmed txs from mempool in %gs\n", num_entries, Ticks<SecondsDouble>(endclear - startclear));
 }
 
+std::chrono::hours CBlockPolicyEstimator::GetFeeEstimatorFileAge()
+{
+    auto file_time = std::filesystem::last_write_time(m_estimation_filepath);
+    auto now = std::filesystem::file_time_type::clock::now();
+    return std::chrono::duration_cast<std::chrono::hours>(now - file_time);
+}
+
 static std::set<double> MakeFeeSet(const CFeeRate& min_incremental_fee,
                                    double max_filter_fee_rate,
                                    double fee_filter_spacing)

src/policy/fees.h

@@ -14,12 +14,25 @@
 #include <util/fs.h>
 
 #include <array>
+#include <chrono>
 #include <map>
 #include <memory>
 #include <set>
 #include <string>
 #include <vector>
 
+
+// How often to flush fee estimates to fee_estimates.dat.
+static constexpr std::chrono::hours FEE_FLUSH_INTERVAL{1};
+
+/** fee_estimates.dat that are more than 60 hours (2.5 days) will not be read,
+ * as the estimates in the file are stale.
+ */
+static constexpr std::chrono::hours MAX_FILE_AGE{60};
+
+// Whether we allow importing a fee_estimates file older than MAX_FILE_AGE.
+static constexpr bool DEFAULT_ACCEPT_STALE_FEE_ESTIMATES{false};
+
 class AutoFile;
 class CTxMemPoolEntry;
 class TxConfirmStats;
@@ -183,7 +196,7 @@ class CBlockPolicyEstimator
     const fs::path m_estimation_filepath;
 public:
     /** Create new BlockPolicyEstimator and initialize stats tracking classes with default values */
-    CBlockPolicyEstimator(const fs::path& estimation_filepath);
+    CBlockPolicyEstimator(const fs::path& estimation_filepath, const bool read_stale_estimates);
     ~CBlockPolicyEstimator();
 
     /** Process all the transactions that have been included in a block */
@@ -239,6 +252,13 @@ class CBlockPolicyEstimator
     void Flush()
         EXCLUSIVE_LOCKS_REQUIRED(!m_cs_fee_estimator);
 
+    /** Record current fee estimations. */
+    void FlushFeeEstimates()
+        EXCLUSIVE_LOCKS_REQUIRED(!m_cs_fee_estimator);
+
+    /** Calculates the age of the file, since last modified */
+    std::chrono::hours GetFeeEstimatorFileAge();
+
 private:
     mutable Mutex m_cs_fee_estimator;
 

src/test/fuzz/policy_estimator.cpp

@@ -31,7 +31,7 @@ void initialize_policy_estimator()
 FUZZ_TARGET_INIT(policy_estimator, initialize_policy_estimator)
 {
     FuzzedDataProvider fuzzed_data_provider(buffer.data(), buffer.size());
-    CBlockPolicyEstimator block_policy_estimator{FeeestPath(*g_setup->m_node.args)};
+    CBlockPolicyEstimator block_policy_estimator{FeeestPath(*g_setup->m_node.args), DEFAULT_ACCEPT_STALE_FEE_ESTIMATES};
     LIMITED_WHILE(fuzzed_data_provider.ConsumeBool(), 10000) {
         CallOneOf(
             fuzzed_data_provider,

src/test/fuzz/policy_estimator_io.cpp

@@ -28,7 +28,7 @@ FUZZ_TARGET_INIT(policy_estimator_io, initialize_policy_estimator_io)
     FuzzedAutoFileProvider fuzzed_auto_file_provider = ConsumeAutoFile(fuzzed_data_provider);
     AutoFile fuzzed_auto_file{fuzzed_auto_file_provider.open()};
     // Re-using block_policy_estimator across runs to avoid costly creation of CBlockPolicyEstimator object.
-    static CBlockPolicyEstimator block_policy_estimator{FeeestPath(*g_setup->m_node.args)};
+    static CBlockPolicyEstimator block_policy_estimator{FeeestPath(*g_setup->m_node.args), DEFAULT_ACCEPT_STALE_FEE_ESTIMATES};
     if (block_policy_estimator.Read(fuzzed_auto_file)) {
         block_policy_estimator.Write(fuzzed_auto_file);
     }

src/test/util/setup_common.cpp

@@ -179,7 +179,7 @@ ChainTestingSetup::ChainTestingSetup(const ChainType chainType, const std::vecto
     m_node.scheduler->m_service_thread = std::thread(util::TraceThread, "scheduler", [&] { m_node.scheduler->serviceQueue(); });
     GetMainSignals().RegisterBackgroundSignalScheduler(*m_node.scheduler);
 
-    m_node.fee_estimator = std::make_unique<CBlockPolicyEstimator>(FeeestPath(*m_node.args));
+    m_node.fee_estimator = std::make_unique<CBlockPolicyEstimator>(FeeestPath(*m_node.args), DEFAULT_ACCEPT_STALE_FEE_ESTIMATES);
     m_node.mempool = std::make_unique<CTxMemPool>(MemPoolOptionsForTest(m_node));
 
     m_cache_sizes = CalculateCacheSizes(m_args);

test/functional/feature_fee_estimation.py

@@ -7,6 +7,7 @@
 from decimal import Decimal
 import os
 import random
+import time
 
 from test_framework.messages import (
     COIN,
@@ -21,6 +22,8 @@
 )
 from test_framework.wallet import MiniWallet
 
+MAX_FILE_AGE = 60
+SECONDS_PER_HOUR = 60 * 60
 
 def small_txpuzzle_randfee(
     wallet, from_node, conflist, unconflist, amount, min_fee, fee_increment, batch_reqs
@@ -290,6 +293,95 @@ def sanity_check_rbf_estimates(self, utxos):
         est_feerate = node.estimatesmartfee(2)["feerate"]
         assert_equal(est_feerate, high_feerate_kvb)
 
+    def test_old_fee_estimate_file(self):
+        # Get the initial fee rate while node is running
+        fee_rate = self.nodes[0].estimatesmartfee(1)["feerate"]
+
+        # Restart node to ensure fee_estimate.dat file is read
+        self.restart_node(0)
+        assert_equal(self.nodes[0].estimatesmartfee(1)["feerate"], fee_rate)
+
+        fee_dat = self.nodes[0].chain_path / "fee_estimates.dat"
+
+        # Stop the node and backdate the fee_estimates.dat file more than MAX_FILE_AGE
+        self.stop_node(0)
+        last_modified_time = time.time() - (MAX_FILE_AGE + 1) * SECONDS_PER_HOUR
+        os.utime(fee_dat, (last_modified_time, last_modified_time))
+
+        # Start node and ensure the fee_estimates.dat file was not read
+        self.start_node(0)
+        assert_equal(self.nodes[0].estimatesmartfee(1)["errors"], ["Insufficient data or no feerate found"])
+
+
+    def test_estimate_dat_is_flushed_periodically(self):
+        fee_dat = self.nodes[0].chain_path / "fee_estimates.dat"
+        os.remove(fee_dat) if os.path.exists(fee_dat) else None
+
+        # Verify that fee_estimates.dat does not exist
+        assert_equal(os.path.isfile(fee_dat), False)
+
+        # Verify if the string "Flushed fee estimates to fee_estimates.dat." is present in the debug log file.
+        # If present, it indicates that fee estimates have been successfully flushed to disk.
+        with self.nodes[0].assert_debug_log(expected_msgs=["Flushed fee estimates to fee_estimates.dat."], timeout=1):
+            # Mock the scheduler for an hour to flush fee estimates to fee_estimates.dat
+            self.nodes[0].mockscheduler(SECONDS_PER_HOUR)
+
+        # Verify that fee estimates were flushed and fee_estimates.dat file is created
+        assert_equal(os.path.isfile(fee_dat), True)
+
+        # Verify that the estimates remain the same if there are no blocks in the flush interval
+        block_hash_before = self.nodes[0].getbestblockhash()
+        fee_dat_initial_content = open(fee_dat, "rb").read()
+        with self.nodes[0].assert_debug_log(expected_msgs=["Flushed fee estimates to fee_estimates.dat."], timeout=1):
+            # Mock the scheduler for an hour to flush fee estimates to fee_estimates.dat
+            self.nodes[0].mockscheduler(SECONDS_PER_HOUR)
+
+        # Verify that there were no blocks in between the flush interval
+        assert_equal(block_hash_before, self.nodes[0].getbestblockhash())
+
+        fee_dat_current_content = open(fee_dat, "rb").read()
+        assert_equal(fee_dat_current_content, fee_dat_initial_content)
+
+        # Verify that the estimates remain the same after shutdown with no blocks before shutdown
+        self.restart_node(0)
+        fee_dat_current_content = open(fee_dat, "rb").read()
+        assert_equal(fee_dat_current_content, fee_dat_initial_content)
+
+        # Verify that the estimates are not the same if new blocks were produced in the flush interval
+        with self.nodes[0].assert_debug_log(expected_msgs=["Flushed fee estimates to fee_estimates.dat."], timeout=1):
+            # Mock the scheduler for an hour to flush fee estimates to fee_estimates.dat
+            self.generate(self.nodes[0], 5, sync_fun=self.no_op)
+            self.nodes[0].mockscheduler(SECONDS_PER_HOUR)
+
+        fee_dat_current_content = open(fee_dat, "rb").read()
+        assert fee_dat_current_content != fee_dat_initial_content
+
+        fee_dat_initial_content = fee_dat_current_content
+
+        # Generate blocks before shutdown and verify that the fee estimates are not the same
+        self.generate(self.nodes[0], 5, sync_fun=self.no_op)
+        self.restart_node(0)
+        fee_dat_current_content = open(fee_dat, "rb").read()
+        assert fee_dat_current_content != fee_dat_initial_content
+
+
+    def test_acceptstalefeeestimates_option(self):
+        # Get the initial fee rate while node is running
+        fee_rate = self.nodes[0].estimatesmartfee(1)["feerate"]
+
+        self.stop_node(0)
+
+        fee_dat = self.nodes[0].chain_path / "fee_estimates.dat"
+
+        # Stop the node and backdate the fee_estimates.dat file more than MAX_FILE_AGE
+        last_modified_time = time.time() - (MAX_FILE_AGE + 1) * SECONDS_PER_HOUR
+        os.utime(fee_dat, (last_modified_time, last_modified_time))
+
+        # Restart node with -acceptstalefeeestimates option to ensure fee_estimate.dat file is read
+        self.start_node(0,extra_args=["-acceptstalefeeestimates"])
+        assert_equal(self.nodes[0].estimatesmartfee(1)["feerate"], fee_rate)
+
+
     def run_test(self):
         self.log.info("This test is time consuming, please be patient")
         self.log.info("Splitting inputs so we can generate tx's")
@@ -312,12 +404,21 @@ def run_test(self):
         self.log.info("Testing estimates with single transactions.")
         self.sanity_check_estimates_range()
 
+        self.log.info("Test fee_estimates.dat is flushed periodically")
+        self.test_estimate_dat_is_flushed_periodically()
+
         # check that the effective feerate is greater than or equal to the mempoolminfee even for high mempoolminfee
         self.log.info(
             "Test fee rate estimation after restarting node with high MempoolMinFee"
         )
         self.test_feerate_mempoolminfee()
 
+        self.log.info("Test acceptstalefeeestimates option")
+        self.test_acceptstalefeeestimates_option()
+
+        self.log.info("Test reading old fee_estimates.dat")
+        self.test_old_fee_estimate_file()
+
         self.log.info("Restarting node with fresh estimation")
         self.stop_node(0)
         fee_dat = os.path.join(self.nodes[0].datadir, self.chain, "fee_estimates.dat")