Bitcoin full node and query server

May 2024

Archive of the libbitcoin Slack #general channel.

Wednesday, May 1, 2024

evoskuil05:29

I completed the integration of neutrino filters into the node today. Turns out the original store design was correct and still appears optimal. This is much more costly in terms of update time than the electrum addressing because it requires previous outputs be read for all blocks (including under checkpoints/milestone). This imposes an ordering similar to validation but not as strict as confirmation. So it can also be parallelized to the extent that multiple concurrent blocks exist.

05:33

I've been running the initial test concurrently with electrum address indexing. Since Electrum affects only block write it directly impacts sync time via concurrent block write. Since neutrino extends validation it is currently running sequentially and will extend validation/confirmation time but won't affect block sync much at all. It appear that sync will complete at around two hours, so an extra 15 minutes over Electrum, which is an extra 15 minutes over basic sync.

05:38

Though at that time, with all blocks and and Electrum addressing complete, the neutrino filter creation will just be passing around block 300,000. The extended time is simply from the concurrent execution using some processor and a lot of disk reading, affecting ongoing parallel writes.

evoskuil06:17

Completed in 2:10, now just computing and indexing neutrino filters and confirming in order.

06:19

I integrated the 300ms benchmark query (above) into the running node console input commands. With the node up and running (and indexing filters at about 25% disk capacity) the query executes in an average of 75ms and as low as 65 ms. That's not a typo.

evoskuil06:25

This custom ad-hoc query spans most of the store's tables, including 8 hashmap searches for each of the 3,277 payments to 3,000 addresses, all while the store is being read/written at about 25% SSD capacity...

06:26

void executor::read_test() const
{
    constexpr auto start_tx = 15'000_u32;
    constexpr auto ns_to_ms = 1'000'000_i64;
    constexpr auto target_count = 3000_size;

    // Set ensures unique addresses.
    std::set<hash_digest> keys{};
    auto tx = start_tx;

    console(format("Getting first [%1%] output address hashes.") %
        target_count);

    auto start = fine_clock::now();
    while (!cancel_ && keys.size() < target_count)
    {
        const auto outputs = query_.get_outputs(tx++);
        if (outputs->empty())
            return;

        for (const auto& put: *outputs)
        {
            keys.emplace(put->script().hash());
            if (cancel_ || keys.size() == target_count)
                break;
        }
    }
    auto end = fine_clock::now();

    console(format("Got first [%1%] unique addresses above tx [%2%] in [%3%] ms.") %
        keys.size() % start_tx % ((end - start).count() / ns_to_ms));

    struct out
    {
        // Address hash, output link, first spender link.
        hash_digest address;
        uint64_t output_fk;
        uint64_t spend_fk;
        uint64_t input_fk;

        // Output's tx link, hash, and block position.
        uint64_t tx_fk;
        hash_digest tx_hash;
        uint16_t tx_position;

        // Output tx's block link, hash, and height.
        uint32_t bk_fk;
        hash_digest bk_hash;
        uint32_t bk_height;

        // Spender's tx link, hash, and block position.
        uint64_t in_tx_fk;
        hash_digest in_tx_hash;
        uint16_t in_tx_position;

        // Spender tx's block link, hash, and height.
        uint32_t in_bk_fk;
        hash_digest in_bk_hash;
        uint32_t in_bk_height;

        // Spender (first input) and output.
        chain::output::cptr output{};
        chain::input::cptr input{};
    };

    std::vector<out> outs{};
    outs.reserve(target_count);
    using namespace database;

    start = fine_clock::now();
    for (auto& key: keys)
    {
        auto address_it = store_.address.it(key);
        if (cancel_ || address_it.self().is_terminal())
            return;

        do
        {
            table::address::record address{};
            if (cancel_ || !store_.address.get(address_it.self(), address))
                return;

            const auto out_fk = address.output_fk;
            table::output::get_parent output{};
            if (!store_.output.get(out_fk, output))
                return;

            const auto tx_fk = output.parent_fk;
            const auto block_fk = query_.to_block(tx_fk);

            // Output tx block has height.
            database::height_link bk_height{};
            table::header::get_height bk_header{};
            if (!block_fk.is_terminal())
                if (!store_.header.get(block_fk, bk_header))
                    return;
                else
                    bk_height = bk_header.height;

            // The block is confirmed by height.
            table::height::record height_record{};
            const auto confirmed = store_.confirmed.get(bk_height,
                height_record) && (height_record.header_fk == block_fk);

            // unconfirmed tx: max height/pos, null hash, terminal/zero links.
            if (!confirmed)
            {
                outs.emplace_back(
                    key,
                    out_fk,
                    max_uint64,  // spend_fk
                    max_uint64,  // input_fk

                    tx_fk,
                    null_hash,
                    max_uint16,  // position

                    block_fk,
                    null_hash,
                    max_uint32,  // height

                    // in_tx
                    max_uint64,
                    null_hash,
                    max_uint16,  // position

                    // in_bk_tx
                    max_uint32,
                    null_hash,
                    max_uint32,  // height

                    nullptr,
                    nullptr);
                continue;
            }

            // Get confirmed output tx block position.
            auto out_position = max_uint16;
            table::txs::get_position txs{ {}, tx_fk };
            if (!store_.txs.get(query_.to_txs_link(block_fk), txs))
                return;
            else
                out_position = possible_narrow_cast<uint16_t>(txs.position);

            // Get first spender only (may or may not be confirmed).
            const auto spenders = query_.to_spenders(out_fk);
            spend_link sp_fk{};
            if (!spenders.empty())
                sp_fk = spenders.front();

            // Get spender input, tx, position, block, height.
            auto in_position = max_uint16;
            input_link in_fk{};
            tx_link in_tx_fk{};
            header_link in_bk_fk{};
            height_link in_bk_height{};

            if (!sp_fk.is_terminal())
            {
                table::spend::record spend{};
                if (!store_.spend.get(sp_fk, spend))
                {
                    return;
                }
                else
                {
                    in_fk = spend.input_fk;
                    in_tx_fk = spend.parent_fk;
                }

                // Get spender tx block.
                in_bk_fk = query_.to_block(in_tx_fk);

                // Get in_tx position in the confirmed block.
                table::txs::get_position in_txs{ {}, in_tx_fk };
                if (!in_bk_fk.is_terminal())
                    if (!store_.txs.get(query_.to_txs_link(in_bk_fk), in_txs))
                        return;
                    else
                        in_position = possible_narrow_cast<uint16_t>(in_txs.position);

                // Get spender input tx block height.
                table::header::get_height in_bk_header{};
                if (!in_bk_fk.is_terminal())
                    if (!store_.header.get(in_bk_fk, in_bk_header))
                        return;
                    else
                        in_bk_height = in_bk_header.height;
            }

            const auto in = query_.get_input(sp_fk);
            const auto out = query_.get_output(out_fk);

            // confirmed tx has block height and tx position.
            outs.emplace_back(
                key,
                out_fk,
                sp_fk,
                in_fk,

                tx_fk,
                query_.get_tx_key(tx_fk),
                out_position,

                block_fk,
                query_.get_header_key(block_fk),
                bk_height,

                in_tx_fk,
                query_.get_tx_key(in_tx_fk),
                in_position,

                in_bk_fk,
                query_.get_header_key(in_bk_fk),
                in_bk_height,
                
                out,
                in);
        }
        while (address_it.advance());
    }
    end = fine_clock::now();

    console(format("Got all [%1%] payments to [%2%] addresses in [%3%] ms.") %
        outs.size() % keys.size() % ((end - start).count() / ns_to_ms));
}

06:29

That's processing payments at an average rate of 51,203,125 per second.

evoskuil06:40

Trimming that back tot he benchmark query from sparrow (no spender info) makes it 4x faster (15-20ms), in which case we're processing 200M of those per second. Single thread, on a 7 year old machine, with no shani.

evoskuil06:43

replied to a thread: view

Please do!!

(edited)

👍 1

Thursday, May 2, 2024

evoskuil17:56

After working through a design for maintaining consistency given a disk full condition during a multi-table write (which only occurs with a tx write), I realized that this condition is already managed. Multi-table writes occur both concurrently and during ongoing reads, such as by validation/confirmation and also client/server queries. Full consistency is of course eventual, but all queries produce logical results even in the midst of multi-table writes. So when a single table fails to expand during a write, such as for disk full, all we need to do is stop and report it.

18:00

