Skip to content

Commit

Permalink
Merge pull request #4815 from pwojcikdev/wallet-logging
Browse files Browse the repository at this point in the history 
More comprehensive logging of wallet actions
  • Loading branch information
@pwojcikdev
pwojcikdev authored Jan 3, 2025
2 parents d5b3379 + c8eb458 commit e65e07a
Show file tree
Hide file tree
Showing 2 changed files with 94 additions and 22 deletions.
114 changes: 92 additions & 22 deletions nano/node/wallet.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -246,6 +246,10 @@ void nano::fan::value_set (nano::raw_key const & value_a)
*(values[0]) ^= value_a;
}

/*
* wallet_store
*/

// Wallet version number
nano::account const nano::wallet_store::version_special{};
// Random number used to salt private key encryption
Expand Down Expand Up @@ -669,17 +673,23 @@ void nano::kdf::phs (nano::raw_key & result_a, std::string const & password_a, n
(void)success;
}

/*
* wallet
*/

nano::wallet::wallet (bool & init_a, store::transaction & transaction_a, nano::wallets & wallets_a, std::string const & wallet_a) :
lock_observer ([] (bool, bool) {}),
store (init_a, wallets_a.kdf, transaction_a, wallets_a.env, wallets_a.node.config.random_representative (), wallets_a.node.config.password_fanout, wallet_a),
wallets (wallets_a)
wallets (wallets_a),
logger (wallets_a.logger)
{
}

nano::wallet::wallet (bool & init_a, store::transaction & transaction_a, nano::wallets & wallets_a, std::string const & wallet_a, std::string const & json) :
lock_observer ([] (bool, bool) {}),
store (init_a, wallets_a.kdf, transaction_a, wallets_a.env, wallets_a.node.config.random_representative (), wallets_a.node.config.password_fanout, wallet_a, json),
wallets (wallets_a)
wallets (wallets_a),
logger (wallets_a.logger)
{
}

