bcache: Fix/revamp tracepoints

The tracepoints were reworked to be more sensible, and fixed a null
pointer deref in one of the tracepoints.

Converted some of the pr_debug()s to tracepoints - this is partly a
performance optimization; it used to be that with DEBUG or
CONFIG_DYNAMIC_DEBUG pr_debug() was an empty macro; but at some point it
was changed to an empty inline function.

Some of the pr_debug() statements had rather expensive function calls as
part of the arguments, so this code was getting run unnecessarily even
on non debug kernels - in some fast paths, too.

Signed-off-by: Kent Overstreet <koverstreet@google.com>

1 files changed, 241 insertions, 111 deletions

diff --git a/include/trace/events/bcache.h b/include/trace/events/bcache.h
index 3cc5a0b278c3..c9952b36fcea 100644
--- a/include/trace/events/bcache.h
+++ b/include/trace/events/bcache.h
@@ -9,9 +9,7 @@
 struct search;
 
 DECLARE_EVENT_CLASS(bcache_request,
-
         TP_PROTO(struct search *s, struct bio *bio),
-
         TP_ARGS(s, bio),
 
         TP_STRUCT__entry(
@@ -22,7 +20,6 @@ DECLARE_EVENT_CLASS(bcache_request,
                 __field(dev_t,          orig_sector             )
                 __field(unsigned int,   nr_sector               )
                 __array(char,           rwbs,   6               )
-                __array(char,           comm,   TASK_COMM_LEN   )
         ),
 
         TP_fast_assign(
@@ -33,36 +30,66 @@ DECLARE_EVENT_CLASS(bcache_request,
                 __entry->orig_sector    = bio->bi_sector - 16;
                 __entry->nr_sector      = bio->bi_size >> 9;
                 blk_fill_rwbs(__entry->rwbs, bio->bi_rw, bio->bi_size);
-                memcpy(__entry->comm, current->comm, TASK_COMM_LEN);
         ),
 
-        TP_printk("%d,%d %s %llu + %u [%s] (from %d,%d @ %llu)",
+        TP_printk("%d,%d %s %llu + %u (from %d,%d @ %llu)",
                   MAJOR(__entry->dev), MINOR(__entry->dev),
-                  __entry->rwbs,
-                  (unsigned long long)__entry->sector,
-                  __entry->nr_sector, __entry->comm,
-                  __entry->orig_major, __entry->orig_minor,
+                  __entry->rwbs, (unsigned long long)__entry->sector,
+                  __entry->nr_sector, __entry->orig_major, __entry->orig_minor,
                   (unsigned long long)__entry->orig_sector)
 );
 
-DEFINE_EVENT(bcache_request, bcache_request_start,
+DECLARE_EVENT_CLASS(bkey,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k),
 
-        TP_PROTO(struct search *s, struct bio *bio),
+        TP_STRUCT__entry(
+                __field(u32,    size                            )
+                __field(u32,    inode                           )
+                __field(u64,    offset                          )
+                __field(bool,   dirty                           )
+        ),
 
-        TP_ARGS(s, bio)
+        TP_fast_assign(
+                __entry->inode  = KEY_INODE(k);
+                __entry->offset = KEY_OFFSET(k);
+                __entry->size   = KEY_SIZE(k);
+                __entry->dirty  = KEY_DIRTY(k);
+        ),
+
+        TP_printk("%u:%llu len %u dirty %u", __entry->inode,
+                  __entry->offset, __entry->size, __entry->dirty)
 );
 
-DEFINE_EVENT(bcache_request, bcache_request_end,
+DECLARE_EVENT_CLASS(btree_node,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b),
+
+        TP_STRUCT__entry(
+                __field(size_t,         bucket                  )
+        ),
+
+        TP_fast_assign(
+                __entry->bucket = PTR_BUCKET_NR(b->c, &b->key, 0);
+        ),
 
+        TP_printk("bucket %zu", __entry->bucket)
+);
+
+/* request.c */
+
+DEFINE_EVENT(bcache_request, bcache_request_start,
         TP_PROTO(struct search *s, struct bio *bio),
+        TP_ARGS(s, bio)
+);
 
+DEFINE_EVENT(bcache_request, bcache_request_end,
+        TP_PROTO(struct search *s, struct bio *bio),
         TP_ARGS(s, bio)
 );
 
 DECLARE_EVENT_CLASS(bcache_bio,
-
         TP_PROTO(struct bio *bio),
-
         TP_ARGS(bio),
 
         TP_STRUCT__entry(
@@ -70,7 +97,6 @@ DECLARE_EVENT_CLASS(bcache_bio,
                 __field(sector_t,       sector                  )
                 __field(unsigned int,   nr_sector               )
                 __array(char,           rwbs,   6               )
-                __array(char,           comm,   TASK_COMM_LEN   )
         ),
 
         TP_fast_assign(
@@ -78,191 +104,295 @@ DECLARE_EVENT_CLASS(bcache_bio,
                 __entry->sector         = bio->bi_sector;
                 __entry->nr_sector      = bio->bi_size >> 9;
                 blk_fill_rwbs(__entry->rwbs, bio->bi_rw, bio->bi_size);
-                memcpy(__entry->comm, current->comm, TASK_COMM_LEN);
         ),
 
-        TP_printk("%d,%d  %s %llu + %u [%s]",
-                  MAJOR(__entry->dev), MINOR(__entry->dev),
-                  __entry->rwbs,
-                  (unsigned long long)__entry->sector,
-                  __entry->nr_sector, __entry->comm)
+        TP_printk("%d,%d  %s %llu + %u",
+                  MAJOR(__entry->dev), MINOR(__entry->dev), __entry->rwbs,
+                  (unsigned long long)__entry->sector, __entry->nr_sector)
 );
 
-
-DEFINE_EVENT(bcache_bio, bcache_passthrough,
-
+DEFINE_EVENT(bcache_bio, bcache_bypass_sequential,
         TP_PROTO(struct bio *bio),
-
         TP_ARGS(bio)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_cache_hit,
-
+DEFINE_EVENT(bcache_bio, bcache_bypass_congested,
         TP_PROTO(struct bio *bio),
-
         TP_ARGS(bio)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_cache_miss,
+TRACE_EVENT(bcache_read,
+        TP_PROTO(struct bio *bio, bool hit, bool bypass),
+        TP_ARGS(bio, hit, bypass),
 
-        TP_PROTO(struct bio *bio),
+        TP_STRUCT__entry(
+                __field(dev_t,          dev                     )
+                __field(sector_t,       sector                  )
+                __field(unsigned int,   nr_sector               )
+                __array(char,           rwbs,   6               )
+                __field(bool,           cache_hit               )
+                __field(bool,           bypass                  )
+        ),
 
-        TP_ARGS(bio)
+        TP_fast_assign(
+                __entry->dev            = bio->bi_bdev->bd_dev;
+                __entry->sector         = bio->bi_sector;
+                __entry->nr_sector      = bio->bi_size >> 9;
+                blk_fill_rwbs(__entry->rwbs, bio->bi_rw, bio->bi_size);
+                __entry->cache_hit = hit;
+                __entry->bypass = bypass;
+        ),
+
+        TP_printk("%d,%d  %s %llu + %u hit %u bypass %u",
+                  MAJOR(__entry->dev), MINOR(__entry->dev),
+                  __entry->rwbs, (unsigned long long)__entry->sector,
+                  __entry->nr_sector, __entry->cache_hit, __entry->bypass)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_read_retry,
+TRACE_EVENT(bcache_write,
+        TP_PROTO(struct bio *bio, bool writeback, bool bypass),
+        TP_ARGS(bio, writeback, bypass),
 
-        TP_PROTO(struct bio *bio),
+        TP_STRUCT__entry(
+                __field(dev_t,          dev                     )
+                __field(sector_t,       sector                  )
+                __field(unsigned int,   nr_sector               )
+                __array(char,           rwbs,   6               )
+                __field(bool,           writeback               )
+                __field(bool,           bypass                  )
+        ),
 
-        TP_ARGS(bio)
-);
+        TP_fast_assign(
+                __entry->dev            = bio->bi_bdev->bd_dev;
+                __entry->sector         = bio->bi_sector;
+                __entry->nr_sector      = bio->bi_size >> 9;
+                blk_fill_rwbs(__entry->rwbs, bio->bi_rw, bio->bi_size);
+                __entry->writeback = writeback;
+                __entry->bypass = bypass;
+        ),
 
-DEFINE_EVENT(bcache_bio, bcache_writethrough,
+        TP_printk("%d,%d  %s %llu + %u hit %u bypass %u",
+                  MAJOR(__entry->dev), MINOR(__entry->dev),
+                  __entry->rwbs, (unsigned long long)__entry->sector,
+                  __entry->nr_sector, __entry->writeback, __entry->bypass)
+);
 
+DEFINE_EVENT(bcache_bio, bcache_read_retry,
         TP_PROTO(struct bio *bio),
-
         TP_ARGS(bio)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_writeback,
+DEFINE_EVENT(bkey, bcache_cache_insert,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k)
+);
 
-        TP_PROTO(struct bio *bio),
+/* Journal */
 
-        TP_ARGS(bio)
-);
+DECLARE_EVENT_CLASS(cache_set,
+        TP_PROTO(struct cache_set *c),
+        TP_ARGS(c),
 
-DEFINE_EVENT(bcache_bio, bcache_write_skip,
+        TP_STRUCT__entry(
+                __array(char,           uuid,   16 )
+        ),
 
-        TP_PROTO(struct bio *bio),
+        TP_fast_assign(
+                memcpy(__entry->uuid, c->sb.set_uuid, 16);
+        ),
 
-        TP_ARGS(bio)
+        TP_printk("%pU", __entry->uuid)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_btree_read,
-
-        TP_PROTO(struct bio *bio),
+DEFINE_EVENT(bkey, bcache_journal_replay_key,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k)
+);
 
-        TP_ARGS(bio)
+DEFINE_EVENT(cache_set, bcache_journal_full,
+        TP_PROTO(struct cache_set *c),
+        TP_ARGS(c)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_btree_write,
+DEFINE_EVENT(cache_set, bcache_journal_entry_full,
+        TP_PROTO(struct cache_set *c),
+        TP_ARGS(c)
+);
 
+DEFINE_EVENT(bcache_bio, bcache_journal_write,
         TP_PROTO(struct bio *bio),
-
         TP_ARGS(bio)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_write_dirty,
+/* Btree */
 
-        TP_PROTO(struct bio *bio),
+DEFINE_EVENT(cache_set, bcache_btree_cache_cannibalize,
+        TP_PROTO(struct cache_set *c),
+        TP_ARGS(c)
+);
 
-        TP_ARGS(bio)
+DEFINE_EVENT(btree_node, bcache_btree_read,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_read_dirty,
+TRACE_EVENT(bcache_btree_write,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b),
 
-        TP_PROTO(struct bio *bio),
+        TP_STRUCT__entry(
+                __field(size_t,         bucket                  )
+                __field(unsigned,       block                   )
+                __field(unsigned,       keys                    )
+        ),
 
-        TP_ARGS(bio)
+        TP_fast_assign(
+                __entry->bucket = PTR_BUCKET_NR(b->c, &b->key, 0);
+                __entry->block  = b->written;
+                __entry->keys   = b->sets[b->nsets].data->keys;
+        ),
+
+        TP_printk("bucket %zu", __entry->bucket)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_write_moving,
+DEFINE_EVENT(btree_node, bcache_btree_node_alloc,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b)
+);
 
-        TP_PROTO(struct bio *bio),
+DEFINE_EVENT(btree_node, bcache_btree_node_alloc_fail,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b)
+);
 
-        TP_ARGS(bio)
+DEFINE_EVENT(btree_node, bcache_btree_node_free,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b)
 );
 
-DEFINE_EVENT(bcache_bio, bcache_read_moving,
+TRACE_EVENT(bcache_btree_gc_coalesce,
+        TP_PROTO(unsigned nodes),
+        TP_ARGS(nodes),
 
-        TP_PROTO(struct bio *bio),
+        TP_STRUCT__entry(
+                __field(unsigned,       nodes                   )
+        ),
 
-        TP_ARGS(bio)
-);
+        TP_fast_assign(
+                __entry->nodes  = nodes;
+        ),
 
-DEFINE_EVENT(bcache_bio, bcache_journal_write,
+        TP_printk("coalesced %u nodes", __entry->nodes)
+);
 
-        TP_PROTO(struct bio *bio),
+DEFINE_EVENT(cache_set, bcache_gc_start,
+        TP_PROTO(struct cache_set *c),
+        TP_ARGS(c)
+);
 
-        TP_ARGS(bio)
+DEFINE_EVENT(cache_set, bcache_gc_end,
+        TP_PROTO(struct cache_set *c),
+        TP_ARGS(c)
 );
 
-DECLARE_EVENT_CLASS(bcache_cache_bio,
+DEFINE_EVENT(bkey, bcache_gc_copy,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k)
+);
 
-        TP_PROTO(struct bio *bio,
-                 sector_t orig_sector,
-                 struct block_device* orig_bdev),
+DEFINE_EVENT(bkey, bcache_gc_copy_collision,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k)
+);
 
-        TP_ARGS(bio, orig_sector, orig_bdev),
+DECLARE_EVENT_CLASS(btree_split,
+        TP_PROTO(struct btree *b, unsigned keys),
+        TP_ARGS(b, keys),
 
         TP_STRUCT__entry(
-                __field(dev_t,          dev                     )
-                __field(dev_t,          orig_dev                )
-                __field(sector_t,       sector                  )
-                __field(sector_t,       orig_sector             )
-                __field(unsigned int,   nr_sector               )
-                __array(char,           rwbs,   6               )
-                __array(char,           comm,   TASK_COMM_LEN   )
+                __field(size_t,         bucket                  )
+                __field(unsigned,       keys                    )
         ),
 
         TP_fast_assign(
-                __entry->dev            = bio->bi_bdev->bd_dev;
-                __entry->orig_dev       = orig_bdev->bd_dev;
-                __entry->sector         = bio->bi_sector;
-                __entry->orig_sector    = orig_sector;
-                __entry->nr_sector      = bio->bi_size >> 9;
-                blk_fill_rwbs(__entry->rwbs, bio->bi_rw, bio->bi_size);
-                memcpy(__entry->comm, current->comm, TASK_COMM_LEN);
+                __entry->bucket = PTR_BUCKET_NR(b->c, &b->key, 0);
+                __entry->keys   = keys;
         ),
 
-        TP_printk("%d,%d  %s %llu + %u [%s] (from %d,%d %llu)",
-                  MAJOR(__entry->dev), MINOR(__entry->dev),
-                  __entry->rwbs,
-                  (unsigned long long)__entry->sector,
-                  __entry->nr_sector, __entry->comm,
-                  MAJOR(__entry->orig_dev), MINOR(__entry->orig_dev),
-                  (unsigned long long)__entry->orig_sector)
+        TP_printk("bucket %zu keys %u", __entry->bucket, __entry->keys)
 );
 
-DEFINE_EVENT(bcache_cache_bio, bcache_cache_insert,
-
-        TP_PROTO(struct bio *bio,
-                 sector_t orig_sector,
-                 struct block_device *orig_bdev),
+DEFINE_EVENT(btree_split, bcache_btree_node_split,
+        TP_PROTO(struct btree *b, unsigned keys),
+        TP_ARGS(b, keys)
+);
 
-        TP_ARGS(bio, orig_sector, orig_bdev)
+DEFINE_EVENT(btree_split, bcache_btree_node_compact,
+        TP_PROTO(struct btree *b, unsigned keys),
+        TP_ARGS(b, keys)
 );
 
-DECLARE_EVENT_CLASS(bcache_gc,
+DEFINE_EVENT(btree_node, bcache_btree_set_root,
+        TP_PROTO(struct btree *b),
+        TP_ARGS(b)
+);
 
-        TP_PROTO(uint8_t *uuid),
+/* Allocator */
 
-        TP_ARGS(uuid),
+TRACE_EVENT(bcache_alloc_invalidate,
+        TP_PROTO(struct cache *ca),
+        TP_ARGS(ca),
 
         TP_STRUCT__entry(
-                __field(uint8_t *,      uuid)
+                __field(unsigned,       free                    )
+                __field(unsigned,       free_inc                )
+                __field(unsigned,       free_inc_size           )
+                __field(unsigned,       unused                  )
         ),
 
         TP_fast_assign(
-                __entry->uuid           = uuid;
+                __entry->free           = fifo_used(&ca->free);
+                __entry->free_inc       = fifo_used(&ca->free_inc);
+                __entry->free_inc_size  = ca->free_inc.size;
+                __entry->unused         = fifo_used(&ca->unused);
         ),
 
-        TP_printk("%pU", __entry->uuid)
+        TP_printk("free %u free_inc %u/%u unused %u", __entry->free,
+                  __entry->free_inc, __entry->free_inc_size, __entry->unused)
 );
 
+TRACE_EVENT(bcache_alloc_fail,
+        TP_PROTO(struct cache *ca),
+        TP_ARGS(ca),
 
-DEFINE_EVENT(bcache_gc, bcache_gc_start,
+        TP_STRUCT__entry(
+                __field(unsigned,       free                    )
+                __field(unsigned,       free_inc                )
+                __field(unsigned,       unused                  )
+                __field(unsigned,       blocked                 )
+        ),
 
-             TP_PROTO(uint8_t *uuid),
+        TP_fast_assign(
+                __entry->free           = fifo_used(&ca->free);
+                __entry->free_inc       = fifo_used(&ca->free_inc);
+                __entry->unused         = fifo_used(&ca->unused);
+                __entry->blocked        = atomic_read(&ca->set->prio_blocked);
+        ),
 
-             TP_ARGS(uuid)
+        TP_printk("free %u free_inc %u unused %u blocked %u", __entry->free,
+                  __entry->free_inc, __entry->unused, __entry->blocked)
 );
 
-DEFINE_EVENT(bcache_gc, bcache_gc_end,
+/* Background writeback */
 
-             TP_PROTO(uint8_t *uuid),
+DEFINE_EVENT(bkey, bcache_writeback,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k)
+);
 
-             TP_ARGS(uuid)
+DEFINE_EVENT(bkey, bcache_writeback_collision,
+        TP_PROTO(struct bkey *k),
+        TP_ARGS(k)
 );
 
 #endif /* _TRACE_BCACHE_H */