This is of course not the same fault tolerance problem as an uncontrolled shutdown, which we now manage by detection and recovery from snapshot. This allows for continuation from the stop point. In fact it will be possible for us to poll storage and restart writes when space becomes available. But today I'm implementing detection with pause and keyboard input to resume.

evoskuil19:30

I'm around if anyone wants to meet today. I know we talked about an earlier start - we should lock that down.

Friday, May 3, 2024

evoskuil18:38

Tracked down a store write query bug that would only surface in the disk full scenario - where the node keeps running despite disk full errors emanating from one or more tables. Basically the queries weren't written with that expectation, but now are. Running tests now in the disk full scenario, where presently I just leave it running while it rejects storage in whatever table is full, resulting in partial writes but valid data.

18:43

Also discovered a race in the node backup implementation that can result in a deadlock. The node broadcasts a pause event so that network traffic halts, and then waits until there are no outstanding writes by waiting on a database write lock. But new channels often pop up and have not received the event, resulting in a log wait (until there is no actual write traffic). It's similar to the shutdown wait, but that's safe because it permanently terminates all channels.

2 replies · evoskuil · last May 05, 2024

evoskuil15:21

*long wait

evoskuil15:53

Resolved this, just placed a pause event rebroadcast in the backup event handler in the case of a wait_lock event. The wait_lock signals that store write exclusivity was not obtained for a full second and will retry. Resending the pause event suspends any channels that may have missed it on the initial send. This does technically present a halting problem, since that back and forth can theoretically go on forever, but that's extremely unlikely. If it did for some reason happen, all that occurs is the backup is deferred until store close, which suspends all channels, resulting in backup obtaining the lock, completing the snapshot, and then close obtaining the lock. So a simple one line good solution to a tricky race condition.

(edited)

🙌 1

Saturday, May 4, 2024

evoskuil15:21

replied to a thread: view

*long wait

evoskuil17:53

The full chain neutrino index completed a while back, so now we have proper sizing. The total index or neutrino filters/heads with hashmap header is 10GiB. The electrum address index is 117GiB. The fully-indexed block archive is 609GiB, vs native serialization of 531GiB (15% indexation cost). The confirmation index (blocks and txs by height) is an additional 13GiB, for 622GiB so total cost of 17%. The total store with both filters is 749GiB. I'm aware of a few simple optimizations that can increase the overall efficiency maybe a couple points. But overall that's better than planned and quite excellent.

Sunday, May 5, 2024

evoskuil15:53

replied to a thread: view

(edited)

🙌 1

evoskuil15:57

The state of the art is pretty damn sad... https://groups.google.com/g/bitcoindev/c/Ww5QMaxdDcY

😞 1

evoskuil16:22

I've completed testing against a disk full condition in which I do not attempt to suspend the network. This results in some writes succeeding and others failing with the disk_full error state. Some will succeed because each table has an independent file with its own preallocation. Since disk_full is no longer a terminal error, the node will just continue to iterate with potential partial success and failure. Eventually if there are successes, those can fill up the preallocation and then will start failing as well. The only down side is wasted store space prior to resumption following space being freed up. Currently if I free up space the node just continues normally. But to limit wasted space we want to suspend operations as soon as a disk_full condition arises, and resume once space becomes available.

Monday, May 6, 2024

evoskuil00:26

The node object doesn't have the ability to stop itself, which is intentional - sort of a design forcing function. The node (console process) stops the node via keyboard command. This forces the implementation to deal rationally with things like network disconnect, disk full, and store corruption (for example). When reviewing the handling of store corruption and disk full I decided that it would be good to slightly modify the libbitcoin-network stack to enable connect/accept suspension. Normally the connectors are allocated at startup and run in a callback loop, always attempting to maintain the configured number of connections. But for both backup and store full/fault conditions, we need to suspend this. So I made those modifications, which were simple. The connector and acceptor classes are now constructed with a reference to an atomic bool, owned by p2p. This tells them to bypass connection attempts with a specific error code. Since certain errors result in a delayed retry (precluding tight loops on things like no internet or no addresses), this fits naturally into the design.

evoskuil00:33

So now when there is a store fault, or a disk full, or a snapshot starting, the network stops connecting but the process remains alive. Existing connections self-terminate using a broadcast event that is picked up in the protocol base. Resume from a backup is automatic (unless there is a preexisting disk full condition). Resume from a disk full condition is currently a command line option. The store object now retains the state of each table, and provides a summary query to provide context for these operations. This is all working seamlessly at this point.

00:34

I also experimented with reducing a given preallocation so that a write may complete. But there is really no logical benefit to this, and it has a significant downside. Without preallocation, there is remap of the memory map for every single write. This is ridonkulously slow so it's not an option.

00:37

I am about to ensure that when there is a store fault the store is either recovered from a snapshot or closes with a flush_lock file so that the corruption knowledge is retained. Disk full is not a corrupted state, so it's just a normal shutdown. However space can be freed and the command line option triggered to resume, which works perfectly.

00:38

So we now have flawless disk full handling and snapshot recovery. Disk space can be increased without stopping the process, and snapshots can be backed up live. So there should currently be no reason to stop the process unless physical space is insufficient or configuration changes are required. I do have a plan to make most configuration dynamic as well.

evoskuil00:45

I am also now going to implement a node object timer that gets set on disk full, which will poll for sufficient space to resume (this can be computed from table properties) automatically. Polling isn't probably absolutely necessary, but system events are a little more platform-specific. Also I'm going to track accumulated store work/size (bytes, txs, validation...) so that snapshots can be taken automatically at reasonable/configurable intervals.

00:46

Snapshots can of course also lead to disk full, however once there are two snapshots there is never any more size increase. All writes are first suspended, then the snapshot directories are rotated and the older one deleted. Since only headers are written, size never changes, so we can always snap once we have to written. However if the disk is full the snapshot just leaves behind the one value directory (which is why we rotate two). I've verified the snapshot disk full behavior as well.

00:50

I expect to have the above done tomorrow, and I've recently completed all of the work for Electrum addressing and Neutrino filters, and tested wince with each independently and both (as these are optional tables). That will leave me with one big chunk of work... the validation concurrency implementation. Presently it executes only one block at a time in sequence, but we can now easily validate any number of blocks concurrently, as long as all prevouts are stored. So for example, the first 10000 blocks tend to show up in a minute or two, and we can validate these all at the same time up to the top contiguous candidate height.

1 reply · evoskuil · last May 06, 2024

evoskuil00:59

This should have said "first 100,000 blocks".

evoskuil00:53

This not only allows up to concurrently validate small blocks, but to validate transactions from another block as threads are freed up completing a preceding block. In other words, instead of a sine wave type of CPU utilization, it should be a true flatline from start to finish - unless of course we hit download gaps, which I have designed the downloader to be able to minimize.

00:56

The major cost with validation however is transaction read/deserialization time (in addition to previous outputs). The node is fast, but we are basically reading the entire store off the network, and then again off the disk. This is optimized for min sync time and max query speed, and performs best with full RAM capacity (like 1TB), not for min validation time. But I think it will at least be competitive there as well.

evoskuil20:37

https://twitter.com/evoskuil/status/1787580034783306107

X (formerly Twitter)

Eric Voskuil (@evoskuil) on X

@lopp Starting to get good numbers from libbitcoin v4. I just ran the bottom line config from above (to 650,000), which completed in 62 minutes, 3x faster than above. The wire size is 281GiB and the v4 store is 343 (22% index cost). This is against the Internet over a 1Gbps wire...

🎉 1

2 replies · John Doe, evoskuil · last May 06, 2024

John Doe21:49

What do you think was the issue here? Something with his setup? https://blog.lopp.net/2023-bitcoin-node-performance-tests/ "My libbitcoin config:

[network] peer = <local network node IP address>:8333 outbound_connections = 1 [blockchain] # I set this to the number of virtual cores since default is physical cores cores = 12 checkpoint = 000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f:0 [database] cache_capacity = 100000

evoskuil21:52

No idea, presumably. The v3 node isn’t even headers first and not relevant to v4 work.

👍 1

Tuesday, May 7, 2024

evoskuil11:08

As I said when setting out to do v4 a few years ago, only an order of magnitude sync speed improvement over Core would satisfy me. BN is now doing that with much more indexing in the same amount of space. https://x.com/evoskuil/status/1787795789592297725

🙌 2

evoskuil13:23

I used to be concerned about the BN mmap shutdown time, but interestingly Core's shutdown time is 2-3x longer.

