Added trace statements through LFS_YES_TRACE

To use, compile and run with LFS_YES_TRACE defined:
make CFLAGS+=-DLFS_YES_TRACE=1 test_format

The name LFS_YES_TRACE was chosen to match the LFS_NO_DEBUG and
LFS_NO_WARN defines for the similar levels of output. The YES is
necessary to avoid a conflict with the actual LFS_TRACE macro that
gets emitting. LFS_TRACE can also be defined directly to provide
a custom trace formatter.

Hopefully having trace statements at the littlefs C API helps
debugging and reproducing issues.

4 files changed, 350 insertions, 40 deletions

diff --git a/Makefile b/Makefile
index 185d8e5..364f299 100644
--- a/Makefile
+++ b/Makefile
@@ -24,6 +24,9 @@ endif
 ifdef WORD
 override CFLAGS += -m$(WORD)
 endif
+ifdef TRACE
+override CFLAGS += -DLFS_YES_TRACE
+endif
 override CFLAGS += -I.
 override CFLAGS += -std=c99 -Wall -pedantic
 override CFLAGS += -Wextra -Wshadow -Wjump-misses-init
diff --git a/emubd/lfs_emubd.c b/emubd/lfs_emubd.c
index 3f31bfa..374c51c 100644
--- a/emubd/lfs_emubd.c
+++ b/emubd/lfs_emubd.c
@@ -55,6 +55,15 @@ static inline void lfs_emubd_fromle32(lfs_emubd_t *emu) {
 
 // Block device emulated on existing filesystem
 int lfs_emubd_create(const struct lfs_config *cfg, const char *path) {
+    LFS_TRACE("lfs_emubd_create(%p {.context=%p, "
+                ".read=%p, .prog=%p, .erase=%p, .sync=%p, "
+                ".read_size=%"PRIu32", .prog_size=%"PRIu32", "
+                ".block_size=%"PRIu32", .block_count=%"PRIu32"}, \"%s\")",
+            (void*)cfg, cfg->context,
+            (void*)(uintptr_t)cfg->read, (void*)(uintptr_t)cfg->prog,
+            (void*)(uintptr_t)cfg->erase, (void*)(uintptr_t)cfg->sync,
+            cfg->read_size, cfg->prog_size, cfg->block_size, cfg->block_count,
+            path);
     lfs_emubd_t *emu = cfg->context;
     emu->cfg.read_size   = cfg->read_size;
     emu->cfg.prog_size   = cfg->prog_size;
@@ -65,7 +74,9 @@ int lfs_emubd_create(const struct lfs_config *cfg, const char *path) {
     size_t pathlen = strlen(path);
     emu->path = malloc(pathlen + 1 + LFS_NAME_MAX + 1);
     if (!emu->path) {
-        return -ENOMEM;
+        int err = -ENOMEM;
+        LFS_TRACE("lfs_emubd_create -> %"PRId32, err);
+        return err;
     }
 
     strcpy(emu->path, path);
@@ -76,7 +87,9 @@ int lfs_emubd_create(const struct lfs_config *cfg, const char *path) {
     // Create directory if it doesn't exist
     int err = mkdir(path, 0777);
     if (err && errno != EEXIST) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_create -> %"PRId32, err);
+        return err;
     }
 
     // Load stats to continue incrementing
@@ -88,12 +101,16 @@ int lfs_emubd_create(const struct lfs_config *cfg, const char *path) {
         size_t res = fread(&emu->stats, sizeof(emu->stats), 1, f);
         lfs_emubd_fromle32(emu);
         if (res < 1) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_create -> %"PRId32, err);
+            return err;
         }
 
         err = fclose(f);
         if (err) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_create -> %"PRId32, err);
+            return err;
         }
     }
 
@@ -106,27 +123,36 @@ int lfs_emubd_create(const struct lfs_config *cfg, const char *path) {
         size_t res = fread(&emu->history, sizeof(emu->history), 1, f);
         lfs_emubd_fromle32(emu);
         if (res < 1) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_create -> %"PRId32, err);
+            return err;
         }
 
         err = fclose(f);
         if (err) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_create -> %"PRId32, err);
+            return err;
         }
     }
 
+    LFS_TRACE("lfs_emubd_create -> %"PRId32, 0);
     return 0;
 }
 
 void lfs_emubd_destroy(const struct lfs_config *cfg) {
+    LFS_TRACE("lfs_emubd_destroy(%p)", (void*)cfg);
     lfs_emubd_sync(cfg);
 
     lfs_emubd_t *emu = cfg->context;
     free(emu->path);
+    LFS_TRACE("lfs_emubd_destroy -> %s", "void");
 }
 
 int lfs_emubd_read(const struct lfs_config *cfg, lfs_block_t block,
         lfs_off_t off, void *buffer, lfs_size_t size) {
+    LFS_TRACE("lfs_emubd_read(%p, %"PRIu32", %"PRIu32", %p, %"PRIu32")",
+            (void*)cfg, block, off, buffer, size);
     lfs_emubd_t *emu = cfg->context;
     uint8_t *data = buffer;
 
@@ -143,32 +169,43 @@ int lfs_emubd_read(const struct lfs_config *cfg, lfs_block_t block,
 
     FILE *f = fopen(emu->path, "rb");
     if (!f && errno != ENOENT) {
-        return -errno;
+        int err = -errno;
+        LFS_TRACE("lfs_emubd_read -> %d", err);
+        return err;
     }
 
     if (f) {
         int err = fseek(f, off, SEEK_SET);
         if (err) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_read -> %d", err);
+            return err;
         }
 
         size_t res = fread(data, 1, size, f);
         if (res < size && !feof(f)) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_read -> %d", err);
+            return err;
         }
 
         err = fclose(f);
         if (err) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_read -> %d", err);
+            return err;
         }
     }
 
     emu->stats.read_count += 1;
+    LFS_TRACE("lfs_emubd_read -> %d", 0);
     return 0;
 }
 
 int lfs_emubd_prog(const struct lfs_config *cfg, lfs_block_t block,
         lfs_off_t off, const void *buffer, lfs_size_t size) {
+    LFS_TRACE("lfs_emubd_prog(%p, %"PRIu32", %"PRIu32", %p, %"PRIu32")",
+            (void*)cfg, block, off, buffer, size);
     lfs_emubd_t *emu = cfg->context;
     const uint8_t *data = buffer;
 
@@ -182,7 +219,9 @@ int lfs_emubd_prog(const struct lfs_config *cfg, lfs_block_t block,
 
     FILE *f = fopen(emu->path, "r+b");
     if (!f) {
-        return (errno == EACCES) ? 0 : -errno;
+        int err = (errno == EACCES) ? 0 : -errno;
+        LFS_TRACE("lfs_emubd_prog -> %d", err);
+        return err;
     }
 
     // Check that file was erased
@@ -190,28 +229,38 @@ int lfs_emubd_prog(const struct lfs_config *cfg, lfs_block_t block,
 
     int err = fseek(f, off, SEEK_SET);
     if (err) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_prog -> %d", err);
+        return err;
     }
 
     size_t res = fwrite(data, 1, size, f);
     if (res < size) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_prog -> %d", err);
+        return err;
     }
 
     err = fseek(f, off, SEEK_SET);
     if (err) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_prog -> %d", err);
+        return err;
     }
 
     uint8_t dat;
     res = fread(&dat, 1, 1, f);
     if (res < 1) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_prog -> %d", err);