Expand Down Expand Up @@ -710,7 +720,7 @@ bool nano::wallet::enter_password (store::transaction const & transaction_a, std
auto result (store.attempt_password (transaction_a, password_a));
if (!result)
{
wallets.node.logger.info (nano::log::type::wallet, "Wallet unlocked");
logger.info (nano::log::type::wallet, "Wallet unlocked");

auto this_l = shared_from_this ();
wallets.queue_wallet_action (nano::wallets::high_priority, this_l, [this_l] (nano::wallet & wallet) {
Expand All @@ -720,7 +730,7 @@ bool nano::wallet::enter_password (store::transaction const & transaction_a, std
}
else
{
wallets.node.logger.warn (nano::log::type::wallet, "Invalid password, wallet locked");
logger.warn (nano::log::type::wallet, "Invalid password, wallet locked");
}
lock_observer (result, password_a.empty ());
return result;
Expand All @@ -732,13 +742,18 @@ nano::public_key nano::wallet::deterministic_insert (store::transaction const &
if (store.valid_password (transaction_a))
{
key = store.deterministic_insert (transaction_a);

logger.info (nano::log::type::wallet, "Deterministically inserted new account: {}", key.to_account ());

if (generate_work_a)
{
work_ensure (key, key);
}
auto half_principal_weight (wallets.node.minimum_principal_weight () / 2);
if (wallets.check_rep (key, half_principal_weight))
{
logger.info (nano::log::type::wallet, "New account qualified as a representative: {}", key.to_account ());

nano::lock_guard<nano::mutex> lock{ representatives_mutex };
representatives.insert (key);
}
Expand All @@ -753,6 +768,9 @@ nano::public_key nano::wallet::deterministic_insert (uint32_t const index, bool
if (store.valid_password (transaction))
{
key = store.deterministic_insert (transaction, index);

logger.info (nano::log::type::wallet, "Deterministically inserted new account: {}", key.to_account ());

if (generate_work_a)
{
work_ensure (key, key);
Expand Down Expand Up @@ -859,6 +877,11 @@ std::shared_ptr<nano::block> nano::wallet::receive_action (nano::block_hash cons
nano::raw_key prv;
if (!store.fetch (transaction, account_a, prv))
{
logger.info (nano::log::type::wallet, "Receiving block {} from account {}, amount: {}",
send_hash_a.to_string (),
account_a.to_account (),
pending_info->amount.number ().convert_to<std::string> ());

if (work_a == 0)
{
store.work_get (transaction, account_a, work_a);
Expand All @@ -877,23 +900,27 @@ std::shared_ptr<nano::block> nano::wallet::receive_action (nano::block_hash cons
}
else
{
wallets.node.logger.warn (nano::log::type::wallet, "Unable to receive, wallet locked");
logger.warn (nano::log::type::wallet, "Unable to receive, wallet locked, block {} to account: {}",
send_hash_a.to_string (),
account_a.to_account ());
}
}
else
{
// Ledger doesn't have this marked as available to receive anymore
logger.warn (nano::log::type::wallet, "Not receiving block {}, block already received", send_hash_a.to_string ());
}
}
else
{
// Ledger doesn't have this block anymore.
logger.warn (nano::log::type::wallet, "Not receiving block {}, block no longer exists or pruned", send_hash_a.to_string ());
}
}
else
{
// Someone sent us something below the threshold of receiving
wallets.node.logger.warn (nano::log::type::wallet, "Not receiving block {} due to minimum receive threshold", send_hash_a.to_string ());
logger.warn (nano::log::type::wallet, "Not receiving block {} due to minimum receive threshold", send_hash_a.to_string ());
}
if (block != nullptr)
{
Expand All @@ -918,6 +945,10 @@ std::shared_ptr<nano::block> nano::wallet::change_action (nano::account const &
auto existing (store.find (transaction, source_a));
if (existing != store.end (transaction) && !wallets.node.ledger.any.account_head (block_transaction, source_a).is_zero ())
{
logger.info (nano::log::type::wallet, "Changing representative for account {} to {}",
source_a.to_account (),
representative_a.to_account ());

auto info = wallets.node.ledger.any.account_get (block_transaction, source_a);
debug_assert (info);
nano::raw_key prv;
Expand All @@ -931,6 +962,16 @@ std::shared_ptr<nano::block> nano::wallet::change_action (nano::account const &
block = std::make_shared<nano::state_block> (source_a, info->head, representative_a, info->balance, 0, prv, source_a, work_a);
details.epoch = info->epoch ();
}
else
{
logger.warn (nano::log::type::wallet, "Changing representative for account {} failed, wallet locked or account not found",
source_a.to_account ());
}
}
else
{
logger.warn (nano::log::type::wallet, "Changing representative for account {} failed, wallet locked",
source_a.to_account ());
}
}
if (block != nullptr)
Expand All @@ -952,7 +993,7 @@ std::shared_ptr<nano::block> nano::wallet::send_action (nano::account const & so
id_mdb_val = nano::store::lmdb::db_val (id_a->size (), const_cast<char *> (id_a->data ()));
}

auto prepare_send = [&id_mdb_val, &wallets = this->wallets, &store = this->store, &source_a, &amount_a, &work_a, &account_a] (auto const & transaction) {
auto prepare_send = [this, &id_mdb_val, &wallets = this->wallets, &store = this->store, &source_a, &amount_a, &work_a, &account_a, &id_a] (auto const & transaction) {
auto block_transaction = wallets.node.ledger.tx_begin_read ();
auto error (false);
auto cached_block (false);
Expand All @@ -969,9 +1010,19 @@ std::shared_ptr<nano::block> nano::wallet::send_action (nano::account const & so
block = wallets.node.ledger.any.block_get (block_transaction, hash);
if (block != nullptr)
{
logger.warn (nano::log::type::wallet, "Block already exists for send action with id: {}, existing hash: {}",
id_a.value (),
hash.to_string ());

cached_block = true;
wallets.node.network.flood_block (block, nano::transport::traffic_type::block_broadcast_initial);
}
else
{
logger.warn (nano::log::type::wallet, "Block was not found in ledger for send action with id: {}, hash: {}",
id_a.value (),
hash.to_string ());
}
}
else if (status != MDB_NOTFOUND)
{
Expand All @@ -988,6 +1039,11 @@ std::shared_ptr<nano::block> nano::wallet::send_action (nano::account const & so
auto balance (wallets.node.ledger.any.account_balance (block_transaction, source_a));
if (balance && balance.value ().number () >= amount_a)
{
logger.info (nano::log::type::wallet, "Sending from account: {} to: {}, amount: {}",
source_a.to_account (),
account_a.to_account (),
amount_a.convert_to<std::string> ());

auto info = wallets.node.ledger.any.account_get (block_transaction, source_a);
debug_assert (info);
nano::raw_key prv;
Expand All @@ -1010,6 +1066,13 @@ std::shared_ptr<nano::block> nano::wallet::send_action (nano::account const & so
}
}
}
else
{
logger.warn (nano::log::type::wallet, "Insufficient balance for send from: {}, required: {} but available: {}",
account_a.to_account (),
amount_a.convert_to<std::string> (),
balance ? balance.value ().number ().convert_to<std::string> () : "unknown");
}
}
}
}
Expand Down Expand Up @@ -1055,7 +1118,7 @@ bool nano::wallet::action_complete (std::shared_ptr<nano::block> const & block_a
auto required_difficulty{ wallets.node.network_params.work.threshold (block_a->work_version (), details_a) };
if (wallets.node.network_params.work.difficulty (*block_a) < required_difficulty)
{
wallets.node.logger.info (nano::log::type::wallet, "Cached or provided work for block {} account {} is invalid, regenerating...",
logger.info (nano::log::type::wallet, "Cached or provided work for block {} account {} is invalid, regenerating...",
block_a->hash ().to_string (),
account_a.to_account ());

Expand Down Expand Up @@ -1153,7 +1216,7 @@ void nano::wallet::work_update (store::transaction const & transaction_a, nano::
}
else
{
wallets.node.logger.warn (nano::log::type::wallet, "Cached work no longer valid, discarding");
logger.warn (nano::log::type::wallet, "Cached work no longer valid, discarding");
}
}

Expand Down Expand Up @@ -1182,7 +1245,7 @@ bool nano::wallet::search_receivable (store::transaction const & wallet_transact
auto result (!store.valid_password (wallet_transaction_a));
if (!result)
{
wallets.node.logger.info (nano::log::type::wallet, "Beginning receivable block search");
logger.info (nano::log::type::wallet, "Beginning receivable block search");

for (auto i (store.begin (wallet_transaction_a)), n (store.end (wallet_transaction_a)); i != n; ++i)
{
Expand All @@ -1199,7 +1262,7 @@ bool nano::wallet::search_receivable (store::transaction const & wallet_transact
auto amount (pending.amount.number ());
if (wallets.node.config.receive_minimum.number () <= amount)
{
wallets.node.logger.info (nano::log::type::wallet, "Found a receivable block {} for account {}", hash.to_string (), pending.source.to_account ());
logger.info (nano::log::type::wallet, "Found a receivable block {} for account {}", hash.to_string (), pending.source.to_account ());

if (wallets.node.ledger.confirmed.block_exists_or_pruned (block_transaction, hash))
{
Expand All @@ -1221,11 +1284,11 @@ bool nano::wallet::search_receivable (store::transaction const & wallet_transact
}
}

wallets.node.logger.info (nano::log::type::wallet, "Receivable block search phase complete");
logger.info (nano::log::type::wallet, "Receivable block search phase complete");
}
else
{
wallets.node.logger.warn (nano::log::type::wallet, "Stopping search, wallet is locked");
logger.warn (nano::log::type::wallet, "Unable to search receivable blocks, wallet is locked");
}
return result;
}
Expand Down Expand Up @@ -1271,17 +1334,23 @@ uint32_t nano::wallet::deterministic_check (store::transaction const & transacti

nano::public_key nano::wallet::change_seed (store::transaction const & transaction_a, nano::raw_key const & prv_a, uint32_t count)
{
logger.info (nano::log::type::wallet, "Changing wallet seed");

store.seed_set (transaction_a, prv_a);
auto account = deterministic_insert (transaction_a);
if (count == 0)
{
count = deterministic_check (transaction_a, 0);
logger.info (nano::log::type::wallet, "Auto-detected {} accounts to generate", count);
}
for (uint32_t i (0); i < count; ++i)
{
// Disable work generation to prevent weak CPU nodes stuck
account = deterministic_insert (transaction_a, false);
}

logger.info (nano::log::type::wallet, "Completed changing wallet seed and generating accounts");

return account;
}

Expand Down Expand Up @@ -1317,11 +1386,15 @@ void nano::wallet::work_cache_blocking (nano::account const & account_a, nano::r
}
else if (!wallets.node.stopped)
{
wallets.node.logger.warn (nano::log::type::wallet, "Could not precache work for root {} due to work generation failure", root_a.to_string ());
logger.warn (nano::log::type::wallet, "Could not precache work for root {} due to work generation failure", root_a.to_string ());
}
}
}

/*
* wallets
*/

void nano::wallets::do_wallet_actions ()
{
nano::unique_lock<nano::mutex> action_lock{ action_mutex };
Expand Down Expand Up @@ -1349,15 +1422,12 @@ void nano::wallets::do_wallet_actions ()
}
}

/*
* wallets
*/

nano::wallets::wallets (bool error_a, nano::node & node_a) :
network_params{ node_a.config.network_params },
observer ([] (bool) {}),
kdf{ node_a.config.network_params.kdf_work },
node (node_a),
logger (node_a.logger),
env (boost::polymorphic_downcast<nano::mdb_wallets_store *> (node_a.wallets_store_impl.get ())->environment),
stopped (false)
{
Expand Down Expand Up @@ -1610,7 +1680,7 @@ void nano::wallets::foreach_representative (std::function<void (nano::public_key
{
last_log = std::chrono::steady_clock::now ();

node.logger.warn (nano::log::type::wallet, "Representative locked inside wallet: {}", i->first.to_string ());
logger.warn (nano::log::type::wallet, "Representative locked inside wallet: {}", i->first.to_string ());
}
}
}
Expand Down Expand Up @@ -1746,12 +1816,12 @@ void nano::wallets::receive_confirmed (nano::block_hash const & hash_a, nano::ac
{
if (!node.ledger.confirmed.block_exists_or_pruned (node.ledger.tx_begin_read (), hash_a))
{
node.logger.warn (nano::log::type::wallet, "Confirmed block is missing: {}", hash_a.to_string ());
debug_assert (false, "Confirmed block is missing");
logger.warn (nano::log::type::wallet, "Confirmed block is missing: {}", hash_a.to_string ());
debug_assert (false, "confirmed block is missing");
}
else
{
node.logger.warn (nano::log::type::wallet, "Block has already been received: {}", hash_a.to_string ());
logger.warn (nano::log::type::wallet, "Block has already been received: {}", hash_a.to_string ());
}
}
}
Expand Down
2 changes: 2 additions & 0 deletions nano/node/wallet.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -172,6 +172,7 @@ class wallet final : public std::enable_shared_from_this<nano::wallet>
std::function<void (bool, bool)> lock_observer;
nano::wallet_store store;
nano::wallets & wallets;
nano::logger & logger;
nano::mutex representatives_mutex;
std::unordered_set<nano::account> representatives;
};
Expand Down Expand Up @@ -242,6 +243,7 @@ class wallets final
MDB_dbi handle;
MDB_dbi send_action_ids;
nano::node & node;
nano::logger & logger;
nano::store::lmdb::env & env;
std::atomic<bool> stopped;
std::thread thread;
Expand Down

0 comments on commit e65e07a

Please sign in to comment.