evoskuil13:52

Cumulative sync time to block 650,000. Note the steep tail, which is a result of no longer being able to fan out the load. Nearly all of the work is complete in 45 minutes, and that trend continues until termination.

👀 1

evoskuil14:04

Dispersion of 650,000 blocks. Very small blocks are obtained very rapidly, despite the load being fanned out. However once blocks get full the dispersion seems pretty random/even.

evoskuil14:36

The larger gaps are a consequence of table remapping, where a table reaches its preallocated size and flushes to disk and reallocates a larger size. This can be eliminated with initial sizing, but unless there is sufficient RAM to hold the whole store, that results in thrashing, so we avoid it.

(edited)

evoskuil14:42

This is the same dispersion overlaid with validation and confirmation times. Since this run is entirely under checkpoint/milestone, there is very little additional cost to these operations. Note however that confirmation requires a store write for every block and transaction, which is why it tends to track above validation.

14:46

What we really want to avoid in the time dispersion, is tall spikes on the left. This delays validation/confirmation. IOW a single block 1 missing until the end would delay all validate/confirm progress until the store is fully populated.

14:48

This can be mitigated with a moving completion window. However that has the downside of restricting bandwidth utilization as gaps are waited on. That makes sense when validating, but as you can see above, probably not when under checkpoint/milestone.

14:48

I've already implemented the moving window, but will wait until validation fan-out is implemented to tune it.

John Doe14:51

Amazing work 🤯

🙏🏻 1

evoskuil15:35

Last night I discovered that node (not network) is leaking closed channels. It's also possible for channels to miss chaser events given how they asynchronously subscribe. So I'll be cleaning that up (requires a desubscriber object vs. a simple subscriber).

(edited)

15:38

The leak isn't actually a process memory leak, as the objects are held until close and then released. But closed channels are held until process close, which means they accumulate and will eventually drag down performance.

Wednesday, May 8, 2024

evoskuil04:46

After resolving the channel leak, I compiled a build with the most of the logging compiled out (one of our build options). I can the same 650k block sync described above, but with the very large Electrum address indexing. The run completed faster than above - fully downloaded and confirmed in 55 minutes. And with an extra 66 GiB index of all addresses in the blockchain up to that height. The only difference in the configuration was 16 vs. 15 network threads. This small additional amount of horsepower allows the network bandwidth to remain redlined for the entire run. That Electrum index typically takes days to weeks to build directly off of a fully-synced Core node, and we are getting it for free - with orders of magnitude faster query.

evoskuil11:52

Extending the Electrum Server run above to 840,000 took 52 minutes (1:47 total) and increased the address index to 115GiB (2,784,257,776 unique payment addresses indexed).

Thursday, May 9, 2024

evoskuil05:01

Spent the day mostly on technical debt, cleaning up the bn command line and settings as well as the add-hoc executable source. Added a few things while I was at it, including an option to detect platform intrinsics:

Intrinsics...
arm..... present:0.
intel... present:1.
avx512.. present:0 compiled:1.
avx2.... present:1 compiled:1.
sse41... present:1 compiled:1.
shani... present:0 compiled:1.
neon.... present:0 compiled:0.

05:04

As well as auto-restore on process startup with store corruption (from uncontrolled process termination) :

2024-05-09T05:03:27Z.0 ====================== startup =======================
2024-05-09T05:03:27Z.0 Press CTRL-C to stop the node.
2024-05-09T05:03:27Z.0 Log system configuration...
2024-05-09T05:03:27Z.0 Application.. compiled:1 enabled:1.
2024-05-09T05:03:27Z.0 News......... compiled:1 enabled:1.
2024-05-09T05:03:27Z.0 Session...... compiled:1 enabled:1.
2024-05-09T05:03:27Z.0 Protocol..... compiled:1 enabled:0.
2024-05-09T05:03:27Z.0 ProXy........ compiled:1 enabled:0.
2024-05-09T05:03:27Z.0 Wire......... compiled:0 enabled:0.
2024-05-09T05:03:27Z.0 Remote....... compiled:1 enabled:1.
2024-05-09T05:03:27Z.0 Fault........ compiled:1 enabled:1.
2024-05-09T05:03:27Z.0 Quit......... compiled:1 enabled:0.
2024-05-09T05:03:27Z.0 Object....... compiled:0 enabled:0.
2024-05-09T05:03:27Z.0 Verbose...... compiled:1 enabled:0.
2024-05-09T05:03:27Z.0 Using config file: "f:\\bn.cfg"
2024-05-09T05:03:27Z.0 Database failed to start with error 'flush lock failure'.
2024-05-09T05:03:27Z.0 Please wait while restoring from most recent snapshot...
2024-05-09T05:03:27Z.0 restore::recover_snapshot(store)
2024-05-09T05:03:45Z.0 restore::open_file(header_head)
2024-05-09T05:03:45Z.0 restore::open_file(header_body)
2024-05-09T05:03:45Z.0 restore::open_file(input_head)
2024-05-09T05:03:45Z.0 restore::open_file(input_body)
2024-05-09T05:03:45Z.0 restore::open_file(output_head)
2024-05-09T05:03:45Z.0 restore::open_file(output_body)
2024-05-09T05:03:45Z.0 restore::open_file(point_head)
2024-05-09T05:03:45Z.0 restore::open_file(point_body)
2024-05-09T05:03:45Z.0 restore::open_file(puts_head)
2024-05-09T05:03:45Z.0 restore::open_file(puts_body)
2024-05-09T05:03:45Z.0 restore::open_file(spend_head)
2024-05-09T05:03:45Z.0 restore::open_file(spend_body)
2024-05-09T05:03:45Z.0 restore::open_file(tx_head)
2024-05-09T05:03:45Z.0 restore::open_file(tx_body)
2024-05-09T05:03:45Z.0 restore::open_file(txs_head)
2024-05-09T05:03:45Z.0 restore::open_file(txs_body)
2024-05-09T05:03:45Z.0 restore::open_file(candidate_head)
2024-05-09T05:03:45Z.0 restore::open_file(candidate_body)
2024-05-09T05:03:45Z.0 restore::open_file(confirmed_head)
2024-05-09T05:03:45Z.0 restore::open_file(confirmed_body)
2024-05-09T05:03:45Z.0 restore::open_file(strong_tx_head)
2024-05-09T05:03:45Z.0 restore::open_file(strong_tx_body)
2024-05-09T05:03:45Z.0 restore::open_file(validated_bk_head)
2024-05-09T05:03:45Z.0 restore::open_file(validated_bk_body)
2024-05-09T05:03:45Z.0 restore::open_file(validated_tx_head)
2024-05-09T05:03:45Z.0 restore::open_file(validated_tx_body)
2024-05-09T05:03:45Z.0 restore::open_file(address_head)
2024-05-09T05:03:45Z.0 restore::open_file(address_body)
2024-05-09T05:03:45Z.0 restore::open_file(neutrino_head)
2024-05-09T05:03:45Z.0 restore::open_file(neutrino_body)
2024-05-09T05:03:45Z.0 restore::load_file(header_head)
2024-05-09T05:03:45Z.0 restore::load_file(header_body)
2024-05-09T05:03:45Z.0 restore::load_file(input_head)
2024-05-09T05:03:45Z.0 restore::load_file(input_body)
2024-05-09T05:03:45Z.0 restore::load_file(output_head)
2024-05-09T05:03:45Z.0 restore::load_file(output_body)
2024-05-09T05:03:45Z.0 restore::load_file(point_head)
2024-05-09T05:03:45Z.0 restore::load_file(point_body)
2024-05-09T05:03:45Z.0 restore::load_file(puts_head)
2024-05-09T05:03:45Z.0 restore::load_file(puts_body)
2024-05-09T05:03:45Z.0 restore::load_file(spend_head)
2024-05-09T05:03:45Z.0 restore::load_file(spend_body)
2024-05-09T05:03:45Z.0 restore::load_file(tx_head)
2024-05-09T05:03:45Z.0 restore::load_file(tx_body)
2024-05-09T05:03:45Z.0 restore::load_file(txs_head)
2024-05-09T05:03:45Z.0 restore::load_file(txs_body)
2024-05-09T05:03:45Z.0 restore::load_file(candidate_head)
2024-05-09T05:03:45Z.0 restore::load_file(candidate_body)
2024-05-09T05:03:45Z.0 restore::load_file(confirmed_head)
2024-05-09T05:03:45Z.0 restore::load_file(confirmed_body)
2024-05-09T05:03:45Z.0 restore::load_file(strong_tx_head)
2024-05-09T05:03:45Z.0 restore::load_file(strong_tx_body)
2024-05-09T05:03:45Z.0 restore::load_file(validated_bk_head)
2024-05-09T05:03:45Z.0 restore::load_file(validated_bk_body)
2024-05-09T05:03:45Z.0 restore::load_file(validated_tx_head)
2024-05-09T05:03:45Z.0 restore::load_file(validated_tx_body)
2024-05-09T05:03:45Z.0 restore::load_file(address_head)
2024-05-09T05:03:45Z.0 restore::load_file(address_body)
2024-05-09T05:03:45Z.0 restore::load_file(neutrino_head)
2024-05-09T05:03:45Z.0 restore::load_file(neutrino_body)
2024-05-09T05:03:45Z.0 restore::restore_table(header_table)
2024-05-09T05:03:45Z.0 restore::restore_table(input_table)
2024-05-09T05:03:45Z.0 restore::restore_table(output_table)
2024-05-09T05:03:45Z.0 restore::restore_table(point_table)
2024-05-09T05:03:45Z.0 restore::restore_table(puts_table)
2024-05-09T05:03:45Z.0 restore::restore_table(spend_table)
2024-05-09T05:03:45Z.0 restore::restore_table(tx_table)
2024-05-09T05:03:45Z.0 restore::restore_table(txs_table)
2024-05-09T05:03:45Z.0 restore::restore_table(candidate_table)
2024-05-09T05:03:45Z.0 restore::restore_table(confirmed_table)
2024-05-09T05:03:45Z.0 restore::restore_table(strong_tx_table)
2024-05-09T05:03:45Z.0 restore::restore_table(validated_bk_table)
2024-05-09T05:03:45Z.0 restore::restore_table(validated_tx_table)
2024-05-09T05:03:45Z.0 restore::restore_table(address_table)
2024-05-09T05:03:45Z.0 restore::restore_table(neutrino_table)
2024-05-09T05:03:45Z.0 Restored the database in 17 secs.

