From 49a737b6a52fba652eba65a53989c246b789810e Mon Sep 17 00:00:00 2001 From: Christopher Haster Date: Tue, 28 Jan 2025 09:06:34 -0600 Subject: [PATCH] Added several more LFS_DEBUG* options To help with debugging. These all seem useful, though the exact output will probably be worth messing around with: - LFS_DEBUGRBYDFETCHES - Debug every rbyd fetch - LFS_DEBUGRBYDCOMMITS - Debug every rbyd commit - LFS_DEBUGBTREEFETCHES - Debug every btree/bshrub fetch (though we currently don't fetch bshrubs...) - LFS_DEBUGBTREECOMMITS - Debug every btree/bshrub commit - LFS_DEBUGMDIRFETCHES - Debug every mdir fetch - LFS_DEBUGMDIRCOMMITS - Debug every mdir commit - LFS_DEBUGALLOCS - Debug every block allocation Let's see if you can match these to each debug output: lfs.c:2942:debug: Fetched rbyd 0xe.d80 w77, eoff 3536, cksum 862283c6 lfs.c:4233:debug: Committed rbyd 0xe.dd0 w78, eoff 3616, cksum 38ae1347 lfs.c:4950:debug: Fetched btree 0x9f.806 w2048, cksum 7fb89b1b lfs.c:6609:debug: Committed btree 0x9f.806 w2048, cksum 7fb89b1b lfs.c:6603:debug: Committed bshrub 0x{0,1}.b06 w1747 lfs.c:7290:debug: Fetched mdir -1 0x{1,0}.8f w0, cksum 7846be7a lfs.c:9022:debug: Committed mdir 0 0x{0,1}.a10 w2, cksum 4d2ccb29 lfs.c:10083:debug: Allocated block 0x8f, lookahead 125/253/256 Also tweaked LFSR_DEBUGRBYDBALANCE to be a bit more readable when LFS_DEBUGRBYDFETCHES is enabled, and tweaked the out-of-space error message to show the same lookahead info as LFS_DEBUGALLOCS: lfs.c:10101:error: No more free space (lookahead 0/0/256) ^ ^ ^ lookahead remaining --' | | ckpoint remaining ------' | block count ---------------' No code changes. --- lfs.c | 110 +++++++++++++++++++++++++++++++++++++++++++++++++---- lfs_util.h | 6 --- 2 files changed, 102 insertions(+), 14 deletions(-) diff --git a/lfs.c b/lfs.c index b1c84b9f..91e008ed 100644 --- a/lfs.c +++ b/lfs.c @@ -2938,6 +2938,17 @@ static int lfsr_rbyd_fetch_(lfs_t *lfs, rbyd->eoff = -1; } + #ifdef LFS_DEBUGRBYDFETCHES + LFS_DEBUG("Fetched rbyd 0x%"PRIx32".%"PRIx32" w%"PRId32", " + "eoff %"PRId32", cksum %"PRIx32, + rbyd->blocks[0], lfsr_rbyd_trunk(rbyd), + rbyd->weight, + (lfsr_rbyd_eoff(rbyd) >= lfs->cfg->block_size) + ? -1 + : (lfs_ssize_t)lfsr_rbyd_eoff(rbyd), + rbyd->cksum); + #endif + // debugging rbyd balance? check that all branches in the rbyd have // the same height #ifdef LFS_DEBUGRBYDBALANCE @@ -2967,10 +2978,11 @@ static int lfsr_rbyd_fetch_(lfs_t *lfs, min_bheight = (min_bheight) ? lfs_min(min_bheight, bheight) : bheight; max_bheight = (max_bheight) ? lfs_max(max_bheight, bheight) : bheight; } - LFS_DEBUG("rbyd 0x%"PRIx32".%"PRIx32": " + LFS_DEBUG("Fetched rbyd 0x%"PRIx32".%"PRIx32" w%"PRId32", " "height %"PRId32"-%"PRId32", " "bheight %"PRId32"-%"PRId32, rbyd->blocks[0], lfsr_rbyd_trunk(rbyd), + rbyd->weight, min_height, max_height, min_bheight, max_bheight); // all branches in the rbyd should have the same bheight @@ -4216,6 +4228,17 @@ static int lfsr_rbyd_appendcksum_(lfs_t *lfs, lfsr_rbyd_t *rbyd, | off_; // revert to canonical checksum rbyd->cksum = cksum; + + #ifdef LFS_DEBUGRBYDCOMMITS + LFS_DEBUG("Committed rbyd 0x%"PRIx32".%"PRIx32" w%"PRId32", " + "eoff %"PRId32", cksum %"PRIx32, + rbyd->blocks[0], lfsr_rbyd_trunk(rbyd), + rbyd->weight, + (lfsr_rbyd_eoff(rbyd) >= lfs->cfg->block_size) + ? -1 + : (lfs_ssize_t)lfsr_rbyd_eoff(rbyd), + rbyd->cksum); + #endif return 0; } @@ -4916,9 +4939,21 @@ static int lfsr_btree_fetch(lfs_t *lfs, lfsr_btree_t *btree, lfs_block_t block, lfs_size_t trunk, lfsr_bid_t weight, uint32_t cksum) { // btree/branch fetch really are the same once we know the weight - return lfsr_branch_fetch(lfs, btree, + int err = lfsr_branch_fetch(lfs, btree, block, trunk, weight, cksum); + if (err) { + return err; + } + + #ifdef LFS_DEBUGBTREEFETCHES + LFS_DEBUG("Fetched btree 0x%"PRIx32".%"PRIx32" w%"PRId32", " + "cksum %"PRIx32, + btree->blocks[0], lfsr_rbyd_trunk(btree), + btree->weight, + btree->cksum); + #endif + return 0; } static int lfsr_data_fetchbtree(lfs_t *lfs, lfsr_data_t *data, @@ -5700,6 +5735,13 @@ static int lfsr_btree_commit_(lfs_t *lfs, lfsr_btree_t *btree, } LFS_ASSERT(lfsr_rbyd_trunk(btree)); + #ifdef LFS_DEBUGBTREECOMMITS + LFS_DEBUG("Committed btree 0x%"PRIx32".%"PRIx32" w%"PRId32", " + "cksum %"PRIx32, + btree->blocks[0], lfsr_rbyd_trunk(btree), + btree->weight, + btree->cksum); + #endif return 0; } @@ -6479,7 +6521,7 @@ static int lfsr_bshrub_commit_(lfs_t *lfs, LFS_ASSERT(!err || rat_count > 0); bool alloc = (err == LFS_ERR_RANGE); - // when btree is shrubbed, lfsr_btree_commit_ stops at the root + // when btree is shrubbed, lfsr_btree_commit__ stops at the root // and returns with pending rats if (rat_count > 0) { // we need to prevent our shrub from overflowing our mdir somehow @@ -6553,11 +6595,24 @@ static int lfsr_bshrub_commit_(lfs_t *lfs, } } LFS_ASSERT(bshrub->u.bshrub.estimate == (lfs_size_t)estimate); - - return 0; } LFS_ASSERT(lfsr_shrub_trunk(&bshrub->u.bshrub)); + #ifdef LFS_DEBUGBTREECOMMITS + if (lfsr_bshrub_isbshrub(mdir, bshrub)) { + LFS_DEBUG("Committed bshrub " + "0x{%"PRIx32",%"PRIx32"}.%"PRIx32" w%"PRId32, + mdir->rbyd.blocks[0], mdir->rbyd.blocks[1], + lfsr_shrub_trunk(&bshrub->u.bshrub), + bshrub->u.bshrub.weight); + } else { + LFS_DEBUG("Committed btree 0x%"PRIx32".%"PRIx32" w%"PRId32", " + "cksum %"PRIx32, + bshrub->u.btree.blocks[0], lfsr_rbyd_trunk(&bshrub->u.btree), + bshrub->u.btree.weight, + bshrub->u.btree.cksum); + } + #endif return 0; relocate:; @@ -6592,6 +6647,15 @@ relocate:; } bshrub->u.btree = rbyd_; + + LFS_ASSERT(lfsr_rbyd_trunk(&bshrub->u.btree)); + #ifdef LFS_DEBUGBTREECOMMITS + LFS_DEBUG("Committed btree 0x%"PRIx32".%"PRIx32" w%"PRId32", " + "cksum %"PRIx32, + bshrub->u.btree.blocks[0], lfsr_rbyd_trunk(&bshrub->u.btree), + bshrub->u.btree.weight, + bshrub->u.btree.cksum); + #endif return 0; } @@ -7222,6 +7286,16 @@ static int lfsr_mdir_fetch(lfs_t *lfs, lfsr_mdir_t *mdir, mdir->mid = mid; // keep track of other block for compactions mdir->rbyd.blocks[1] = blocks[1]; + #ifdef LFS_DEBUGMDIRFETCHES + LFS_DEBUG("Fetched mdir %"PRId32" " + "0x{%"PRIx32",%"PRIx32"}.%"PRIx32" w%"PRId32", " + "cksum %"PRIx32, + mdir->mid >> lfs->mdir_bits, + mdir->rbyd.blocks[0], mdir->rbyd.blocks[1], + lfsr_rbyd_trunk(&mdir->rbyd), + mdir->rbyd.weight, + mdir->rbyd.cksum); + #endif return 0; } @@ -8944,6 +9018,16 @@ static int lfsr_mdir_commit(lfs_t *lfs, lfsr_mdir_t *mdir, lfsr_mdir_sync(&lfs->mroot, &mroot_); lfs->mtree = mtree_; + #ifdef LFS_DEBUGMDIRCOMMITS + LFS_DEBUG("Committed mdir %"PRId32" " + "0x{%"PRIx32",%"PRIx32"}.%"PRIx32" w%"PRId32", " + "cksum %"PRIx32, + mdir->mid >> lfs->mdir_bits, + mdir->rbyd.blocks[0], mdir->rbyd.blocks[1], + lfsr_rbyd_trunk(&mdir->rbyd), + mdir->rbyd.weight, + mdir->rbyd.cksum); + #endif return 0; failed:; @@ -9995,6 +10079,14 @@ static lfs_sblock_t lfs_alloc(lfs_t *lfs, bool erase) { lfs_alloc_inc(lfs); lfs_alloc_findfree(lfs); + #ifdef LFS_DEBUGALLOCS + LFS_DEBUG("Allocated block 0x%"PRIx32", " + "lookahead %"PRId32"/%"PRId32"/%"PRId32, + block, + lfs->lookahead.size, + lfs->lookahead.ckpoint, + lfs->cfg->block_count); + #endif return block; } @@ -10006,9 +10098,11 @@ static lfs_sblock_t lfs_alloc(lfs_t *lfs, bool erase) { // the filesystem as out of storage // if (lfs->lookahead.ckpoint <= 0) { - LFS_ERROR("No more free space (0x%"PRIx32")", - (lfs->lookahead.window + lfs->lookahead.off) - % lfs->block_count); + LFS_ERROR("No more free space " + "(lookahead %"PRId32"/%"PRId32"/%"PRId32")", + lfs->lookahead.size, + lfs->lookahead.ckpoint, + lfs->cfg->block_count); return LFS_ERR_NOSPC; } diff --git a/lfs_util.h b/lfs_util.h index 88f1a779..e47d6c6b 100644 --- a/lfs_util.h +++ b/lfs_util.h @@ -204,12 +204,6 @@ extern "C" #define LFS_IFDEF_GC(a, b) (b) #endif -#ifdef LFS_DEBUGRBYDBALANCE -#define LFS_IFDEF_DEBUGRBYDBALANCE(a, b) (a) -#else -#define LFS_IFDEF_DEBUGRBYDBALANCE(a, b) (b) -#endif - // Builtin functions, these may be replaced by more efficient // toolchain-specific implementations. LFS_NO_BUILTINS falls back to a more