+        return err;
     }
 
     err = fclose(f);
     if (err) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_prog -> %d", err);
+        return err;
     }
 
     // update history and stats
@@ -222,10 +271,12 @@ int lfs_emubd_prog(const struct lfs_config *cfg, lfs_block_t block,
     }
 
     emu->stats.prog_count += 1;
+    LFS_TRACE("lfs_emubd_prog -> %d", 0);
     return 0;
 }
 
 int lfs_emubd_erase(const struct lfs_config *cfg, lfs_block_t block) {
+    LFS_TRACE("lfs_emubd_erase(%p, %"PRIu32")", (void*)cfg, block);
     lfs_emubd_t *emu = cfg->context;
 
     // Check if erase is valid
@@ -236,89 +287,118 @@ int lfs_emubd_erase(const struct lfs_config *cfg, lfs_block_t block) {
     struct stat st;
     int err = stat(emu->path, &st);
     if (err && errno != ENOENT) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_erase -> %d", err);
+        return err;
     }
 
     if (!err && S_ISREG(st.st_mode) && (S_IWUSR & st.st_mode)) {
         err = unlink(emu->path);
         if (err) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_erase -> %d", err);
+            return err;
         }
     }
 
     if (err || (S_ISREG(st.st_mode) && (S_IWUSR & st.st_mode))) {
         FILE *f = fopen(emu->path, "w");
         if (!f) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_erase -> %d", err);
+            return err;
         }
 
         err = fclose(f);
         if (err) {
-            return -errno;
+            err = -errno;
+            LFS_TRACE("lfs_emubd_erase -> %d", err);
+            return err;
         }
     }
 
     emu->stats.erase_count += 1;