05:06

As well as handling when there are no snapshots:

2024-05-09T05:05:53Z.0 ====================== startup =======================
2024-05-09T05:05:53Z.0 Press CTRL-C to stop the node.
2024-05-09T05:05:53Z.0 Log system configuration...
2024-05-09T05:05:53Z.0 Application.. compiled:1 enabled:1.
2024-05-09T05:05:53Z.0 News......... compiled:1 enabled:1.
2024-05-09T05:05:53Z.0 Session...... compiled:1 enabled:1.
2024-05-09T05:05:53Z.0 Protocol..... compiled:1 enabled:0.
2024-05-09T05:05:53Z.0 ProXy........ compiled:1 enabled:0.
2024-05-09T05:05:53Z.0 Wire......... compiled:0 enabled:0.
2024-05-09T05:05:53Z.0 Remote....... compiled:1 enabled:1.
2024-05-09T05:05:53Z.0 Fault........ compiled:1 enabled:1.
2024-05-09T05:05:53Z.0 Quit......... compiled:1 enabled:0.
2024-05-09T05:05:53Z.0 Object....... compiled:0 enabled:0.
2024-05-09T05:05:53Z.0 Verbose...... compiled:1 enabled:0.
2024-05-09T05:05:53Z.0 Using config file: "f:\\bn.cfg"
2024-05-09T05:05:53Z.0 Database failed to start with error 'flush lock failure'.
2024-05-09T05:05:53Z.0 Please wait while restoring from most recent snapshot...
2024-05-09T05:05:53Z.0 restore::recover_snapshot(store)
2024-05-09T05:05:53Z.0 Database restore failed with error 'missing snapshot'.
2024-05-09T05:05:53Z.0 Node stopped successfully.
2024-05-09T05:05:53Z.0 ====================== shutdown ======================
2024-05-09T05:05:53Z.0 Press <enter> to exit...

05:08

Also as you can see above, log system config. This is helpful since the log system allows for all or some categories to be compiled out, such that the messages are not even constructed. But this can be misleading if it's not clear in the log or at the console what options are both compiled and enabled. They can be toggled on the command line, if compiled in, which reflects in the log. But this allows us to see log levels from startup.