Last minute tweaks to debug scripts

- Standardized littlefs debug statements to use hex prefixes and
  brackets for printing pairs.

- Removed the entry behavior for readtree and made -t the default.
  This is because 1. the CTZ skip-list parsing was broken, which is not
  surprising, and 2. the entry parsing was more complicated than useful.
  This functionality may be better implemented as a proper filesystem
  read script, complete with directory tree dumping.

- Changed test.py's --gdb argument to take [init, main, assert],
  this matches the names of the stages in C's startup.

- Added printing of tail to all mdir dumps in readtree/readmdir.

- Added a print for if any mdirs are corrupted in readtree.

- Added debug script side-effects to .gitignore.

.gitignore

@@ -8,3 +8,5 @@ blocks/
 lfs
 test.c
 tests/*.toml.*
+scripts/__pycache__
+.gdb_history

lfs.c

@@ -979,7 +979,7 @@ static lfs_stag_t lfs_dir_fetchmatch(lfs_t *lfs,
         dir->rev = revs[(r+1)%2];
     }
 
-    LFS_ERROR("Corrupted dir pair at %"PRIx32" %"PRIx32,
+    LFS_ERROR("Corrupted dir pair at {0x%"PRIx32", 0x%"PRIx32"}",
             dir->pair[0], dir->pair[1]);
     return LFS_ERR_CORRUPT;
 }
@@ -1667,12 +1667,13 @@ relocate:
         relocated = true;
         lfs_cache_drop(lfs, &lfs->pcache);
         if (!tired) {
-            LFS_DEBUG("Bad block at %"PRIx32, dir->pair[1]);
+            LFS_DEBUG("Bad block at 0x%"PRIx32, dir->pair[1]);
         }
 
         // can't relocate superblock, filesystem is now frozen
         if (lfs_pair_cmp(dir->pair, (const lfs_block_t[2]){0, 1}) == 0) {
-            LFS_WARN("Superblock %"PRIx32" has become unwritable", dir->pair[1]);
+            LFS_WARN("Superblock 0x%"PRIx32" has become unwritable",
+                    dir->pair[1]);
             return LFS_ERR_NOSPC;
         }
 
@@ -1688,7 +1689,8 @@ relocate:
 
     if (relocated) {
         // update references if we relocated
-        LFS_DEBUG("Relocating %"PRIx32" %"PRIx32" -> %"PRIx32" %"PRIx32,
+        LFS_DEBUG("Relocating {0x%"PRIx32", 0x%"PRIx32"} "
+                    "-> {0x%"PRIx32", 0x%"PRIx32"}",
                 oldpair[0], oldpair[1], dir->pair[0], dir->pair[1]);
         int err = lfs_fs_relocate(lfs, oldpair, dir->pair);
         if (err) {
@@ -2311,7 +2313,7 @@ static int lfs_ctz_extend(lfs_t *lfs,
         }
 
 relocate:
-        LFS_DEBUG("Bad block at %"PRIx32, nblock);
+        LFS_DEBUG("Bad block at 0x%"PRIx32, nblock);
 
         // just clear cache and try a new block
         lfs_cache_drop(lfs, pcache);
@@ -2615,7 +2617,7 @@ static int lfs_file_relocate(lfs_t *lfs, lfs_file_t *file) {
         return 0;
 
 relocate:
-        LFS_DEBUG("Bad block at %"PRIx32, nblock);
+        LFS_DEBUG("Bad block at 0x%"PRIx32, nblock);
 
         // just clear cache and try a new block
         lfs_cache_drop(lfs, &lfs->pcache);
@@ -2692,7 +2694,7 @@ static int lfs_file_flush(lfs_t *lfs, lfs_file_t *file) {
                 break;
 
 relocate:
-                LFS_DEBUG("Bad block at %"PRIx32, file->block);
+                LFS_DEBUG("Bad block at 0x%"PRIx32, file->block);
                 err = lfs_file_relocate(lfs, file);
                 if (err) {
                     return err;
@@ -3716,7 +3718,7 @@ int lfs_mount(lfs_t *lfs, const struct lfs_config *cfg) {
             uint16_t minor_version = (0xffff & (superblock.version >>  0));
             if ((major_version != LFS_DISK_VERSION_MAJOR ||
                  minor_version > LFS_DISK_VERSION_MINOR)) {
-                LFS_ERROR("Invalid version %"PRIu16".%"PRIu16,
+                LFS_ERROR("Invalid version v%"PRIu16".%"PRIu16,
                         major_version, minor_version);
                 err = LFS_ERR_INVAL;
                 goto cleanup;
@@ -3772,7 +3774,7 @@ int lfs_mount(lfs_t *lfs, const struct lfs_config *cfg) {
 
     // update littlefs with gstate
     if (!lfs_gstate_iszero(&lfs->gstate)) {
-        LFS_DEBUG("Found pending gstate %08"PRIx32" %08"PRIx32" %08"PRIx32,
+        LFS_DEBUG("Found pending gstate 0x%08"PRIx32"%08"PRIx32"%08"PRIx32,
                 lfs->gstate.tag,
                 lfs->gstate.pair[0],
                 lfs->gstate.pair[1]);
@@ -3987,8 +3989,6 @@ static int lfs_fs_relocate(lfs_t *lfs,
         const lfs_block_t oldpair[2], lfs_block_t newpair[2]) {
     // update internal root
     if (lfs_pair_cmp(oldpair, lfs->root) == 0) {
-        LFS_DEBUG("Relocating root %"PRIx32" %"PRIx32,
-                newpair[0], newpair[1]);
         lfs->root[0] = newpair[0];
         lfs->root[1] = newpair[1];
     }
@@ -4024,7 +4024,7 @@ static int lfs_fs_relocate(lfs_t *lfs,
         if (lfs_gstate_hasmovehere(&lfs->gstate, parent.pair)) {
             moveid = lfs_tag_id(lfs->gstate.tag);
             LFS_DEBUG("Fixing move while relocating "
-                    "%"PRIx32" %"PRIx32" %"PRIx16"\n",
+                    "{0x%"PRIx32", 0x%"PRIx32"} 0x%"PRIx16"\n",
                     parent.pair[0], parent.pair[1], moveid);
             lfs_fs_prepmove(lfs, 0x3ff, NULL);
             if (moveid < lfs_tag_id(tag)) {
@@ -4060,7 +4060,7 @@ static int lfs_fs_relocate(lfs_t *lfs,
         if (lfs_gstate_hasmovehere(&lfs->gstate, parent.pair)) {
             moveid = lfs_tag_id(lfs->gstate.tag);
             LFS_DEBUG("Fixing move while relocating "
-                    "%"PRIx32" %"PRIx32" %"PRIx16"\n",
+                    "{0x%"PRIx32", 0x%"PRIx32"} 0x%"PRIx16"\n",
                     parent.pair[0], parent.pair[1], moveid);
             lfs_fs_prepmove(lfs, 0x3ff, NULL);
         }
@@ -4101,7 +4101,7 @@ static int lfs_fs_demove(lfs_t *lfs) {
     }
 
     // Fix bad moves
-    LFS_DEBUG("Fixing move %"PRIx32" %"PRIx32" %"PRIx16,
+    LFS_DEBUG("Fixing move {0x%"PRIx32", 0x%"PRIx32"} 0x%"PRIx16,
             lfs->gdisk.pair[0],
             lfs->gdisk.pair[1],
             lfs_tag_id(lfs->gdisk.tag));
@@ -4152,7 +4152,7 @@ static int lfs_fs_deorphan(lfs_t *lfs) {
 
             if (tag == LFS_ERR_NOENT) {
                 // we are an orphan
-                LFS_DEBUG("Fixing orphan %"PRIx32" %"PRIx32,
+                LFS_DEBUG("Fixing orphan {0x%"PRIx32", 0x%"PRIx32"}",
                         pdir.tail[0], pdir.tail[1]);
 
                 err = lfs_dir_drop(lfs, &pdir, &dir);
@@ -4174,8 +4174,8 @@ static int lfs_fs_deorphan(lfs_t *lfs) {
 
             if (!lfs_pair_sync(pair, pdir.tail)) {
                 // we have desynced
-                LFS_DEBUG("Fixing half-orphan "
-                        "%"PRIx32" %"PRIx32" -> %"PRIx32" %"PRIx32,
+                LFS_DEBUG("Fixing half-orphan {0x%"PRIx32", 0x%"PRIx32"} "
+                            "-> {0x%"PRIx32", 0x%"PRIx32"}",
                         pdir.tail[0], pdir.tail[1], pair[0], pair[1]);
 
                 lfs_pair_tole32(pair);
@@ -4438,7 +4438,7 @@ static int lfs1_dir_fetch(lfs_t *lfs,
     }
 
     if (!valid) {
-        LFS_ERROR("Corrupted dir pair at %" PRIx32 " %" PRIx32 ,
+        LFS_ERROR("Corrupted dir pair at {0x%"PRIx32", 0x%"PRIx32"}",
                 tpair[0], tpair[1]);
         return LFS_ERR_CORRUPT;
     }
@@ -4626,7 +4626,8 @@ static int lfs1_mount(lfs_t *lfs, struct lfs1 *lfs1,
         }
 
         if (err || memcmp(superblock.d.magic, "littlefs", 8) != 0) {
-            LFS_ERROR("Invalid superblock at %d %d", 0, 1);
+            LFS_ERROR("Invalid superblock at {0x%"PRIx32", 0x%"PRIx32"}",
+                    0, 1);
             err = LFS_ERR_CORRUPT;
             goto cleanup;
         }
@@ -4635,7 +4636,7 @@ static int lfs1_mount(lfs_t *lfs, struct lfs1 *lfs1,
         uint16_t minor_version = (0xffff & (superblock.d.version >>  0));
         if ((major_version != LFS1_DISK_VERSION_MAJOR ||
              minor_version > LFS1_DISK_VERSION_MINOR)) {
-            LFS_ERROR("Invalid version %d.%d", major_version, minor_version);
+            LFS_ERROR("Invalid version v%d.%d", major_version, minor_version);
             err = LFS_ERR_INVAL;
             goto cleanup;
         }
@@ -4801,7 +4802,8 @@ int lfs_migrate(lfs_t *lfs, const struct lfs_config *cfg) {
 
             // Copy over first block to thread into fs. Unfortunately
             // if this fails there is not much we can do.
-            LFS_DEBUG("Migrating %"PRIx32" %"PRIx32" -> %"PRIx32" %"PRIx32,
+            LFS_DEBUG("Migrating {0x%"PRIx32", 0x%"PRIx32"} "
+                        "-> {0x%"PRIx32", 0x%"PRIx32"}",
                     lfs->root[0], lfs->root[1], dir1.head[0], dir1.head[1]);
 
             err = lfs_bd_erase(lfs, dir1.head[1]);

scripts/readmdir.py

@@ -233,8 +233,8 @@ class MetadataPair:
 
     def __lt__(self, other):
         # corrupt blocks don't count
-        if not self and other:
-            return True
+        if not self or not other:
+            return bool(other)
 
         # use sequence arithmetic to avoid overflow
         return not ((other.rev - self.rev) & 0x80000000)
@@ -318,14 +318,24 @@ def main(args):
 
     # find most recent pair
     mdir = MetadataPair(blocks)
-    print("mdir {%s} rev %d%s%s" % (
+
+    try:
+        mdir.tail = mdir[Tag('tail', 0, 0)]
+        if mdir.tail.size != 8 or mdir.tail.data == 8*b'\xff':
+            mdir.tail = None
+    except KeyError:
+        mdir.tail = None
+
+    print("mdir {%s} rev %d%s%s%s" % (
         ', '.join('%#x' % b
             for b in [args.block1, args.block2]
             if b is not None),
         mdir.rev,
         ' (was %s)' % ', '.join('%d' % m.rev for m in mdir.pair[1:])
         if len(mdir.pair) > 1 else '',
-        ' (corrupted)' if not mdir else ''))
+        ' (corrupted!)' if not mdir else '',
+        ' -> {%#x, %#x}' % struct.unpack('<II', mdir.tail.data)
+        if mdir.tail else ''))
     if args.all:
         mdir.dump_all(truncate=not args.no_truncate)
     elif args.log:

scripts/readtree.py

@@ -7,97 +7,14 @@ import io
 import itertools as it
 from readmdir import Tag, MetadataPair
 
-def popc(x):
-    return bin(x).count('1')
-
-def ctz(x):
-    return len(bin(x)) - len(bin(x).rstrip('0'))
-
-def dumpentries(args, mdir, f):
-    for k, id_ in enumerate(mdir.ids):
-        name = mdir[Tag('name', id_, 0)]
-        struct_ = mdir[Tag('struct', id_, 0)]
-
-        desc = "id %d %s %s" % (
-            id_, name.typerepr(),
-            json.dumps(name.data.decode('utf8')))
-        if struct_.is_('dirstruct'):
-            desc += " dir {%#x, %#x}" % struct.unpack(
-                '<II', struct_.data[:8].ljust(8, b'\xff'))
-        if struct_.is_('ctzstruct'):
-            desc += " ctz {%#x} size %d" % struct.unpack(
-                '<II', struct_.data[:8].ljust(8, b'\xff'))
-        if struct_.is_('inlinestruct'):
-            desc += " inline size %d" % struct_.size
-
-        data = None
-        if struct_.is_('inlinestruct'):
-            data = struct_.data
-        elif struct_.is_('ctzstruct'):
-            block, size = struct.unpack(
-                '<II', struct_.data[:8].ljust(8, b'\xff'))
-            data = []
-            i = 0 if size == 0 else (size-1) // (args.block_size - 8)
-            if i != 0:
-                i = ((size-1) - 4*popc(i-1)+2) // (args.block_size - 8)
-            with open(args.disk, 'rb') as f2:
-                while i >= 0:
-                    f2.seek(block * args.block_size)
-                    dat = f2.read(args.block_size)
-                    data.append(dat[4*(ctz(i)+1) if i != 0 else 0:])
-                    block, = struct.unpack('<I', dat[:4].ljust(4, b'\xff'))
-                    i -= 1
-            data = bytes(it.islice(
-                it.chain.from_iterable(reversed(data)), size))
-
-        f.write("%-45s%s\n" % (desc,
-            "%-23s  %-8s" % (
-                ' '.join('%02x' % c for c in data[:8]),
-                ''.join(c if c >= ' ' and c <= '~' else '.'
-                    for c in map(chr, data[:8])))
-            if not args.no_truncate and len(desc) < 45
-                and data is not None else ""))
-
-        if name.is_('superblock') and struct_.is_('inlinestruct'):
-            f.write(
-                "  block_size %d\n"
-                "  block_count %d\n"
-                "  name_max %d\n"
-                "  file_max %d\n"
-                "  attr_max %d\n" % struct.unpack(
-                    '<IIIII', struct_.data[4:4+20].ljust(20, b'\xff')))
-
-        for tag in mdir.tags:
-            if tag.id==id_ and tag.is_('userattr'):
-                desc = "%s size %d" % (tag.typerepr(), tag.size)
-                f.write("  %-43s%s\n" % (desc,
-                    "%-23s  %-8s" % (
-                        ' '.join('%02x' % c for c in tag.data[:8]),
-                        ''.join(c if c >= ' ' and c <= '~' else '.'
-                            for c in map(chr, tag.data[:8])))
-                    if not args.no_truncate and len(desc) < 43 else ""))
-
-                if args.no_truncate:
-                    for i in range(0, len(tag.data), 16):
-                        f.write("    %08x: %-47s  %-16s\n" % (
-                            i, ' '.join('%02x' % c for c in tag.data[i:i+16]),
-                            ''.join(c if c >= ' ' and c <= '~' else '.'
-                                for c in map(chr, tag.data[i:i+16]))))
-
-        if args.no_truncate and data is not None:
-            for i in range(0, len(data), 16):
-                f.write("  %08x: %-47s  %-16s\n" % (
-                    i, ' '.join('%02x' % c for c in data[i:i+16]),
-                    ''.join(c if c >= ' ' and c <= '~' else '.'
-                        for c in map(chr, data[i:i+16]))))
-
 def main(args):
+    superblock = None
+    gstate = b'\0\0\0\0\0\0\0\0\0\0\0\0'
+    dirs = []
+    mdirs = []
+    corrupted = []
+    cycle = False
     with open(args.disk, 'rb') as f:
-        dirs = []
-        superblock = None
-        gstate = b''
-        mdirs = []
-        cycle = False
         tail = (args.block1, args.block2)
         hard = False
         while True:
@@ -144,6 +61,10 @@ def main(args):
             except KeyError:
                 pass
 
+            # corrupted?
+            if not mdir:
+                corrupted.append(mdir)
+
             # add to directories
             mdirs.append(mdir)
             if mdir.tail is None or not mdir.tail.is_('hardtail'):
@@ -178,7 +99,7 @@ def main(args):
 
         dir[0].path = path.replace('//', '/')
 
-    # dump tree
+    # print littlefs + version info
     version = ('?', '?')
     if superblock:
         version = tuple(reversed(
@@ -187,53 +108,56 @@ def main(args):
         "data (truncated, if it fits)"
         if not any([args.no_truncate, args.tags, args.log, args.all]) else ""))
 
-    if gstate:
-        print("gstate 0x%s" % ''.join('%02x' % c for c in gstate))
-        tag = Tag(struct.unpack('<I', gstate[0:4].ljust(4, b'\xff'))[0])
-        blocks = struct.unpack('<II', gstate[4:4+8].ljust(8, b'\xff'))
-        if tag.size or not tag.isvalid:
-            print("  orphans >=%d" % max(tag.size, 1))
-        if tag.type:
-            print("  move dir {%#x, %#x} id %d" % (
-                blocks[0], blocks[1], tag.id))
-
+    # print gstate
+    print("gstate 0x%s" % ''.join('%02x' % c for c in gstate))
+    tag = Tag(struct.unpack('<I', gstate[0:4].ljust(4, b'\xff'))[0])
+    blocks = struct.unpack('<II', gstate[4:4+8].ljust(8, b'\xff'))
+    if tag.size or not tag.isvalid:
+        print("  orphans >=%d" % max(tag.size, 1))
+    if tag.type:
+        print("  move dir {%#x, %#x} id %d" % (
+            blocks[0], blocks[1], tag.id))
+
+    # print mdir info
     for i, dir in enumerate(dirs):
         print("dir %s" % (json.dumps(dir[0].path)
             if hasattr(dir[0], 'path') else '(orphan)'))
 
         for j, mdir in enumerate(dir):
-            print("mdir {%#x, %#x} rev %d%s" % (
-                mdir.blocks[0], mdir.blocks[1], mdir.rev,
-                ' (corrupted)' if not mdir else ''))
+            print("mdir {%#x, %#x} rev %d (was %d)%s%s" % (
+                mdir.blocks[0], mdir.blocks[1], mdir.rev, mdir.pair[1].rev,
+                ' (corrupted!)' if not mdir else '',
+                ' -> {%#x, %#x}' % struct.unpack('<II', mdir.tail.data)
+                if mdir.tail else ''))
 
             f = io.StringIO()
-            if args.tags:
-                mdir.dump_tags(f, truncate=not args.no_truncate)
-            elif args.log:
+            if args.log:
                 mdir.dump_log(f, truncate=not args.no_truncate)
             elif args.all:
                 mdir.dump_all(f, truncate=not args.no_truncate)
             else:
-                dumpentries(args, mdir, f)
+                mdir.dump_tags(f, truncate=not args.no_truncate)
 
             lines = list(filter(None, f.getvalue().split('\n')))
             for k, line in enumerate(lines):
                 print("%s %s" % (
-                    ' ' if i == len(dirs)-1 and j == len(dir)-1 else
+                    ' ' if j == len(dir)-1 else
                     'v' if k == len(lines)-1 else
-                    '.' if j == len(dir)-1 else
                     '|',
                     line))
 
-    if cycle:
-        print("*** cycle detected! -> {%#x, %#x} ***" % (cycle[0], cycle[1]))
+    errcode = 0
+    for mdir in corrupted:
+        errcode = errcode or 1
+        print("*** corrupted mdir {%#x, %#x}! ***" % (
+            mdir.blocks[0], mdir.blocks[1]))
 
     if cycle:
-        return 2
-    elif not all(mdir for dir in dirs for mdir in dir):
-        return 1
-    else:
-        return 0;
+        errcode = errcode or 2
+        print("*** cycle detected {%#x, %#x}! ***" % (
+            cycle[0], cycle[1]))
+
+    return errcode
 
 if __name__ == "__main__":
     import argparse
@@ -246,12 +170,10 @@ if __name__ == "__main__":
         help="Size of a block in bytes.")
     parser.add_argument('block1', nargs='?', default=0,
         type=lambda x: int(x, 0),
-        help="Optional first block address for finding the root.")
+        help="Optional first block address for finding the superblock.")
     parser.add_argument('block2', nargs='?', default=1,
         type=lambda x: int(x, 0),
-        help="Optional second block address for finding the root.")
-    parser.add_argument('-t', '--tags', action='store_true',
-        help="Show metadata tags instead of reconstructing entries.")
+        help="Optional second block address for finding the superblock.")
     parser.add_argument('-l', '--log', action='store_true',
         help="Show tags in log.")
     parser.add_argument('-a', '--all', action='store_true',

scripts/test.py

@@ -231,7 +231,7 @@ class TestCase:
                 ncmd.extend(['-ex', 'r'])
                 if failure.assert_:
                     ncmd.extend(['-ex', 'up 2'])
-            elif gdb == 'start':
+            elif gdb == 'main':
                 ncmd.extend([
                     '-ex', 'b %s:%d' % (self.suite.path, self.code_lineno),
                     '-ex', 'r'])
@@ -760,7 +760,7 @@ if __name__ == "__main__":
         help="Store disk image in a file.")
     parser.add_argument('-b', '--build', action='store_true',
         help="Only build the tests, do not execute.")
-    parser.add_argument('-g', '--gdb', choices=['init', 'start', 'assert'],
+    parser.add_argument('-g', '--gdb', choices=['init', 'main', 'assert'],
         nargs='?', const='assert',
         help="Drop into gdb on test failure.")
     parser.add_argument('--no-internal', action='store_true',