+    LFS_TRACE("lfs_emubd_erase -> %d", 0);
     return 0;
 }
 
 int lfs_emubd_sync(const struct lfs_config *cfg) {
+    LFS_TRACE("lfs_emubd_sync(%p)", (void*)cfg);
     lfs_emubd_t *emu = cfg->context;
 
     // Just write out info/stats for later lookup
     snprintf(emu->child, LFS_NAME_MAX, ".config");
     FILE *f = fopen(emu->path, "w");
     if (!f) {
-        return -errno;
+        int err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     lfs_emubd_tole32(emu);
     size_t res = fwrite(&emu->cfg, sizeof(emu->cfg), 1, f);
     lfs_emubd_fromle32(emu);
     if (res < 1) {
-        return -errno;
+        int err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     int err = fclose(f);
     if (err) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     snprintf(emu->child, LFS_NAME_MAX, ".stats");
     f = fopen(emu->path, "w");
     if (!f) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     lfs_emubd_tole32(emu);
     res = fwrite(&emu->stats, sizeof(emu->stats), 1, f);
     lfs_emubd_fromle32(emu);
     if (res < 1) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     err = fclose(f);
     if (err) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     snprintf(emu->child, LFS_NAME_MAX, ".history");
     f = fopen(emu->path, "w");
     if (!f) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     lfs_emubd_tole32(emu);
     res = fwrite(&emu->history, sizeof(emu->history), 1, f);
     lfs_emubd_fromle32(emu);
     if (res < 1) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
     err = fclose(f);
     if (err) {
-        return -errno;
+        err = -errno;
+        LFS_TRACE("lfs_emubd_sync -> %d", err);
+        return err;
     }
 
+    LFS_TRACE("lfs_emubd_sync -> %d", 0);
     return 0;
 }
diff --git a/lfs.c b/lfs.c
index c554135..4edf6b7 100644
--- a/lfs.c
+++ b/lfs.c
@@ -1821,9 +1821,11 @@ compact:
 
 /// Top level directory operations ///
 int lfs_mkdir(lfs_t *lfs, const char *path) {
+    LFS_TRACE("lfs_mkdir(%p, \"%s\")", (void*)lfs, path);
     // deorphan if we haven't yet, needed at most once after poweron
     int err = lfs_fs_forceconsistency(lfs);
     if (err) {
+        LFS_TRACE("lfs_mkdir -> %d", err);
         return err;
     }
 
@@ -1831,12 +1833,14 @@ int lfs_mkdir(lfs_t *lfs, const char *path) {
     uint16_t id;
     err = lfs_dir_find(lfs, &cwd, &path, &id);
     if (!(err == LFS_ERR_NOENT && id != 0x3ff)) {
+        LFS_TRACE("lfs_mkdir -> %d", (err < 0) ? err : LFS_ERR_EXIST);
         return (err < 0) ? err : LFS_ERR_EXIST;
     }
 
     // check that name fits
     lfs_size_t nlen = strlen(path);
     if (nlen > lfs->name_max) {
+        LFS_TRACE("lfs_mkdir -> %d", LFS_ERR_NAMETOOLONG);
         return LFS_ERR_NAMETOOLONG;
     }
 
@@ -1845,6 +1849,7 @@ int lfs_mkdir(lfs_t *lfs, const char *path) {
     lfs_mdir_t dir;
     err = lfs_dir_alloc(lfs, &dir);
     if (err) {
+        LFS_TRACE("lfs_mkdir -> %d", err);
         return err;
     }
 
@@ -1853,6 +1858,7 @@ int lfs_mkdir(lfs_t *lfs, const char *path) {
     while (pred.split) {
         err = lfs_dir_fetch(lfs, &pred, pred.tail);
         if (err) {
+            LFS_TRACE("lfs_mkdir -> %d", err);
             return err;
         }
     }
@@ -1863,6 +1869,7 @@ int lfs_mkdir(lfs_t *lfs, const char *path) {
             {LFS_MKTAG(LFS_TYPE_SOFTTAIL, 0x3ff, 8), pred.tail}));
     lfs_pair_fromle32(pred.tail);
     if (err) {
+        LFS_TRACE("lfs_mkdir -> %d", err);
         return err;
     }
 
@@ -1875,6 +1882,7 @@ int lfs_mkdir(lfs_t *lfs, const char *path) {
                 {LFS_MKTAG(LFS_TYPE_SOFTTAIL, 0x3ff, 8), dir.pair}));
         lfs_pair_fromle32(dir.pair);
         if (err) {
+            LFS_TRACE("lfs_mkdir -> %d", err);
             return err;
         }
         lfs_fs_preporphans(lfs, -1);
@@ -1891,19 +1899,24 @@ int lfs_mkdir(lfs_t *lfs, const char *path) {
                 : LFS_MKTAG(LFS_FROM_NOOP, 0, 0), dir.pair}));
     lfs_pair_fromle32(dir.pair);
     if (err) {
+        LFS_TRACE("lfs_mkdir -> %d", err);
         return err;
     }
 
+    LFS_TRACE("lfs_mkdir -> %d", 0);
     return 0;
 }
 
 int lfs_dir_open(lfs_t *lfs, lfs_dir_t *dir, const char *path) {
+    LFS_TRACE("lfs_dir_open(%p, %p, \"%s\")", (void*)lfs, (void*)dir, path);
     lfs_stag_t tag = lfs_dir_find(lfs, &dir->m, &path, NULL);
     if (tag < 0) {
+        LFS_TRACE("lfs_dir_open -> %d", tag);
         return tag;
     }
 
     if (lfs_tag_type3(tag) != LFS_TYPE_DIR) {
+        LFS_TRACE("lfs_dir_open -> %d", LFS_ERR_NOTDIR);
         return LFS_ERR_NOTDIR;
     }
 
@@ -1917,6 +1930,7 @@ int lfs_dir_open(lfs_t *lfs, lfs_dir_t *dir, const char *path) {
         lfs_stag_t res = lfs_dir_get(lfs, &dir->m, LFS_MKTAG(0x700, 0x3ff, 0),
                 LFS_MKTAG(LFS_TYPE_STRUCT, lfs_tag_id(tag), 8), pair);
         if (res < 0) {
+            LFS_TRACE("lfs_dir_open -> %d", res);
             return res;
         }
         lfs_pair_fromle32(pair);
@@ -1925,6 +1939,7 @@ int lfs_dir_open(lfs_t *lfs, lfs_dir_t *dir, const char *path) {
     // fetch first pair
     int err = lfs_dir_fetch(lfs, &dir->m, pair);
     if (err) {
+        LFS_TRACE("lfs_dir_open -> %d", err);
         return err;
     }
 
@@ -1939,10 +1954,12 @@ int lfs_dir_open(lfs_t *lfs, lfs_dir_t *dir, const char *path) {
     dir->next = (lfs_dir_t*)lfs->mlist;
     lfs->mlist = (struct lfs_mlist*)dir;
 
+    LFS_TRACE("lfs_dir_open -> %d", 0);
     return 0;
 }
 
 int lfs_dir_close(lfs_t *lfs, lfs_dir_t *dir) {
+    LFS_TRACE("lfs_dir_close(%p, %p)", (void*)lfs, (void*)dir);
     // remove from list of mdirs
     for (struct lfs_mlist **p = &lfs->mlist; *p; p = &(*p)->next) {
         if (*p == (struct lfs_mlist*)dir) {
@@ -1951,10 +1968,13 @@ int lfs_dir_close(lfs_t *lfs, lfs_dir_t *dir) {
         }
     }
 
+    LFS_TRACE("lfs_dir_close -> %d", 0);
     return 0;
 }
 
 int lfs_dir_read(lfs_t *lfs, lfs_dir_t *dir, struct lfs_info *info) {
+    LFS_TRACE("lfs_dir_read(%p, %p, %p)",
+            (void*)lfs, (void*)dir, (void*)info);
     memset(info, 0, sizeof(*info));
 
     // special offset for '.' and '..'
@@ -1962,22 +1982,26 @@ int lfs_dir_read(lfs_t *lfs, lfs_dir_t *dir, struct lfs_info *info) {
         info->type = LFS_TYPE_DIR;
         strcpy(info->name, ".");
         dir->pos += 1;
-        return 1;
+        LFS_TRACE("lfs_dir_read -> %d", true);
+        return true;
     } else if (dir->pos == 1) {
         info->type = LFS_TYPE_DIR;
         strcpy(info->name, "..");
         dir->pos += 1;
-        return 1;
+        LFS_TRACE("lfs_dir_read -> %d", true);
+        return true;
     }
 
     while (true) {
         if (dir->id == dir->m.count) {
             if (!dir->m.split) {
+                LFS_TRACE("lfs_dir_read -> %d", false);
                 return false;
             }
 
             int err = lfs_dir_fetch(lfs, &dir->m, dir->m.tail);
             if (err) {
+                LFS_TRACE("lfs_dir_read -> %d", err);
                 return err;
             }
 
@@ -1986,6 +2010,7 @@ int lfs_dir_read(lfs_t *lfs, lfs_dir_t *dir, struct lfs_info *info) {
 
         int err = lfs_dir_getinfo(lfs, &dir->m, dir->id, info);
         if (err && err != LFS_ERR_NOENT) {
+            LFS_TRACE("lfs_dir_read -> %d", err);
             return err;
         }
 
@@ -1996,13 +2021,17 @@ int lfs_dir_read(lfs_t *lfs, lfs_dir_t *dir, struct lfs_info *info) {
     }
 
     dir->pos += 1;
+    LFS_TRACE("lfs_dir_read -> %d", true);
     return true;
 }
 
 int lfs_dir_seek(lfs_t *lfs, lfs_dir_t *dir, lfs_off_t off) {
+    LFS_TRACE("lfs_dir_seek(%p, %p, %"PRIu32")",
+            (void*)lfs, (void*)dir, off);
     // simply walk from head dir
     int err = lfs_dir_rewind(lfs, dir);
     if (err) {
+        LFS_TRACE("lfs_dir_seek -> %d", err);
         return err;
     }
 
@@ -2017,28 +2046,35 @@ int lfs_dir_seek(lfs_t *lfs, lfs_dir_t *dir, lfs_off_t off) {
 
         if (dir->id == dir->m.count) {
             if (!dir->m.split) {
+                LFS_TRACE("lfs_dir_seek -> %d", LFS_ERR_INVAL);
                 return LFS_ERR_INVAL;
             }
 
             err = lfs_dir_fetch(lfs, &dir->m, dir->m.tail);
             if (err) {
+                LFS_TRACE("lfs_dir_seek -> %d", err);
                 return err;
             }
         }
     }
 
+    LFS_TRACE("lfs_dir_seek -> %d", 0);
     return 0;
 }
 
 lfs_soff_t lfs_dir_tell(lfs_t *lfs, lfs_dir_t *dir) {
+    LFS_TRACE("lfs_dir_tell(%p, %p)", (void*)lfs, (void*)dir);
     (void)lfs;
+    LFS_TRACE("lfs_dir_tell -> %"PRId32, dir->pos);
     return dir->pos;
 }
 
 int lfs_dir_rewind(lfs_t *lfs, lfs_dir_t *dir) {
+    LFS_TRACE("lfs_dir_rewind(%p, %p)", (void*)lfs, (void*)dir);
     // reload the head dir
     int err = lfs_dir_fetch(lfs, &dir->m, dir->head);
     if (err) {
+        LFS_TRACE("lfs_dir_rewind -> %d", err);
         return err;
     }
 
@@ -2046,6 +2082,7 @@ int lfs_dir_rewind(lfs_t *lfs, lfs_dir_t *dir) {
     dir->m.pair[1] = dir->head[1];
     dir->id = 0;
     dir->pos = 0;
+    LFS_TRACE("lfs_dir_rewind -> %d", 0);
     return 0;
 }
 
@@ -2248,10 +2285,15 @@ static int lfs_ctz_traverse(lfs_t *lfs,
 int lfs_file_opencfg(lfs_t *lfs, lfs_file_t *file,
         const char *path, int flags,
         const struct lfs_file_config *cfg) {
+    LFS_TRACE("lfs_file_opencfg(%p, %p, \"%s\", 0x%x, %p {"
+                 ".buffer=%p, .attrs=%p, .attr_count=%"PRIu32"})",
+            (void*)lfs, (void*)file, path, flags,
+            (void*)cfg, cfg->buffer, (void*)cfg->attrs, cfg->attr_count);
     // deorphan if we haven't yet, needed at most once after poweron
     if ((flags & 3) != LFS_O_RDONLY) {
         int err = lfs_fs_forceconsistency(lfs);
         if (err) {
+            LFS_TRACE("lfs_file_opencfg -> %d", err);
             return err;
         }
     }
@@ -2381,22 +2423,29 @@ int lfs_file_opencfg(lfs_t *lfs, lfs_file_t *file,
         }
     }
 
+    LFS_TRACE("lfs_file_opencfg -> %d", 0);
     return 0;
 
 cleanup:
     // clean up lingering resources
     file->flags |= LFS_F_ERRED;
     lfs_file_close(lfs, file);
+    LFS_TRACE("lfs_file_opencfg -> %d", err);
     return err;
 }
 
 int lfs_file_open(lfs_t *lfs, lfs_file_t *file,
         const char *path, int flags) {
+    LFS_TRACE("lfs_file_open(%p, %p, \"%s\", 0x%x)",
+            (void*)lfs, (void*)file, path, flags);
     static const struct lfs_file_config defaults = {0};
-    return lfs_file_opencfg(lfs, file, path, flags, &defaults);
+    int err = lfs_file_opencfg(lfs, file, path, flags, &defaults);
+    LFS_TRACE("lfs_file_open -> %d", err);
+    return err;
 }
 
 int lfs_file_close(lfs_t *lfs, lfs_file_t *file) {
+    LFS_TRACE("lfs_file_close(%p, %p)", (void*)lfs, (void*)file);
     int err = lfs_file_sync(lfs, file);
 
     // remove from list of mdirs
@@ -2412,6 +2461,7 @@ int lfs_file_close(lfs_t *lfs, lfs_file_t *file) {
         lfs_free(file->cache.buffer);
     }
 
+    LFS_TRACE("lfs_file_close -> %d", err);
     return err;
 }
 
@@ -2564,10 +2614,12 @@ relocate:
 }
 
 int lfs_file_sync(lfs_t *lfs, lfs_file_t *file) {
+    LFS_TRACE("lfs_file_sync(%p, %p)", (void*)lfs, (void*)file);
     while (true) {
         int err = lfs_file_flush(lfs, file);
         if (err) {
             file->flags |= LFS_F_ERRED;
+            LFS_TRACE("lfs_file_sync -> %d", err);
             return err;
         }
 
@@ -2604,12 +2656,14 @@ int lfs_file_sync(lfs_t *lfs, lfs_file_t *file) {
                     goto relocate;
                 }
                 file->flags |= LFS_F_ERRED;
+                LFS_TRACE("lfs_file_sync -> %d", err);
                 return err;
             }
 
             file->flags &= ~LFS_F_DIRTY;
         }
 
+        LFS_TRACE("lfs_file_sync -> %d", 0);
         return 0;
 
 relocate:
@@ -2618,6 +2672,7 @@ relocate:
         err = lfs_file_relocate(lfs, file);
         if (err) {
             file->flags |= LFS_F_ERRED;
+            LFS_TRACE("lfs_file_sync -> %d", err);
             return err;
         }
     }
@@ -2625,10 +2680,13 @@ relocate:
 
 lfs_ssize_t lfs_file_read(lfs_t *lfs, lfs_file_t *file,
         void *buffer, lfs_size_t size) {
+    LFS_TRACE("lfs_file_read(%p, %p, %p, %"PRIu32")",
+            (void*)lfs, (void*)file, buffer, size);
     uint8_t *data = buffer;
     lfs_size_t nsize = size;
 
     if ((file->flags & 3) == LFS_O_WRONLY) {
+        LFS_TRACE("lfs_file_read -> %"PRId32, LFS_ERR_BADF);
         return LFS_ERR_BADF;
     }
 
@@ -2636,12 +2694,14 @@ lfs_ssize_t lfs_file_read(lfs_t *lfs, lfs_file_t *file,
         // flush out any writes
         int err = lfs_file_flush(lfs, file);
         if (err) {
+            LFS_TRACE("lfs_file_read -> %"PRId32, err);
             return err;
         }
     }
 
     if (file->pos >= file->ctz.size) {
         // eof if past end
+        LFS_TRACE("lfs_file_read -> %"PRId32, 0);
         return 0;
     }
 
@@ -2657,6 +2717,7 @@ lfs_ssize_t lfs_file_read(lfs_t *lfs, lfs_file_t *file,
                         file->ctz.head, file->ctz.size,
                         file->pos, &file->block, &file->off);
                 if (err) {
+                    LFS_TRACE("lfs_file_read -> %"PRId32, err);
                     return err;
                 }
             } else {
@@ -2676,6 +2737,7 @@ lfs_ssize_t lfs_file_read(lfs_t *lfs, lfs_file_t *file,
                     LFS_MKTAG(LFS_TYPE_INLINESTRUCT, file->id, 0),
                     file->off, data, diff);
             if (err) {
+                LFS_TRACE("lfs_file_read -> %"PRId32, err);
                 return err;
             }
         } else {
@@ -2683,6 +2745,7 @@ lfs_ssize_t lfs_file_read(lfs_t *lfs, lfs_file_t *file,
                     NULL, &file->cache, lfs->cfg->block_size,
                     file->block, file->off, data, diff);
             if (err) {
+                LFS_TRACE("lfs_file_read -> %"PRId32, err);
                 return err;
             }
         }
@@ -2693,15 +2756,19 @@ lfs_ssize_t lfs_file_read(lfs_t *lfs, lfs_file_t *file,
         nsize -= diff;
     }
 
+    LFS_TRACE("lfs_file_read -> %"PRId32, size);
     return size;
 }
 
 lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
         const void *buffer, lfs_size_t size) {
+    LFS_TRACE("lfs_file_write(%p, %p, %p, %"PRIu32")",
+            (void*)lfs, (void*)file, buffer, size);
     const uint8_t *data = buffer;
     lfs_size_t nsize = size;
 
     if ((file->flags & 3) == LFS_O_RDONLY) {
+        LFS_TRACE("lfs_file_write -> %"PRId32, LFS_ERR_BADF);
         return LFS_ERR_BADF;
     }
 
@@ -2709,6 +2776,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
         // drop any reads
         int err = lfs_file_flush(lfs, file);
         if (err) {
+            LFS_TRACE("lfs_file_write -> %"PRId32, err);
             return err;
         }
     }
@@ -2719,6 +2787,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
 
     if (file->pos + size > lfs->file_max) {
         // Larger than file limit?
+        LFS_TRACE("lfs_file_write -> %"PRId32, LFS_ERR_FBIG);
         return LFS_ERR_FBIG;
     }
 
@@ -2730,6 +2799,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
         while (file->pos < pos) {
             lfs_ssize_t res = lfs_file_write(lfs, file, &(uint8_t){0}, 1);
             if (res < 0) {
+                LFS_TRACE("lfs_file_write -> %"PRId32, res);
                 return res;
             }
         }
@@ -2745,6 +2815,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
         int err = lfs_file_relocate(lfs, file);
         if (err) {
             file->flags |= LFS_F_ERRED;
+            LFS_TRACE("lfs_file_write -> %"PRId32, err);
             return err;
         }
     }
@@ -2761,6 +2832,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
                             file->pos-1, &file->block, &file->off);
                     if (err) {
                         file->flags |= LFS_F_ERRED;
+                        LFS_TRACE("lfs_file_write -> %"PRId32, err);
                         return err;
                     }
 
@@ -2775,6 +2847,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
                         &file->block, &file->off);
                 if (err) {
                     file->flags |= LFS_F_ERRED;
+                    LFS_TRACE("lfs_file_write -> %"PRId32, err);
                     return err;
                 }
             } else {
@@ -2795,6 +2868,7 @@ lfs_ssize_t lfs_file_write(lfs_t *lfs, lfs_file_t *file,
                     goto relocate;
                 }
                 file->flags |= LFS_F_ERRED;
+                LFS_TRACE("lfs_file_write -> %"PRId32, err);
                 return err;
             }
 
@@ -2803,6 +2877,7 @@ relocate:
             err = lfs_file_relocate(lfs, file);
             if (err) {
                 file->flags |= LFS_F_ERRED;
+                LFS_TRACE("lfs_file_write -> %"PRId32, err);
                 return err;
             }
         }
