bcachefs: Error message improvement
authorKent Overstreet <kent.overstreet@linux.dev>
Wed, 16 Nov 2022 01:25:08 +0000 (20:25 -0500)
committerKent Overstreet <kent.overstreet@linux.dev>
Sun, 22 Oct 2023 21:09:46 +0000 (17:09 -0400)
 - Centralize format strings in bcachefs.h
 - Add bch2_fmt_inum_offset() and related helpers
 - Switch error messages for inodes to also print out the offset, in
   bytes

Signed-off-by: Kent Overstreet <kent.overstreet@linux.dev>
fs/bcachefs/bcachefs.h
fs/bcachefs/error.h
fs/bcachefs/fs-io.c
fs/bcachefs/io.c
fs/bcachefs/io_types.h
fs/bcachefs/journal_io.c

index 90a1bd1f9d63c91edd34bcc70e5457975db2c36a..c8ab0e2029dfc838d913ddf70e581d3867a4c13a 100644 (file)
@@ -230,15 +230,27 @@ do {                                                                      \
 #endif
 
 #ifdef BCACHEFS_LOG_PREFIX
-#define bch2_log_msg(_c, fmt)          "bcachefs (%s): " fmt, ((_c)->name)
-#define bch2_fmt(_c, fmt)              bch2_log_msg(_c, fmt "\n")
-#define bch2_fmt_inum(_c, _inum, fmt)  "bcachefs (%s inum %llu): " fmt "\n", ((_c)->name), (_inum)
+
+#define bch2_log_msg(_c, fmt)                  "bcachefs (%s): " fmt, ((_c)->name)
+#define bch2_fmt_dev(_ca, fmt)                 "bcachefs (%s): " fmt "\n", ((_ca)->name)
+#define bch2_fmt_dev_offset(_ca, _offset, fmt) "bcachefs (%s sector %llu): " fmt "\n", ((_ca)->name), (_offset)
+#define bch2_fmt_inum(_c, _inum, fmt)          "bcachefs (%s inum %llu): " fmt "\n", ((_c)->name), (_inum)
+#define bch2_fmt_inum_offset(_c, _inum, _offset, fmt)                  \
+        "bcachefs (%s inum %llu offset %llu): " fmt "\n", ((_c)->name), (_inum), (_offset)
+
 #else
-#define bch2_log_msg(_c, fmt)          fmt
-#define bch2_fmt(_c, fmt)              fmt "\n"
-#define bch2_fmt_inum(_c, _inum, fmt)  "inum %llu: " fmt "\n", (_inum)
+
+#define bch2_log_msg(_c, fmt)                  fmt
+#define bch2_fmt_dev(_ca, fmt)                 "%s: " fmt "\n", ((_ca)->name)
+#define bch2_fmt_dev_offset(_ca, _offset, fmt) "%s sector %llu: " fmt "\n", ((_ca)->name), (_offset)
+#define bch2_fmt_inum(_c, _inum, fmt)          "inum %llu: " fmt "\n", (_inum)
+#define bch2_fmt_inum_offset(_c, _inum, _offset, fmt)                          \
+        "inum %llu offset %llu: " fmt "\n", (_inum), (_offset)
+
 #endif
 
+#define bch2_fmt(_c, fmt)              bch2_log_msg(_c, fmt "\n")
+
 #define bch_info(c, fmt, ...) \
        printk(KERN_INFO bch2_fmt(c, fmt), ##__VA_ARGS__)
 #define bch_notice(c, fmt, ...) \
@@ -247,13 +259,28 @@ do {                                                                      \
        printk(KERN_WARNING bch2_fmt(c, fmt), ##__VA_ARGS__)
 #define bch_warn_ratelimited(c, fmt, ...) \
        printk_ratelimited(KERN_WARNING bch2_fmt(c, fmt), ##__VA_ARGS__)
+
 #define bch_err(c, fmt, ...) \
        printk(KERN_ERR bch2_fmt(c, fmt), ##__VA_ARGS__)
+#define bch_err_dev(ca, fmt, ...) \
+       printk(KERN_ERR bch2_fmt_dev(ca, fmt), ##__VA_ARGS__)
+#define bch_err_dev_offset(ca, _offset, fmt, ...) \
+       printk(KERN_ERR bch2_fmt_dev_offset(ca, _offset, fmt), ##__VA_ARGS__)
+#define bch_err_inum(c, _inum, fmt, ...) \
+       printk(KERN_ERR bch2_fmt_inum(c, _inum, fmt), ##__VA_ARGS__)
+#define bch_err_inum_offset(c, _inum, _offset, fmt, ...) \
+       printk(KERN_ERR bch2_fmt_inum_offset(c, _inum, _offset, fmt), ##__VA_ARGS__)
 
 #define bch_err_ratelimited(c, fmt, ...) \
        printk_ratelimited(KERN_ERR bch2_fmt(c, fmt), ##__VA_ARGS__)
+#define bch_err_dev_ratelimited(ca, fmt, ...) \
+       printk_ratelimited(KERN_ERR bch2_fmt_dev(ca, fmt), ##__VA_ARGS__)
+#define bch_err_dev_offset_ratelimited(ca, _offset, fmt, ...) \
+       printk_ratelimited(KERN_ERR bch2_fmt_dev_offset(ca, _offset, fmt), ##__VA_ARGS__)
 #define bch_err_inum_ratelimited(c, _inum, fmt, ...) \
        printk_ratelimited(KERN_ERR bch2_fmt_inum(c, _inum, fmt), ##__VA_ARGS__)
+#define bch_err_inum_offset_ratelimited(c, _inum, _offset, fmt, ...) \
+       printk_ratelimited(KERN_ERR bch2_fmt_inum_offset(c, _inum, _offset, fmt), ##__VA_ARGS__)
 
 #define bch_verbose(c, fmt, ...)                                       \
 do {                                                                   \
index bbf9b6d85b4dcf55d794afd88ed52d228e40eba8..dae72620dae36e4bc8b23298010766f9e2b074c3 100644 (file)
@@ -186,36 +186,25 @@ void bch2_io_error_work(struct work_struct *);
 /* Does the error handling without logging a message */
 void bch2_io_error(struct bch_dev *);
 
-/* Logs message and handles the error: */
-#define bch2_dev_io_error(ca, fmt, ...)                                        \
-do {                                                                   \
-       printk_ratelimited(KERN_ERR "bcachefs (%s): " fmt,              \
-               (ca)->name, ##__VA_ARGS__);                             \
-       bch2_io_error(ca);                                              \
-} while (0)
-
-#define bch2_dev_inum_io_error(ca, _inum, _offset, fmt, ...)           \
-do {                                                                   \
-       printk_ratelimited(KERN_ERR "bcachefs (%s inum %llu offset %llu): " fmt,\
-               (ca)->name, (_inum), (_offset), ##__VA_ARGS__);         \
-       bch2_io_error(ca);                                              \
-} while (0)
-
 #define bch2_dev_io_err_on(cond, ca, ...)                              \
 ({                                                                     \
        bool _ret = (cond);                                             \
                                                                        \
-       if (_ret)                                                       \
-               bch2_dev_io_error(ca, __VA_ARGS__);                     \
+       if (_ret) {                                                     \
+               bch_err_dev_ratelimited(ca, __VA_ARGS__);               \
+               bch2_io_error(ca);                                      \
+       }                                                               \
        _ret;                                                           \
 })
 
-#define bch2_dev_inum_io_err_on(cond, ca, _inum, _offset, ...)         \
+#define bch2_dev_inum_io_err_on(cond, ca, ...)                         \
 ({                                                                     \
        bool _ret = (cond);                                             \
                                                                        \
-       if (_ret)                                                       \
-               bch2_dev_inum_io_error(ca, _inum, _offset, __VA_ARGS__);\
+       if (_ret) {                                                     \
+               bch_err_inum_offset_ratelimited(ca, __VA_ARGS__);       \
+               bch2_io_error(ca);                                      \
+       }                                                               \
        _ret;                                                           \
 })
 
index 36c42231b7ed87ebb4fe22666e7bdf0aa63bda11..8deb476a17c8060509d2618480178c5970084b5d 100644 (file)
@@ -1087,7 +1087,9 @@ err:
                goto retry;
 
        if (ret) {
-               bch_err_inum_ratelimited(c, inum.inum,
+               bch_err_inum_offset_ratelimited(c,
+                               iter.pos.inode,
+                               iter.pos.offset << 9,
                                "read error %i from btree lookup", ret);
                rbio->bio.bi_status = BLK_STS_IOERR;
                bio_endio(&rbio->bio);
index 701bfc8ce0e414dc99019a658318cdf3ee800590..821c14763c66a5c1d58178613e5f8cfa77a87e26 100644 (file)
@@ -571,6 +571,7 @@ void bch2_submit_wbio_replicas(struct bch_write_bio *wbio, struct bch_fs *c,
                n->have_ioref           = bch2_dev_get_ioref(ca,
                                        type == BCH_DATA_btree ? READ : WRITE);
                n->submit_time          = local_clock();
+               n->inode_offset         = bkey_start_offset(&k->k);
                n->bio.bi_iter.bi_sector = ptr->offset;
 
                if (likely(n->have_ioref)) {
@@ -680,8 +681,12 @@ static void __bch2_write_index(struct bch_write_op *op)
                op->written += sectors_start - keylist_sectors(keys);
 
                if (ret) {
-                       bch_err_inum_ratelimited(c, op->pos.inode,
-                               "write error while doing btree update: %s", bch2_err_str(ret));
+                       struct bkey_i *k = bch2_keylist_front(&op->insert_keys);
+
+                       bch_err_inum_offset_ratelimited(c,
+                               k->k.p.inode, k->k.p.offset << 9,
+                               "write error while doing btree update: %s",
+                               bch2_err_str(ret));
                        goto err;
                }
        }
@@ -787,7 +792,7 @@ static void bch2_write_endio(struct bio *bio)
 
        if (bch2_dev_inum_io_err_on(bio->bi_status, ca,
                                    op->pos.inode,
-                                   op->pos.offset - bio_sectors(bio), /* XXX definitely wrong */
+                                   wbio->inode_offset << 9,
                                    "data write error: %s",
                                    bch2_blk_status_to_str(bio->bi_status))) {
                set_bit(wbio->dev, op->failed.d);
@@ -1405,8 +1410,10 @@ void bch2_write(struct closure *cl)
        wbio_init(bio)->put_bio = false;
 
        if (bio->bi_iter.bi_size & (c->opts.block_size - 1)) {
-               bch_err_inum_ratelimited(c, op->pos.inode,
-                                        "misaligned write");
+               bch_err_inum_offset_ratelimited(c,
+                       op->pos.inode,
+                       op->pos.offset << 9,
+                       "misaligned write");
                op->error = -EIO;
                goto err;
        }
@@ -1987,20 +1994,25 @@ csum_err:
                goto out;
        }
 
-       bch2_dev_inum_io_error(ca, rbio->read_pos.inode, (u64) rbio->bvec_iter.bi_sector,
+       bch_err_inum_offset_ratelimited(ca,
+               rbio->read_pos.inode,
+               rbio->read_pos.offset << 9,
                "data checksum error: expected %0llx:%0llx got %0llx:%0llx (type %s)",
                rbio->pick.crc.csum.hi, rbio->pick.crc.csum.lo,
                csum.hi, csum.lo, bch2_csum_types[crc.csum_type]);
+       bch2_io_error(ca);
        bch2_rbio_error(rbio, READ_RETRY_AVOID, BLK_STS_IOERR);
        goto out;
 decompression_err:
-       bch_err_inum_ratelimited(c, rbio->read_pos.inode,
-                                "decompression error");
+       bch_err_inum_offset_ratelimited(c, rbio->read_pos.inode,
+                                       rbio->read_pos.offset << 9,
+                                       "decompression error");
        bch2_rbio_error(rbio, READ_ERR, BLK_STS_IOERR);
        goto out;
 decrypt_err:
-       bch_err_inum_ratelimited(c, rbio->read_pos.inode,
-                                "decrypt error");
+       bch_err_inum_offset_ratelimited(c, rbio->read_pos.inode,
+                                       rbio->read_pos.offset << 9,
+                                       "decrypt error");
        bch2_rbio_error(rbio, READ_ERR, BLK_STS_IOERR);
        goto out;
 }
@@ -2075,7 +2087,9 @@ int __bch2_read_indirect_extent(struct btree_trans *trans,
 
        if (k.k->type != KEY_TYPE_reflink_v &&
            k.k->type != KEY_TYPE_indirect_inline_data) {
-               bch_err_inum_ratelimited(trans->c, orig_k->k->k.p.inode,
+               bch_err_inum_offset_ratelimited(trans->c,
+                       orig_k->k->k.p.inode,
+                       orig_k->k->k.p.offset << 9,
                        "%llu len %u points to nonexistent indirect extent %llu",
                        orig_k->k->k.p.offset,
                        orig_k->k->k.size,
@@ -2161,8 +2175,9 @@ retry_pick:
                goto hole;
 
        if (pick_ret < 0) {
-               bch_err_inum_ratelimited(c, k.k->p.inode,
-                                        "no device to read from");
+               bch_err_inum_offset_ratelimited(c,
+                               read_pos.inode, read_pos.offset << 9,
+                               "no device to read from");
                goto err;
        }
 
@@ -2341,8 +2356,10 @@ get_bio:
 
        if (!rbio->pick.idx) {
                if (!rbio->have_ioref) {
-                       bch_err_inum_ratelimited(c, k.k->p.inode,
-                                                "no device to read from");
+                       bch_err_inum_offset_ratelimited(c,
+                                       read_pos.inode,
+                                       read_pos.offset << 9,
+                                       "no device to read from");
                        bch2_rbio_error(rbio, READ_RETRY_AVOID, BLK_STS_IOERR);
                        goto out;
                }
@@ -2515,8 +2532,9 @@ err:
        bch2_bkey_buf_exit(&sk, c);
 
        if (ret) {
-               bch_err_inum_ratelimited(c, inum.inum,
-                                        "read error %i from btree lookup", ret);
+               bch_err_inum_offset_ratelimited(c, inum.inum,
+                                               bvec_iter.bi_sector << 9,
+                                               "read error %i from btree lookup", ret);
                rbio->bio.bi_status = BLK_STS_IOERR;
                bch2_rbio_done(rbio);
        }
index b31f2a22f098260612c69ba9802e0228120bd26b..8e83ce5bc805062cba71a450009382946e741695 100644 (file)
@@ -88,6 +88,7 @@ struct bch_write_bio {
        struct bch_write_bio    *parent;
 
        u64                     submit_time;
+       u64                     inode_offset;
 
        struct bch_devs_list    failed;
        u8                      dev;
index 1db2ccf2627ad9b27501baaab3f3f8b26eb7c91a..6b9bd1f55fe343790a77b9c3e7c54ea8d0cbd7e3 100644 (file)
@@ -1268,10 +1268,10 @@ int bch2_journal_read(struct bch_fs *c, u64 *blacklist_seq, u64 *start_seq)
                        struct bch_dev *ca = bch_dev_bkey_exists(c, i->ptrs[ptr].dev);
 
                        if (!i->ptrs[ptr].csum_good)
-                               printk(KERN_ERR "bcachefs (%s) sector %llu: invalid journal checksum, seq %llu%s\n",
-                                      ca->name, i->ptrs[ptr].sector,
-                                      le64_to_cpu(i->j.seq),
-                                      i->csum_good ? " (had good copy on another device)" : "");
+                               bch_err_dev_offset(ca, i->ptrs[ptr].sector,
+                                                  "invalid journal checksum, seq %llu%s",
+                                                  le64_to_cpu(i->j.seq),
+                                                  i->csum_good ? " (had good copy on another device)" : "");
                }
 
                ret = jset_validate(c,