bcachefs: Improve trace_move_extent_fail()
authorKent Overstreet <kent.overstreet@linux.dev>
Fri, 10 Mar 2023 22:34:29 +0000 (17:34 -0500)
committerKent Overstreet <kent.overstreet@linux.dev>
Sun, 22 Oct 2023 21:09:59 +0000 (17:09 -0400)
This greatly expands the move_extent_fail tracepoint - now it includes
all the information we have available, including exactly why the extent
wasn't updated.

Signed-off-by: Kent Overstreet <kent.overstreet@linux.dev>
fs/bcachefs/data_update.c
fs/bcachefs/trace.h

index 865514d..7a58506 100644 (file)
@@ -7,6 +7,7 @@
 #include "buckets.h"
 #include "data_update.h"
 #include "ec.h"
+#include "error.h"
 #include "extents.h"
 #include "io.h"
 #include "keylist.h"
@@ -91,6 +92,70 @@ static int insert_snapshot_whiteouts(struct btree_trans *trans,
        return ret;
 }
 
+static void trace_move_extent_fail2(struct data_update *m,
+                        struct bkey_s_c new,
+                        struct bkey_s_c wrote,
+                        struct bkey_i *insert,
+                        const char *msg)
+{
+       struct bch_fs *c = m->op.c;
+       struct bkey_s_c old = bkey_i_to_s_c(m->k.k);
+       const union bch_extent_entry *entry;
+       struct bch_extent_ptr *ptr;
+       struct extent_ptr_decoded p;
+       struct printbuf buf = PRINTBUF;
+       unsigned i, rewrites_found = 0;
+
+       if (!trace_move_extent_fail_enabled())
+               return;
+
+       prt_str(&buf, msg);
+
+       if (insert) {
+               i = 0;
+               bkey_for_each_ptr_decode(old.k, bch2_bkey_ptrs_c(old), p, entry) {
+                       struct bkey_s new_s;
+                       new_s.k = (void *) new.k;
+                       new_s.v = (void *) new.v;
+
+                       if (((1U << i) & m->data_opts.rewrite_ptrs) &&
+                           (ptr = bch2_extent_has_ptr(old, p, bkey_i_to_s(insert))) &&
+                           !ptr->cached)
+                               rewrites_found |= 1U << i;
+                       i++;
+               }
+       }
+
+       prt_printf(&buf, "\nrewrite ptrs:   %u%u%u%u",
+                  (m->data_opts.rewrite_ptrs & (1 << 0)) != 0,
+                  (m->data_opts.rewrite_ptrs & (1 << 1)) != 0,
+                  (m->data_opts.rewrite_ptrs & (1 << 2)) != 0,
+                  (m->data_opts.rewrite_ptrs & (1 << 3)) != 0);
+
+       prt_printf(&buf, "\nrewrites found: %u%u%u%u",
+                  (rewrites_found & (1 << 0)) != 0,
+                  (rewrites_found & (1 << 1)) != 0,
+                  (rewrites_found & (1 << 2)) != 0,
+                  (rewrites_found & (1 << 3)) != 0);
+
+       prt_str(&buf, "\nold:    ");
+       bch2_bkey_val_to_text(&buf, c, old);
+
+       prt_str(&buf, "\nnew:    ");
+       bch2_bkey_val_to_text(&buf, c, new);
+
+       prt_str(&buf, "\nwrote:  ");
+       bch2_bkey_val_to_text(&buf, c, wrote);
+
+       if (insert) {
+               prt_str(&buf, "\ninsert: ");
+               bch2_bkey_val_to_text(&buf, c, bkey_i_to_s_c(insert));
+       }
+
+       trace_move_extent_fail(c, buf.buf);
+       printbuf_exit(&buf);
+}
+
 static int __bch2_data_update_index_update(struct btree_trans *trans,
                                           struct bch_write_op *op)
 {
@@ -134,8 +199,11 @@ static int __bch2_data_update_index_update(struct btree_trans *trans,
 
                new = bkey_i_to_extent(bch2_keylist_front(keys));
 
-               if (!bch2_extents_match(k, old))
+               if (!bch2_extents_match(k, old)) {
+                       trace_move_extent_fail2(m, k, bkey_i_to_s_c(&new->k_i),
+                                               NULL, "no match:");
                        goto nowork;
+               }
 
                bkey_reassemble(_insert.k, k);
                insert = _insert.k;
@@ -174,8 +242,10 @@ static int __bch2_data_update_index_update(struct btree_trans *trans,
 
                if (m->data_opts.rewrite_ptrs &&
                    !rewrites_found &&
-                   bch2_bkey_durability(c, k) >= m->op.opts.data_replicas)
+                   bch2_bkey_durability(c, k) >= m->op.opts.data_replicas) {
+                       trace_move_extent_fail2(m, k, bkey_i_to_s_c(&new->k_i), insert, "no rewrites found:");
                        goto nowork;
+               }
 
                /*
                 * A replica that we just wrote might conflict with a replica
@@ -189,8 +259,10 @@ restart_drop_conflicting_replicas:
                                goto restart_drop_conflicting_replicas;
                        }
 
-               if (!bkey_val_u64s(&new->k))
+               if (!bkey_val_u64s(&new->k)) {
+                       trace_move_extent_fail2(m, k, bkey_i_to_s_c(&new->k_i), insert, "new replicas conflicted:");
                        goto nowork;
+               }
 
                /* Now, drop pointers that conflict with what we just wrote: */
                extent_for_each_ptr_decode(extent_i_to_s(new), p, entry)
@@ -293,7 +365,6 @@ nowork:
                }
 
                this_cpu_add(c->counters[BCH_COUNTER_move_extent_fail], new->k.size);
-               trace_move_extent_fail(&new->k);
 
                bch2_btree_iter_advance(&iter);
                goto next;
index 65521c0..bbe8eb7 100644 (file)
@@ -682,9 +682,21 @@ DEFINE_EVENT(bkey, move_extent_finish,
        TP_ARGS(k)
 );
 
-DEFINE_EVENT(bkey, move_extent_fail,
-       TP_PROTO(const struct bkey *k),
-       TP_ARGS(k)
+TRACE_EVENT(move_extent_fail,
+       TP_PROTO(struct bch_fs *c, const char *msg),
+       TP_ARGS(c, msg),
+
+       TP_STRUCT__entry(
+               __field(dev_t,          dev                     )
+               __string(msg,           msg                     )
+       ),
+
+       TP_fast_assign(
+               __entry->dev            = c->dev;
+               __assign_str(msg, msg);
+       ),
+
+       TP_printk("%d:%d %s", MAJOR(__entry->dev), MINOR(__entry->dev), __get_str(msg))
 );
 
 DEFINE_EVENT(bkey, move_extent_alloc_mem_fail,