@@ -2816,14 +2891,18 @@ relocate:
     }
 
     file->flags &= ~LFS_F_ERRED;
+    LFS_TRACE("lfs_file_write -> %"PRId32, size);
     return size;
 }
 
 lfs_soff_t lfs_file_seek(lfs_t *lfs, lfs_file_t *file,
         lfs_soff_t off, int whence) {
+    LFS_TRACE("lfs_file_seek(%p, %p, %"PRId32", %d)",
+            (void*)lfs, (void*)file, off, whence);
     // write out everything beforehand, may be noop if rdonly
     int err = lfs_file_flush(lfs, file);
     if (err) {
+        LFS_TRACE("lfs_file_seek -> %"PRId32, err);
         return err;
     }
 
@@ -2839,20 +2918,26 @@ lfs_soff_t lfs_file_seek(lfs_t *lfs, lfs_file_t *file,
 
     if (npos > lfs->file_max) {
         // file position out of range
+        LFS_TRACE("lfs_file_seek -> %"PRId32, LFS_ERR_INVAL);
         return LFS_ERR_INVAL;
     }
 
     // update pos
     file->pos = npos;
+    LFS_TRACE("lfs_file_seek -> %"PRId32, npos);
     return npos;
 }
 
 int lfs_file_truncate(lfs_t *lfs, lfs_file_t *file, lfs_off_t size) {
+    LFS_TRACE("lfs_file_truncate(%p, %p, %"PRIu32")",
+            (void*)lfs, (void*)file, size);
     if ((file->flags & 3) == LFS_O_RDONLY) {
+        LFS_TRACE("lfs_file_truncate -> %d", LFS_ERR_BADF);
         return LFS_ERR_BADF;
     }
 
     if (size > LFS_FILE_MAX) {
+        LFS_TRACE("lfs_file_truncate -> %d", LFS_ERR_INVAL);
         return LFS_ERR_INVAL;
     }
 
@@ -2861,6 +2946,7 @@ int lfs_file_truncate(lfs_t *lfs, lfs_file_t *file, lfs_off_t size) {
         // need to flush since directly changing metadata
         int err = lfs_file_flush(lfs, file);
         if (err) {
+            LFS_TRACE("lfs_file_truncate -> %d", err);
             return err;
         }
 
@@ -2869,6 +2955,7 @@ int lfs_file_truncate(lfs_t *lfs, lfs_file_t *file, lfs_off_t size) {
                 file->ctz.head, file->ctz.size,
                 size, &file->block, &file->off);
         if (err) {
+            LFS_TRACE("lfs_file_truncate -> %d", err);
             return err;
         }
 
@@ -2882,6 +2969,7 @@ int lfs_file_truncate(lfs_t *lfs, lfs_file_t *file, lfs_off_t size) {
         if (file->pos != oldsize) {
             int err = lfs_file_seek(lfs, file, 0, LFS_SEEK_END);
             if (err < 0) {
+                LFS_TRACE("lfs_file_truncate -> %d", err);
                 return err;
             }
         }
@@ -2890,6 +2978,7 @@ int lfs_file_truncate(lfs_t *lfs, lfs_file_t *file, lfs_off_t size) {
         while (file->pos < size) {
             lfs_ssize_t res = lfs_file_write(lfs, file, &(uint8_t){0}, 1);
             if (res < 0) {
+                LFS_TRACE("lfs_file_truncate -> %d", res);
                 return res;
             }
         }
@@ -2897,32 +2986,43 @@ int lfs_file_truncate(lfs_t *lfs, lfs_file_t *file, lfs_off_t size) {
         // restore pos
         int err = lfs_file_seek(lfs, file, pos, LFS_SEEK_SET);
         if (err < 0) {
+            LFS_TRACE("lfs_file_truncate -> %d", err);
             return err;
         }
     }
 
+    LFS_TRACE("lfs_file_truncate -> %d", 0);
     return 0;
 }
 
 lfs_soff_t lfs_file_tell(lfs_t *lfs, lfs_file_t *file) {
+    LFS_TRACE("lfs_file_tell(%p, %p)", (void*)lfs, (void*)file);
     (void)lfs;
+    LFS_TRACE("lfs_file_tell -> %"PRId32, file->pos);
     return file->pos;
 }
 
 int lfs_file_rewind(lfs_t *lfs, lfs_file_t *file) {
+    LFS_TRACE("lfs_file_rewind(%p, %p)", (void*)lfs, (void*)file);
     lfs_soff_t res = lfs_file_seek(lfs, file, 0, LFS_SEEK_SET);
     if (res < 0) {
+        LFS_TRACE("lfs_file_rewind -> %d", res);
         return res;
     }
 
+    LFS_TRACE("lfs_file_rewind -> %d", 0);
     return 0;
 }
 
 lfs_soff_t lfs_file_size(lfs_t *lfs, lfs_file_t *file) {
+    LFS_TRACE("lfs_file_size(%p, %p)", (void*)lfs, (void*)file);
     (void)lfs;
     if (file->flags & LFS_F_WRITING) {
+        LFS_TRACE("lfs_file_size -> %"PRId32,
+                lfs_max(file->pos, file->ctz.size));
         return lfs_max(file->pos, file->ctz.size);
     } else {
+        LFS_TRACE("lfs_file_size -> %"PRId32, file->ctz.size);
         return file->ctz.size;
     }
 }
@@ -2930,25 +3030,32 @@ lfs_soff_t lfs_file_size(lfs_t *lfs, lfs_file_t *file) {
 
 /// General fs operations ///
 int lfs_stat(lfs_t *lfs, const char *path, struct lfs_info *info) {
+    LFS_TRACE("lfs_stat(%p, \"%s\", %p)", (void*)lfs, path, (void*)info);
     lfs_mdir_t cwd;
     lfs_stag_t tag = lfs_dir_find(lfs, &cwd, &path, NULL);
     if (tag < 0) {
+        LFS_TRACE("lfs_stat -> %d", tag);
         return tag;
     }
 
-    return lfs_dir_getinfo(lfs, &cwd, lfs_tag_id(tag), info);
+    int err = lfs_dir_getinfo(lfs, &cwd, lfs_tag_id(tag), info);
+    LFS_TRACE("lfs_stat -> %d", err);
+    return err;
 }
 
 int lfs_remove(lfs_t *lfs, const char *path) {
+    LFS_TRACE("lfs_remove(%p, \"%s\")", (void*)lfs, path);
     // deorphan if we haven't yet, needed at most once after poweron
     int err = lfs_fs_forceconsistency(lfs);
     if (err) {
+        LFS_TRACE("lfs_remove -> %d", err);
         return err;
     }
 
     lfs_mdir_t cwd;
     lfs_stag_t tag = lfs_dir_find(lfs, &cwd, &path, NULL);
     if (tag < 0 || lfs_tag_id(tag) == 0x3ff) {
+        LFS_TRACE("lfs_remove -> %d", (tag < 0) ? tag : LFS_ERR_INVAL);
         return (tag < 0) ? tag : LFS_ERR_INVAL;
     }
 
@@ -2959,16 +3066,19 @@ int lfs_remove(lfs_t *lfs, const char *path) {
         lfs_stag_t res = lfs_dir_get(lfs, &cwd, LFS_MKTAG(0x700, 0x3ff, 0),
                 LFS_MKTAG(LFS_TYPE_STRUCT, lfs_tag_id(tag), 8), pair);
         if (res < 0) {
+            LFS_TRACE("lfs_remove -> %d", res);
             return res;
         }
         lfs_pair_fromle32(pair);
 
         err = lfs_dir_fetch(lfs, &dir, pair);
         if (err) {
+            LFS_TRACE("lfs_remove -> %d", err);
             return err;
         }
 
         if (dir.count > 0 || dir.split) {
+            LFS_TRACE("lfs_remove -> %d", LFS_ERR_NOTEMPTY);
             return LFS_ERR_NOTEMPTY;
         }
 
@@ -2980,6 +3090,7 @@ int lfs_remove(lfs_t *lfs, const char *path) {
     err = lfs_dir_commit(lfs, &cwd, LFS_MKATTRS(
             {LFS_MKTAG(LFS_TYPE_DELETE, lfs_tag_id(tag), 0), NULL}));
     if (err) {
+        LFS_TRACE("lfs_remove -> %d", err);
         return err;
     }
 
@@ -2989,22 +3100,28 @@ int lfs_remove(lfs_t *lfs, const char *path) {
 
         err = lfs_fs_pred(lfs, dir.pair, &cwd);
         if (err) {
+            LFS_TRACE("lfs_remove -> %d", err);
             return err;
         }
 
         err = lfs_dir_drop(lfs, &cwd, &dir);
         if (err) {
+            LFS_TRACE("lfs_remove -> %d", err);
             return err;
         }
     }
 
+    LFS_TRACE("lfs_remove -> %d", 0);
     return 0;
 }
 
 int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
+    LFS_TRACE("lfs_rename(%p, \"%s\", \"%s\")", (void*)lfs, oldpath, newpath);
+
     // deorphan if we haven't yet, needed at most once after poweron
     int err = lfs_fs_forceconsistency(lfs);
     if (err) {
+        LFS_TRACE("lfs_rename -> %d", err);
         return err;
     }
 
@@ -3012,6 +3129,7 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
     lfs_mdir_t oldcwd;
     lfs_stag_t oldtag = lfs_dir_find(lfs, &oldcwd, &oldpath, NULL);
     if (oldtag < 0 || lfs_tag_id(oldtag) == 0x3ff) {
+        LFS_TRACE("lfs_rename -> %d", (oldtag < 0) ? oldtag : LFS_ERR_INVAL);
         return (oldtag < 0) ? oldtag : LFS_ERR_INVAL;
     }
 
@@ -3021,6 +3139,7 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
     lfs_stag_t prevtag = lfs_dir_find(lfs, &newcwd, &newpath, &newid);
     if ((prevtag < 0 || lfs_tag_id(prevtag) == 0x3ff) &&
             !(prevtag == LFS_ERR_NOENT && newid != 0x3ff)) {
+        LFS_TRACE("lfs_rename -> %d", (prevtag < 0) ? prevtag : LFS_ERR_INVAL);
         return (prevtag < 0) ? prevtag : LFS_ERR_INVAL;
     }
 
@@ -3029,9 +3148,11 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
         // check that name fits
         lfs_size_t nlen = strlen(newpath);
         if (nlen > lfs->name_max) {
+            LFS_TRACE("lfs_rename -> %d", LFS_ERR_NAMETOOLONG);
             return LFS_ERR_NAMETOOLONG;
         }
     } else if (lfs_tag_type3(prevtag) != lfs_tag_type3(oldtag)) {
+        LFS_TRACE("lfs_rename -> %d", LFS_ERR_ISDIR);
         return LFS_ERR_ISDIR;
     } else if (lfs_tag_type3(prevtag) == LFS_TYPE_DIR) {
         // must be empty before removal
@@ -3039,6 +3160,7 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
         lfs_stag_t res = lfs_dir_get(lfs, &newcwd, LFS_MKTAG(0x700, 0x3ff, 0),
                 LFS_MKTAG(LFS_TYPE_STRUCT, newid, 8), prevpair);
         if (res < 0) {
+            LFS_TRACE("lfs_rename -> %d", res);
             return res;
         }
         lfs_pair_fromle32(prevpair);
@@ -3046,10 +3168,12 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
         // must be empty before removal
         err = lfs_dir_fetch(lfs, &prevdir, prevpair);
         if (err) {
+            LFS_TRACE("lfs_rename -> %d", err);
             return err;
         }
 
         if (prevdir.count > 0 || prevdir.split) {
+            LFS_TRACE("lfs_rename -> %d", LFS_ERR_NOTEMPTY);
             return LFS_ERR_NOTEMPTY;
         }
 
@@ -3079,6 +3203,7 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
                 newpath},
             {LFS_MKTAG(LFS_FROM_MOVE, newid, lfs_tag_id(oldtag)), &oldcwd}));
     if (err) {
+        LFS_TRACE("lfs_rename -> %d", err);
         return err;
     }
 
@@ -3087,6 +3212,7 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
     if (lfs_pair_cmp(oldcwd.pair, newcwd.pair) != 0) {
         err = lfs_dir_commit(lfs, &oldcwd, NULL, 0);
         if (err) {
+            LFS_TRACE("lfs_rename -> %d", err);
             return err;
         }
     }
@@ -3097,23 +3223,29 @@ int lfs_rename(lfs_t *lfs, const char *oldpath, const char *newpath) {
 
         err = lfs_fs_pred(lfs, prevdir.pair, &newcwd);
         if (err) {
+            LFS_TRACE("lfs_rename -> %d", err);
             return err;
         }
 
         err = lfs_dir_drop(lfs, &newcwd, &prevdir);
         if (err) {
+            LFS_TRACE("lfs_rename -> %d", err);
             return err;
         }
     }
 
+    LFS_TRACE("lfs_rename -> %d", 0);
     return 0;
 }
 
 lfs_ssize_t lfs_getattr(lfs_t *lfs, const char *path,
         uint8_t type, void *buffer, lfs_size_t size) {
+    LFS_TRACE("lfs_getattr(%p, \"%s\", %"PRIu8", %p, %"PRIu32")",
+            (void*)lfs, path, type, buffer, size);
     lfs_mdir_t cwd;
     lfs_stag_t tag = lfs_dir_find(lfs, &cwd, &path, NULL);
     if (tag < 0) {
+        LFS_TRACE("lfs_getattr -> %"PRId32, tag);
         return tag;
     }
 
@@ -3123,6 +3255,7 @@ lfs_ssize_t lfs_getattr(lfs_t *lfs, const char *path,
         id = 0;
         int err = lfs_dir_fetch(lfs, &cwd, lfs->root);
         if (err) {
+            LFS_TRACE("lfs_getattr -> %"PRId32, err);
             return err;
         }
     }
@@ -3133,12 +3266,17 @@ lfs_ssize_t lfs_getattr(lfs_t *lfs, const char *path,
             buffer);
     if (tag < 0) {
         if (tag == LFS_ERR_NOENT) {
+            LFS_TRACE("lfs_getattr -> %"PRId32, LFS_ERR_NOATTR);
             return LFS_ERR_NOATTR;
         }
+
+        LFS_TRACE("lfs_getattr -> %"PRId32, tag);
         return tag;
     }
 
-    return lfs_tag_size(tag);
+    size = lfs_tag_size(tag);
+    LFS_TRACE("lfs_getattr -> %"PRId32, size);
+    return size;
 }
 
 static int lfs_commitattr(lfs_t *lfs, const char *path,
@@ -3165,15 +3303,23 @@ static int lfs_commitattr(lfs_t *lfs, const char *path,
 
 int lfs_setattr(lfs_t *lfs, const char *path,
         uint8_t type, const void *buffer, lfs_size_t size) {
+    LFS_TRACE("lfs_setattr(%p, \"%s\", %"PRIu8", %p, %"PRIu32")",
+            (void*)lfs, path, type, buffer, size);
     if (size > lfs->attr_max) {
+        LFS_TRACE("lfs_setattr -> %d", LFS_ERR_NOSPC);
         return LFS_ERR_NOSPC;
     }
 
-    return lfs_commitattr(lfs, path, type, buffer, size);
+    int err = lfs_commitattr(lfs, path, type, buffer, size);
+    LFS_TRACE("lfs_setattr -> %d", err);
+    return err;
 }
 
 int lfs_removeattr(lfs_t *lfs, const char *path, uint8_t type) {
-    return lfs_commitattr(lfs, path, type, NULL, 0x3ff);
+    LFS_TRACE("lfs_removeattr(%p, \"%s\", %"PRIu8")", (void*)lfs, path, type);
+    int err = lfs_commitattr(lfs, path, type, NULL, 0x3ff);
+    LFS_TRACE("lfs_removeattr -> %d", err);
+    return err;
 }
 
 
@@ -3291,10 +3437,27 @@ static int lfs_deinit(lfs_t *lfs) {
 }
 
 int lfs_format(lfs_t *lfs, const struct lfs_config *cfg) {
+    LFS_TRACE("lfs_format(%p, %p {.context=%p, "
+                ".read=%p, .prog=%p, .erase=%p, .sync=%p, "
+                ".read_size=%"PRIu32", .prog_size=%"PRIu32", "
+                ".block_size=%"PRIu32", .block_count=%"PRIu32", "
+                ".block_cycles=%"PRIu32", .cache_size=%"PRIu32", "
+                ".lookahead_size=%"PRIu32", .read_buffer=%p, "
+                ".prog_buffer=%p, .lookahead_buffer=%p, "
+                ".name_max=%"PRIu32", .file_max=%"PRIu32", "
+                ".attr_max=%"PRIu32"})",
+            (void*)lfs, (void*)cfg, cfg->context,
+            (void*)(uintptr_t)cfg->read, (void*)(uintptr_t)cfg->prog,
+            (void*)(uintptr_t)cfg->erase, (void*)(uintptr_t)cfg->sync,
+            cfg->read_size, cfg->prog_size, cfg->block_size, cfg->block_count,
+            cfg->block_cycles, cfg->cache_size, cfg->lookahead_size,
+            cfg->read_buffer, cfg->prog_buffer, cfg->lookahead_buffer,
+            cfg->name_max, cfg->file_max, cfg->attr_max);
     int err = 0;
     {
         err = lfs_init(lfs, cfg);
         if (err) {
+            LFS_TRACE("lfs_format -> %d", err);
             return err;
         }
 
@@ -3350,12 +3513,30 @@ int lfs_format(lfs_t *lfs, const struct lfs_config *cfg) {
 
 cleanup:
     lfs_deinit(lfs);
+    LFS_TRACE("lfs_format -> %d", err);
     return err;
 }
 
 int lfs_mount(lfs_t *lfs, const struct lfs_config *cfg) {
+    LFS_TRACE("lfs_mount(%p, %p {.context=%p, "
+                ".read=%p, .prog=%p, .erase=%p, .sync=%p, "
+                ".read_size=%"PRIu32", .prog_size=%"PRIu32", "
+                ".block_size=%"PRIu32", .block_count=%"PRIu32", "
+                ".block_cycles=%"PRIu32", .cache_size=%"PRIu32", "
+                ".lookahead_size=%"PRIu32", .read_buffer=%p, "
+                ".prog_buffer=%p, .lookahead_buffer=%p, "
+                ".name_max=%"PRIu32", .file_max=%"PRIu32", "
+                ".attr_max=%"PRIu32"})",
+            (void*)lfs, (void*)cfg, cfg->context,
+            (void*)(uintptr_t)cfg->read, (void*)(uintptr_t)cfg->prog,
+            (void*)(uintptr_t)cfg->erase, (void*)(uintptr_t)cfg->sync,
+            cfg->read_size, cfg->prog_size, cfg->block_size, cfg->block_count,
+            cfg->block_cycles, cfg->cache_size, cfg->lookahead_size,
+            cfg->read_buffer, cfg->prog_buffer, cfg->lookahead_buffer,
+            cfg->name_max, cfg->file_max, cfg->attr_max);
     int err = lfs_init(lfs, cfg);
     if (err) {
+        LFS_TRACE("lfs_mount -> %d", err);
         return err;
     }
 
@@ -3440,7 +3621,7 @@ int lfs_mount(lfs_t *lfs, const struct lfs_config *cfg) {
         // has gstate?
         err = lfs_dir_getgstate(lfs, &dir, &lfs->gpending);
         if (err) {
-            return err;
+            goto cleanup;
         }
     }
 
@@ -3466,21 +3647,28 @@ int lfs_mount(lfs_t *lfs, const struct lfs_config *cfg) {
     lfs->free.i = 0;
     lfs_alloc_ack(lfs);
 
+    LFS_TRACE("lfs_mount -> %d", 0);
     return 0;
 
 cleanup:
     lfs_unmount(lfs);
+    LFS_TRACE("lfs_mount -> %d", err);
     return err;
 }
 
 int lfs_unmount(lfs_t *lfs) {
-    return lfs_deinit(lfs);
+    LFS_TRACE("lfs_unmount(%p)", (void*)lfs);
+    int err = lfs_deinit(lfs);
+    LFS_TRACE("lfs_unmount -> %d", err);
+    return err;
 }
 
 
 /// Filesystem filesystem operations ///
 int lfs_fs_traverse(lfs_t *lfs,
         int (*cb)(void *data, lfs_block_t block), void *data) {
+    LFS_TRACE("lfs_fs_traverse(%p, %p, %p)",
+            (void*)lfs, (void*)(uintptr_t)cb, data);
     // iterate over metadata pairs
     lfs_mdir_t dir = {.tail = {0, 1}};
 
@@ -3489,6 +3677,7 @@ int lfs_fs_traverse(lfs_t *lfs,
     if (lfs->lfs1) {
         int err = lfs1_traverse(lfs, cb, data);
         if (err) {
+            LFS_TRACE("lfs_fs_traverse -> %d", err);
             return err;
         }
 
@@ -3501,6 +3690,7 @@ int lfs_fs_traverse(lfs_t *lfs,
         for (int i = 0; i < 2; i++) {
             int err = cb(data, dir.tail[i]);
             if (err) {
+                LFS_TRACE("lfs_fs_traverse -> %d", err);
                 return err;
             }
         }
@@ -3508,6 +3698,7 @@ int lfs_fs_traverse(lfs_t *lfs,
         // iterate through ids in directory
         int err = lfs_dir_fetch(lfs, &dir, dir.tail);
         if (err) {
+            LFS_TRACE("lfs_fs_traverse -> %d", err);
             return err;
         }
 
@@ -3519,6 +3710,7 @@ int lfs_fs_traverse(lfs_t *lfs,
                 if (tag == LFS_ERR_NOENT) {
                     continue;
                 }
+                LFS_TRACE("lfs_fs_traverse -> %d", tag);
                 return tag;
             }
             lfs_ctz_fromle32(&ctz);
@@ -3527,6 +3719,7 @@ int lfs_fs_traverse(lfs_t *lfs,
                 err = lfs_ctz_traverse(lfs, NULL, &lfs->rcache,
                         ctz.head, ctz.size, cb, data);
                 if (err) {
+                    LFS_TRACE("lfs_fs_traverse -> %d", err);
                     return err;
                 }
             }
@@ -3543,6 +3736,7 @@ int lfs_fs_traverse(lfs_t *lfs,
             int err = lfs_ctz_traverse(lfs, &f->cache, &lfs->rcache,
                     f->ctz.head, f->ctz.size, cb, data);
             if (err) {
+                LFS_TRACE("lfs_fs_traverse -> %d", err);
                 return err;
             }
         }
@@ -3551,11 +3745,13 @@ int lfs_fs_traverse(lfs_t *lfs,
             int err = lfs_ctz_traverse(lfs, &f->cache, &lfs->rcache,
                     f->block, f->pos, cb, data);
             if (err) {
+                LFS_TRACE("lfs_fs_traverse -> %d", err);
                 return err;
             }
         }
     }
 
+    LFS_TRACE("lfs_fs_traverse -> %d", 0);
     return 0;
 }
 
@@ -3819,13 +4015,16 @@ static int lfs_fs_size_count(void *p, lfs_block_t block) {
 }
 
 lfs_ssize_t lfs_fs_size(lfs_t *lfs) {
+    LFS_TRACE("lfs_fs_size(%p)", (void*)lfs);
     lfs_size_t size = 0;
     int err = lfs_fs_traverse(lfs, lfs_fs_size_count, &size);
     if (err) {
+        LFS_TRACE("lfs_fs_size -> %"PRId32, err);
         return err;
     }
 
-  return size;
+    LFS_TRACE("lfs_fs_size -> %"PRId32, err);
+    return size;
 }
 
 #ifdef LFS_MIGRATE
@@ -4249,9 +4448,26 @@ static int lfs1_unmount(lfs_t *lfs) {
 
 /// v1 migration ///
 int lfs_migrate(lfs_t *lfs, const struct lfs_config *cfg) {
+    LFS_TRACE("lfs_migrate(%p, %p {.context=%p, "
+                ".read=%p, .prog=%p, .erase=%p, .sync=%p, "
+                ".read_size=%"PRIu32", .prog_size=%"PRIu32", "
+                ".block_size=%"PRIu32", .block_count=%"PRIu32", "
+                ".block_cycles=%"PRIu32", .cache_size=%"PRIu32", "
+                ".lookahead_size=%"PRIu32", .read_buffer=%p, "
+                ".prog_buffer=%p, .lookahead_buffer=%p, "
+                ".name_max=%"PRIu32", .file_max=%"PRIu32", "
+                ".attr_max=%"PRIu32"})",
+            (void*)lfs, (void*)cfg, cfg->context,
+            (void*)(uintptr_t)cfg->read, (void*)(uintptr_t)cfg->prog,
+            (void*)(uintptr_t)cfg->erase, (void*)(uintptr_t)cfg->sync,
+            cfg->read_size, cfg->prog_size, cfg->block_size, cfg->block_count,
+            cfg->block_cycles, cfg->cache_size, cfg->lookahead_size,
+            cfg->read_buffer, cfg->prog_buffer, cfg->lookahead_buffer,
+            cfg->name_max, cfg->file_max, cfg->attr_max);
     struct lfs1 lfs1;
     int err = lfs1_mount(lfs, &lfs1, cfg);
     if (err) {
+        LFS_TRACE("lfs_migrate -> %d", err);
         return err;
     }
 
@@ -4466,6 +4682,7 @@ int lfs_migrate(lfs_t *lfs, const struct lfs_config *cfg) {
 
 cleanup:
     lfs1_unmount(lfs);
+    LFS_TRACE("lfs_migrate -> %d", err);
     return err;
 }
 
diff --git a/lfs_util.h b/lfs_util.h
index 5a34eb3..5e29b61 100644
--- a/lfs_util.h
+++ b/lfs_util.h
@@ -31,7 +31,10 @@
 #ifndef LFS_NO_ASSERT
 #include <assert.h>
 #endif
-#if !defined(LFS_NO_DEBUG) || !defined(LFS_NO_WARN) || !defined(LFS_NO_ERROR)
+#if !defined(LFS_NO_DEBUG) || \
+        !defined(LFS_NO_WARN) || \
+        !defined(LFS_NO_ERROR) || \
+        defined(LFS_YES_TRACE)
 #include <stdio.h>
 #endif
 
@@ -46,6 +49,13 @@ extern "C"
 // code footprint
 
 // Logging functions
+#ifdef LFS_YES_TRACE
+#define LFS_TRACE(fmt, ...) \
+    printf("lfs trace:%d: " fmt "\n", __LINE__, __VA_ARGS__)
+#else
+#define LFS_TRACE(fmt, ...)
+#endif
+
 #ifndef LFS_NO_DEBUG
 #define LFS_DEBUG(fmt, ...) \
     printf("lfs debug:%d: " fmt "\n", __LINE__, __VA_ARGS__)