diff --git a/repos/gems/src/lib/tresor/block_io.cc b/repos/gems/src/lib/tresor/block_io.cc index 9aa9dbb274..9a739b4181 100644 --- a/repos/gems/src/lib/tresor/block_io.cc +++ b/repos/gems/src/lib/tresor/block_io.cc @@ -612,7 +612,9 @@ bool Block_io::_peek_completed_request(uint8_t *buf_ptr, } memcpy(buf_ptr, &req, sizeof(req)); - if (VERBOSE_BLOCK_IO) { + if (VERBOSE_BLOCK_IO && + (!VERBOSE_BLOCK_IO_PBA_FILTER || + VERBOSE_BLOCK_IO_PBA == req._pba)) { switch (req._type) { case Request::READ: diff --git a/repos/gems/src/lib/tresor/crypto.cc b/repos/gems/src/lib/tresor/crypto.cc index 16c5b488df..9def677a4d 100644 --- a/repos/gems/src/lib/tresor/crypto.cc +++ b/repos/gems/src/lib/tresor/crypto.cc @@ -18,6 +18,7 @@ /* tresor includes */ #include #include +#include using namespace Tresor; @@ -652,20 +653,20 @@ bool Crypto::_peek_completed_request(uint8_t *buf_ptr, memcpy(buf_ptr, &channel._request, sizeof(channel._request)); Request &req { channel._request }; - if (VERBOSE_VBA_ACCESS) { + if (VERBOSE_WRITE_VBA && req._type == Request::ENCRYPT_CLIENT_DATA) { - switch (req._type) { - case Request::DECRYPT_CLIENT_DATA: - case Request::ENCRYPT_CLIENT_DATA: - { - log(" plain ", *(Block *)channel._blk_buf); - log(" cipher ", *(Block *)req._ciphertext_blk_ptr); + Hash hash { }; + calc_sha256_4k_hash(*(Block *)channel._blk_buf, hash); + log(" encrypt leaf data: plaintext ", *(Block *)channel._blk_buf, " hash ", hash); + log(" update branch:"); + log(" ", Branch_lvl_prefix("leaf data: "), *(Block *)req._ciphertext_blk_ptr); + } + if (VERBOSE_READ_VBA && req._type == Request::DECRYPT_CLIENT_DATA) { - break; - } - default: - break; - } + Hash hash { }; + calc_sha256_4k_hash(*(Block *)channel._blk_buf, hash); + log(" ", Branch_lvl_prefix("leaf data: "), *(Block *)req._ciphertext_blk_ptr); + log(" decrypt leaf data: plaintext ", *(Block *)channel._blk_buf, " hash ", hash); } if (VERBOSE_CRYPTO) { diff --git a/repos/gems/src/lib/tresor/include/tresor/types.h b/repos/gems/src/lib/tresor/include/tresor/types.h index 9d96f31b7c..ab6dcd101c 100644 --- a/repos/gems/src/lib/tresor/include/tresor/types.h +++ b/repos/gems/src/lib/tresor/include/tresor/types.h @@ -19,6 +19,9 @@ #include #include +/* os includes */ +#include + /* tresor includes */ #include #include @@ -98,6 +101,13 @@ namespace Tresor { struct Tree_walk_pbas; struct Level_indent; + template + class Fixed_length; + + class Pba_allocation; + + using Branch_lvl_prefix = Fixed_length<15>; + constexpr Virtual_block_address tree_max_max_vba(Tree_degree degree, Tree_level_index max_lvl) { @@ -581,8 +591,8 @@ struct Tresor::Snapshot if (valid) Genode::print( out, "pba ", (Physical_block_address)pba, " gen ", - (Generation)gen, " hash ", hash, " leaves ", nr_of_leaves, - " max_lvl ", max_level); + (Generation)gen, " hash ", hash, " maxlvl ", max_level, " leaves ", + nr_of_leaves, " keep ", keep, " id ", id); else Genode::print(out, ""); } @@ -598,6 +608,19 @@ struct Tresor::Snapshots { Snapshot items[MAX_NR_OF_SNAPSHOTS]; + void print(Output &out) const + { + bool first { false }; + for (Snapshot_index idx { 0 }; idx < MAX_NR_OF_SNAPSHOTS; idx++) { + + if (!items[idx].valid) + continue; + + Genode::print(out, first ? "" : "\n", idx, ": ", items[idx]); + first = false; + } + } + void decode_from_blk(Block_scanner &scanner) { for (Snapshot &snap : items) @@ -826,12 +849,38 @@ struct Tresor::Superblock struct Tresor::Type_1_node_walk { Type_1_node nodes[TREE_MAX_NR_OF_LEVELS] { }; + + void print(Output &out) const + { + bool first { true }; + for (unsigned idx { 0 }; idx < TREE_MAX_NR_OF_LEVELS; idx++) { + + if (!nodes[idx].valid()) + continue; + + Genode::print(out, first ? "" : "\n", idx, ": ", nodes[idx]); + first = false; + } + } }; struct Tresor::Tree_walk_pbas { Physical_block_address pbas[TREE_MAX_NR_OF_LEVELS] { 0 }; + + void print(Output &out) const + { + bool first { true }; + for (unsigned idx { 0 }; idx < TREE_MAX_NR_OF_LEVELS; idx++) { + + if (!pbas[idx]) + continue; + + Genode::print(out, first ? "" : "\n", idx, ": ", pbas[idx]); + first = false; + } + } }; @@ -854,4 +903,54 @@ struct Tresor::Level_indent }; +template +class Tresor::Fixed_length +{ + private: + + String const _str; + + public: + + template + Fixed_length(ARGS &&... args) : _str(args...) { } + + void print(Output &out) const + { + Genode::print(out, Left_aligned(LEN, _str)); + } +}; + + +class Tresor::Pba_allocation { + + private: + + Type_1_node_walk const &_t1_node_walk; + Tree_walk_pbas const &_new_pbas; + + public: + + Pba_allocation(Type_1_node_walk const &t1_node_walk, + Tree_walk_pbas const &new_pbas) + : + _t1_node_walk { t1_node_walk }, + _new_pbas { new_pbas } + { } + + void print(Output &out) const + { + bool first { true }; + for (unsigned lvl { 0 }; lvl < TREE_MAX_NR_OF_LEVELS; lvl++) { + + if (_t1_node_walk.nodes[lvl].pba == _new_pbas.pbas[lvl]) + continue; + + Genode::print(out, first ? "" : ", ", _t1_node_walk.nodes[lvl].pba, " -> ", _new_pbas.pbas[lvl]); + first = false; + } + } +}; + + #endif /* _TRESOR__TYPES_H_ */ diff --git a/repos/gems/src/lib/tresor/include/tresor/verbosity.h b/repos/gems/src/lib/tresor/include/tresor/verbosity.h index 558ca82778..394776b4c2 100644 --- a/repos/gems/src/lib/tresor/include/tresor/verbosity.h +++ b/repos/gems/src/lib/tresor/include/tresor/verbosity.h @@ -20,9 +20,12 @@ namespace Tresor { enum { VERBOSE_VBD_EXTENSION = 0 }; enum { VERBOSE_FT_EXTENSION = 0 }; enum { VERBOSE_REKEYING = 0 }; - enum { VERBOSE_VBA_ACCESS = 0 }; + enum { VERBOSE_READ_VBA = 0 }; + enum { VERBOSE_WRITE_VBA = 0 }; enum { VERBOSE_CRYPTO = 0 }; enum { VERBOSE_BLOCK_IO = 0 }; + enum { VERBOSE_BLOCK_IO_PBA_FILTER = 0 }; + enum { VERBOSE_BLOCK_IO_PBA = 0 }; enum { VERBOSE_CHECK = 0 }; } diff --git a/repos/gems/src/lib/tresor/include/tresor/virtual_block_device.h b/repos/gems/src/lib/tresor/include/tresor/virtual_block_device.h index 79fa7edf88..401e2c63ec 100644 --- a/repos/gems/src/lib/tresor/include/tresor/virtual_block_device.h +++ b/repos/gems/src/lib/tresor/include/tresor/virtual_block_device.h @@ -139,6 +139,8 @@ class Tresor::Virtual_block_device_channel friend class Virtual_block_device; + using Request = Virtual_block_device_request; + enum State { SUBMITTED, READ_ROOT_NODE_PENDING, @@ -229,6 +231,8 @@ class Tresor::Virtual_block_device_channel Snapshot &snap(); + void _log_rekeying_pba_alloc() const; + Virtual_block_device_request _request { }; State _state { SUBMITTED }; Generated_prim _generated_prim { }; diff --git a/repos/gems/src/lib/tresor/superblock_control.cc b/repos/gems/src/lib/tresor/superblock_control.cc index 6b8a709c3c..cc6424bf14 100644 --- a/repos/gems/src/lib/tresor/superblock_control.cc +++ b/repos/gems/src/lib/tresor/superblock_control.cc @@ -181,7 +181,7 @@ void Superblock_control::_execute_read_vba(Channel &channel, channel._state = Channel::State::READ_VBA_AT_VBD_PENDING; progress = true; - if (VERBOSE_VBA_ACCESS) + if (VERBOSE_READ_VBA) log("read vba ", channel._request._vba, ": snap ", (Snapshot_index)_sb.curr_snap, " key ", (Key_id)channel._curr_key_plaintext.id); @@ -253,10 +253,11 @@ void Superblock_control::_execute_write_vba(Channel &channel, channel._state = Channel::State::WRITE_VBA_AT_VBD_PENDING; progress = true; - if (VERBOSE_VBA_ACCESS) + if (VERBOSE_WRITE_VBA) log("write vba ", channel._request._vba, ": snap ", (Snapshot_index)_sb.curr_snap, - " key ", (Key_id)channel._curr_key_plaintext.id); + " key ", (Key_id)channel._curr_key_plaintext.id, + " gen ", curr_gen); break; case Channel::State::WRITE_VBA_AT_VBD_COMPLETED: diff --git a/repos/gems/src/lib/tresor/virtual_block_device.cc b/repos/gems/src/lib/tresor/virtual_block_device.cc index cb73a3cb05..c63b3a3d34 100644 --- a/repos/gems/src/lib/tresor/virtual_block_device.cc +++ b/repos/gems/src/lib/tresor/virtual_block_device.cc @@ -232,11 +232,8 @@ void Virtual_block_device::_execute_read_vba_read_inner_node_completed (Channel .blk_nr = child.pba, .idx = job_idx }; - if (VERBOSE_VBA_ACCESS) { - log( - " lvl ", channel._t1_blk_idx, - ": read t1 nodes blk: pba ", channel._generated_prim.blk_nr); - } + if (VERBOSE_READ_VBA) + log(" ", Branch_lvl_prefix("lvl ", parent_lvl, " node ", child_idx, ": "), child); channel._state = Channel::State::READ_INNER_NODE_PENDING; progress = true; @@ -259,12 +256,8 @@ void Virtual_block_device::_execute_read_vba_read_inner_node_completed (Channel .blk_nr = child.pba, .idx = job_idx }; - if (VERBOSE_VBA_ACCESS) { - log( - " lvl ", 0, - ": read data blk: pba ", channel._generated_prim.blk_nr, - " key ", channel._request._new_key_id); - } + if (VERBOSE_READ_VBA) + log(" ", Branch_lvl_prefix("lvl ", parent_lvl, " node ", child_idx, ": "), child); channel._state = Channel::State::READ_CLIENT_DATA_FROM_LEAF_NODE_PENDING; progress = true; @@ -294,10 +287,10 @@ void Virtual_block_device::_execute_read_vba(Channel &channel, .blk_nr = snapshot.pba, .idx = idx }; - if (VERBOSE_VBA_ACCESS) - log(" lvl ", channel._t1_blk_idx, ": read t1 nodes blk: pba ", - channel._generated_prim.blk_nr); - + if (VERBOSE_READ_VBA) { + log(" load branch:"); + log(" ", Branch_lvl_prefix("root: "), snapshot); + } channel._state = Channel::State::READ_ROOT_NODE_PENDING; progress = true; break; @@ -344,6 +337,9 @@ void Virtual_block_device::_update_nodes_of_branch_of_written_vba(Snapshot &snap node.gen = curr_gen; node.hash = leaf_hash; + if (VERBOSE_WRITE_VBA) + log(" ", Branch_lvl_prefix("lvl ", lvl + 1, " node ", child_idx, ": "), node); + } else if (lvl < snapshot.max_level) { auto const child_idx = t1_child_idx_for_vba(vba, lvl + 1, snapshot_degree); @@ -356,6 +352,9 @@ void Virtual_block_device::_update_nodes_of_branch_of_written_vba(Snapshot &snap t1_blks.items[lvl].encode_to_blk(blk); calc_sha256_4k_hash(blk, node.hash); + if (VERBOSE_WRITE_VBA) + log(" ", Branch_lvl_prefix("lvl ", lvl + 1, " node ", child_idx, ": "), node); + } else { snapshot.pba = new_pbas.pbas[lvl]; @@ -364,6 +363,9 @@ void Virtual_block_device::_update_nodes_of_branch_of_written_vba(Snapshot &snap Block blk { }; t1_blks.items[lvl].encode_to_blk(blk); calc_sha256_4k_hash(blk, snapshot.hash); + + if (VERBOSE_WRITE_VBA) + log(" ", Branch_lvl_prefix("root: "), snapshot); } } } @@ -580,6 +582,10 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._vba = request._vba; chan._t1_blk_idx = chan.snapshots(chan._snapshot_idx).max_level; + if (VERBOSE_WRITE_VBA) { + log(" load branch:"); + log(" ", Branch_lvl_prefix("root: "), chan.snapshots(chan._snapshot_idx)); + } _set_args_in_order_to_read_type_1_node(chan.snapshots(chan._snapshot_idx), chan._request._snapshots_degree, chan._t1_blk_idx, @@ -590,11 +596,6 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._generated_prim, progress); - if (VERBOSE_VBA_ACCESS) { - log(" lvl ", chan._t1_blk_idx, ": read t1 nodes blk: pba ", - chan._generated_prim.blk_nr); - } - break; } case Channel::State::READ_INNER_NODE_COMPLETED: @@ -605,6 +606,11 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._t1_blk_idx, chan._t1_blks, chan._vba); + if (VERBOSE_WRITE_VBA) { + uint64_t const child_idx { t1_child_idx_for_vba(chan._vba, chan._t1_blk_idx, chan._request._snapshots_degree) }; + Type_1_node const &child { chan._t1_blks.items[chan._t1_blk_idx].nodes[child_idx] }; + log(" ", Branch_lvl_prefix("lvl ", chan._t1_blk_idx, " node ", child_idx, ": "), child); + } if (chan._t1_blk_idx > 1) { chan._t1_blk_idx = chan._t1_blk_idx - 1; @@ -618,11 +624,6 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._generated_prim, progress); - if (VERBOSE_VBA_ACCESS) { - log(" lvl ", chan._t1_blk_idx, ": read t1 nodes blk: pba ", - chan._generated_prim.blk_nr); - } - } else { _initialize_new_pbas_and_determine_nr_of_pbas_to_allocate(req._curr_gen, chan.snapshots(chan._snapshot_idx), @@ -652,11 +653,6 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._state, chan._generated_prim, progress); - - if (VERBOSE_VBA_ACCESS) - log(" lvl ", 0, ": write data blk: pba ", - chan._generated_prim.blk_nr, - " key ", req._new_key_id); } } @@ -665,30 +661,14 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, _check_that_primitive_was_successful(chan._generated_prim); - if (VERBOSE_VBA_ACCESS) { - log(" lvl ", 0, ": alloc ", chan._nr_of_blks, " pba", - chan._nr_of_blks > 1 ? "s" : ""); + if (VERBOSE_WRITE_VBA) + log(" alloc pba", chan._nr_of_blks > 1 ? "s" : "", ": ", Pba_allocation(chan._t1_node_walk, chan._new_pbas)); - for (Tree_level_index lvl = TREE_MAX_LEVEL; ; lvl--) { - if (lvl <= chan.snapshots(chan._snapshot_idx).max_level) { - Type_1_node &node = chan._t1_node_walk.nodes[lvl]; - log(" lvl ", lvl, " gen ", (Generation)node.gen, - " pba ", (Physical_block_address)node.pba, " -> ", - (Physical_block_address)chan._new_pbas.pbas[lvl]); - } - if (lvl == 0) - break; - } - } _set_args_in_order_to_write_client_data_to_leaf_node(chan._new_pbas, job_idx, chan._state, chan._generated_prim, progress); - if (VERBOSE_VBA_ACCESS) - log(" lvl ", 0, ": write data blk: pba ", - chan._generated_prim.blk_nr, - " key ", req._new_key_id); break; @@ -705,10 +685,6 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._new_pbas.pbas[chan._t1_blk_idx], job_idx, chan._state, progress, chan._generated_prim); - if (VERBOSE_VBA_ACCESS) - log(" lvl ", chan._t1_blk_idx, ": write t1 nodes blk: pba ", - chan._generated_prim.blk_nr); - break; case Channel::State::WRITE_INNER_NODE_COMPLETED: @@ -721,10 +697,6 @@ void Virtual_block_device::_execute_write_vba(Channel &chan, chan._t1_blk_idx, chan._new_pbas.pbas[chan._t1_blk_idx], job_idx, chan._state, progress, chan._generated_prim); - if (VERBOSE_VBA_ACCESS) - log(" lvl ", chan._t1_blk_idx, ": write t1 nodes blk: pba ", - chan._generated_prim.blk_nr); - break; case Channel::State::WRITE_ROOT_NODE_COMPLETED: @@ -908,6 +880,13 @@ _set_args_for_alloc_of_new_pbas_for_rekeying(Channel &chan, } +void Virtual_block_device_channel::_log_rekeying_pba_alloc() const +{ + if (VERBOSE_REKEYING) + log(" alloc pba", _nr_of_blks > 1 ? "s" : "", ": ", Pba_allocation { _t1_node_walk, _new_pbas }); +} + + void Virtual_block_device::_execute_rekey_vba(Channel &chan, uint64_t chan_idx, bool &progress) @@ -948,8 +927,8 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, if (VERBOSE_REKEYING) { log(" snapshot ", chan._snapshot_idx, ":"); - log(" lvl ", (Tree_level_index)snap.max_level + 1, - ": old snap: ", snap); + log(" load branch:"); + log(" ", Branch_lvl_prefix("root: "), snap); } chan._generated_prim = { .op = Generated_prim::READ, @@ -1001,8 +980,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, Type_1_node const &child { chan._t1_blks.items[parent_lvl].nodes[child_idx] }; if (VERBOSE_REKEYING) - log(" lvl ", parent_lvl, ": old t1 node ", child_idx, - ": ", child); + log(" ", Branch_lvl_prefix("lvl ", parent_lvl, " node ", child_idx, ": "), child); if (!chan._first_snapshot && chan._t1_blks_old_pbas.items[child_lvl] == child.pba) { @@ -1015,6 +993,10 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, chan._t1_blk_idx = child_lvl; _set_args_for_alloc_of_new_pbas_for_rekeying(chan, chan_idx, parent_lvl); chan._state = Channel::ALLOC_PBAS_AT_HIGHER_INNER_LVL_PENDING; + + if (VERBOSE_REKEYING) + log(" [child already rekeyed at pba ", chan._new_pbas.pbas[child_lvl], "]"); + progress = true; } else { @@ -1041,8 +1023,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, Type_1_node const &child { chan._t1_blks.items[parent_lvl].nodes[child_idx] }; if (VERBOSE_REKEYING) - log(" lvl ", parent_lvl, ": old t1 node ", child_idx, - ": ", child); + log(" ", Branch_lvl_prefix("lvl ", parent_lvl, " node ", child_idx, ": "), child); if (!chan._first_snapshot && chan._data_blk_old_pba == child.pba) { @@ -1055,6 +1036,9 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, _set_args_for_alloc_of_new_pbas_for_rekeying( chan, chan_idx, parent_lvl); + if (VERBOSE_REKEYING) + log(" [child already rekeyed at pba ", chan._new_pbas.pbas[0], "]"); + chan._state = Channel::ALLOC_PBAS_AT_LOWEST_INNER_LVL_PENDING; progress = true; @@ -1066,6 +1050,10 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, * zeroes for it regardless of the used key. */ _set_args_for_alloc_of_new_pbas_for_rekeying(chan, chan_idx, 0); + + if (VERBOSE_REKEYING) + log(" [child needs no rekeying]"); + chan._state = Channel::ALLOC_PBAS_AT_LOWEST_INNER_LVL_PENDING; progress = true; @@ -1113,7 +1101,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, progress = true; if (VERBOSE_REKEYING) - log(" lvl 0: old data: cipher ", chan._data_blk); + log(" ", Branch_lvl_prefix("leaf data: "), chan._data_blk); break; } @@ -1122,11 +1110,14 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, if (_handle_failed_generated_req(chan, progress)) break; - if (VERBOSE_REKEYING) - log(" plain ", chan._data_blk); - _set_args_for_alloc_of_new_pbas_for_rekeying(chan, chan_idx, 0); chan._state = Channel::ALLOC_PBAS_AT_LEAF_LVL_PENDING; + + if (VERBOSE_REKEYING) { + Hash hash { }; + calc_sha256_4k_hash(chan._data_blk, hash); + log(" re-encrypt leaf data: plaintext ", chan._data_blk, " hash ", hash); + } progress = true; break; @@ -1135,6 +1126,11 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, if (_handle_failed_generated_req(chan, progress)) break; + chan._log_rekeying_pba_alloc(); + + if (VERBOSE_REKEYING) + log(" update branch:"); + chan._state = Channel::WRITE_LEAF_NODE_COMPLETED; progress = true; break; @@ -1144,6 +1140,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, if (_handle_failed_generated_req(chan, progress)) break; + chan._log_rekeying_pba_alloc(); chan._generated_prim = { .op = Generated_prim::WRITE, .succ = false, @@ -1153,10 +1150,6 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, }; chan._state = Channel::ENCRYPT_LEAF_NODE_PENDING; progress = true; - - if (VERBOSE_REKEYING) - log(" lvl 0: new data: plain ", chan._data_blk); - break; case Channel::ENCRYPT_LEAF_NODE_COMPLETED: @@ -1178,9 +1171,10 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, chan._state = Channel::WRITE_LEAF_NODE_PENDING; progress = true; - if (VERBOSE_REKEYING) - log(" cipher ", chan._data_blk); - + if (VERBOSE_REKEYING) { + log(" update branch:"); + log(" ", Branch_lvl_prefix("leaf data: "), chan._data_blk); + } break; } case Channel::WRITE_LEAF_NODE_COMPLETED: @@ -1200,8 +1194,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, calc_sha256_4k_hash(chan._data_blk, node.hash); if (VERBOSE_REKEYING) - log(" lvl ", parent_lvl, - ": new t1 node ", child_idx, ": ", node); + log(" ", Branch_lvl_prefix("lvl ", parent_lvl, " node ", child_idx, ": "), node); chan._generated_prim = { .op = Generated_prim::WRITE, @@ -1232,8 +1225,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, calc_sha256_4k_hash(chan._encoded_blk, node.hash); if (VERBOSE_REKEYING) - log(" lvl ", parent_lvl, - ": new t1 node ", child_idx, ": ", node); + log(" ", Branch_lvl_prefix("lvl ", parent_lvl, " node ", child_idx, ": "), node); chan._t1_blk_idx++; chan._generated_prim = { @@ -1264,8 +1256,7 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, calc_sha256_4k_hash(chan._encoded_blk, snap.hash); if (VERBOSE_REKEYING) - log(" lvl ", (Tree_level_index)snap.max_level + 1, - ": new snap: ", snap); + log(" ", Branch_lvl_prefix("root: "), snap); Snapshot_index next_snap_idx { 0 }; if (_find_next_snap_to_rekey_vba_at(chan, next_snap_idx)) { @@ -1292,8 +1283,11 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, chan._state = Channel::READ_ROOT_NODE_PENDING; progress = true; - if (VERBOSE_REKEYING) + if (VERBOSE_REKEYING) { log(" snapshot ", chan._snapshot_idx, ":"); + log(" load branch:"); + log(" ", Branch_lvl_prefix("root: "), snap); + } } } else { @@ -1307,7 +1301,12 @@ void Virtual_block_device::_execute_rekey_vba(Channel &chan, if (_handle_failed_generated_req(chan, progress)) break; + chan._log_rekeying_pba_alloc(); chan._state = Channel::WRITE_INNER_NODE_COMPLETED; + + if (VERBOSE_REKEYING) + log(" update branch:"); + progress = true; default: