From: Kent Overstreet Date: Fri, 10 Dec 2021 20:41:38 +0000 (-0500) Subject: bcachefs: Add more time_stats X-Git-Tag: v6.7-rc1~201^2~1257 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=991ba0211290884df42f9506499aba7e933a2bb8;p=thirdparty%2Fkernel%2Flinux.git bcachefs: Add more time_stats This adds more latency/event measurements and breaks some apart into more events. Journal writes are broken apart into flush writes and noflush writes, btree compactions are broken out from btree splits, btree mergers are added, as well as btree_interior_updates - foreground and total. Signed-off-by: Kent Overstreet --- diff --git a/fs/bcachefs/bcachefs.h b/fs/bcachefs/bcachefs.h index 5e9378843476d..dde919a955859 100644 --- a/fs/bcachefs/bcachefs.h +++ b/fs/bcachefs/bcachefs.h @@ -321,8 +321,12 @@ BCH_DEBUG_PARAMS_DEBUG() #define BCH_TIME_STATS() \ x(btree_node_mem_alloc) \ x(btree_node_split) \ + x(btree_node_compact) \ + x(btree_node_merge) \ x(btree_node_sort) \ x(btree_node_read) \ + x(btree_interior_update_foreground) \ + x(btree_interior_update_total) \ x(btree_gc) \ x(btree_lock_contended_read) \ x(btree_lock_contended_intent) \ @@ -330,8 +334,8 @@ BCH_DEBUG_PARAMS_DEBUG() x(data_write) \ x(data_read) \ x(data_promote) \ - x(journal_write) \ - x(journal_delay) \ + x(journal_flush_write) \ + x(journal_noflush_write) \ x(journal_flush_seq) \ x(blocked_journal) \ x(blocked_allocate) \ diff --git a/fs/bcachefs/btree_gc.c b/fs/bcachefs/btree_gc.c index dc4562a1e1223..ccb85850080b6 100644 --- a/fs/bcachefs/btree_gc.c +++ b/fs/bcachefs/btree_gc.c @@ -1849,6 +1849,7 @@ int bch2_gc_gens(struct bch_fs *c) struct bch_dev *ca; struct bucket_array *buckets; struct bucket *g; + u64 start_time = local_clock(); unsigned i; int ret; @@ -1892,6 +1893,8 @@ int bch2_gc_gens(struct bch_fs *c) c->gc_gens_pos = POS_MIN; c->gc_count++; + + bch2_time_stats_update(&c->times[BCH_TIME_btree_gc], start_time); err: up_read(&c->gc_lock); return ret; diff --git a/fs/bcachefs/btree_update_interior.c b/fs/bcachefs/btree_update_interior.c index a28c7cf381ce8..8865ab7d087be 100644 --- a/fs/bcachefs/btree_update_interior.c +++ b/fs/bcachefs/btree_update_interior.c @@ -455,15 +455,23 @@ static void bch2_btree_update_free(struct btree_update *as) bch2_disk_reservation_put(c, &as->disk_res); bch2_btree_reserve_put(as); + bch2_time_stats_update(&c->times[BCH_TIME_btree_interior_update_total], + as->start_time); + mutex_lock(&c->btree_interior_update_lock); list_del(&as->unwritten_list); list_del(&as->list); - mutex_unlock(&c->btree_interior_update_lock); closure_debug_destroy(&as->cl); mempool_free(as, &c->btree_interior_update_pool); + /* + * Have to do the wakeup with btree_interior_update_lock still held, + * since being on btree_interior_update_list is our ref on @c: + */ closure_wake_up(&c->btree_interior_update_wait); + + mutex_unlock(&c->btree_interior_update_lock); } static void btree_update_will_delete_key(struct btree_update *as, @@ -902,6 +910,9 @@ static void bch2_btree_interior_update_will_free_node(struct btree_update *as, static void bch2_btree_update_done(struct btree_update *as) { + struct bch_fs *c = as->c; + u64 start_time = as->start_time; + BUG_ON(as->mode == BTREE_INTERIOR_NO_UPDATE); if (as->took_gc_lock) @@ -912,6 +923,9 @@ static void bch2_btree_update_done(struct btree_update *as) continue_at(&as->cl, btree_update_set_nodes_written, as->c->btree_interior_update_worker); + + bch2_time_stats_update(&c->times[BCH_TIME_btree_interior_update_foreground], + start_time); } static struct btree_update * @@ -921,6 +935,7 @@ bch2_btree_update_start(struct btree_trans *trans, struct btree_path *path, struct bch_fs *c = trans->c; struct btree_update *as; struct closure cl; + u64 start_time = local_clock(); int disk_res_flags = (flags & BTREE_INSERT_NOFAIL) ? BCH_DISK_RESERVATION_NOFAIL : 0; int journal_flags = 0; @@ -960,6 +975,7 @@ retry: memset(as, 0, sizeof(*as)); closure_init(&as->cl, NULL); as->c = c; + as->start_time = start_time; as->mode = BTREE_INTERIOR_NO_UPDATE; as->took_gc_lock = !(flags & BTREE_INSERT_GC_LOCK_HELD); as->btree_id = path->btree_id; @@ -1452,7 +1468,9 @@ static void btree_split(struct btree_update *as, struct btree_trans *trans, bch2_trans_verify_locks(trans); - bch2_time_stats_update(&c->times[BCH_TIME_btree_node_split], + bch2_time_stats_update(&c->times[n2 + ? BCH_TIME_btree_node_split + : BCH_TIME_btree_node_compact], start_time); } @@ -1573,6 +1591,7 @@ int __bch2_foreground_maybe_merge(struct btree_trans *trans, struct btree *b, *m, *n, *prev, *next, *parent; struct bpos sib_pos; size_t sib_u64s; + u64 start_time = local_clock(); int ret = 0; BUG_ON(!path->should_be_locked); @@ -1710,6 +1729,8 @@ int __bch2_foreground_maybe_merge(struct btree_trans *trans, six_unlock_intent(&n->c.lock); bch2_btree_update_done(as); + + bch2_time_stats_update(&c->times[BCH_TIME_btree_node_merge], start_time); out: err: bch2_path_put(trans, sib_path, true); diff --git a/fs/bcachefs/btree_update_interior.h b/fs/bcachefs/btree_update_interior.h index 8e03bd987d6dc..d4574161a733a 100644 --- a/fs/bcachefs/btree_update_interior.h +++ b/fs/bcachefs/btree_update_interior.h @@ -35,6 +35,7 @@ bool bch2_btree_node_format_fits(struct bch_fs *c, struct btree *, struct btree_update { struct closure cl; struct bch_fs *c; + u64 start_time; struct list_head list; struct list_head unwritten_list; diff --git a/fs/bcachefs/fs-common.c b/fs/bcachefs/fs-common.c index 5f3429e991156..d543480be1117 100644 --- a/fs/bcachefs/fs-common.c +++ b/fs/bcachefs/fs-common.c @@ -329,6 +329,7 @@ bool bch2_reinherit_attrs(struct bch_inode_unpacked *dst_u, bool ret = false; for (id = 0; id < Inode_opt_nr; id++) { + /* Skip attributes that were explicitly set on this inode */ if (dst_u->bi_fields_set & (1 << id)) continue; diff --git a/fs/bcachefs/journal.c b/fs/bcachefs/journal.c index 3ce6a78263baf..f15d265ef1b64 100644 --- a/fs/bcachefs/journal.c +++ b/fs/bcachefs/journal.c @@ -625,6 +625,12 @@ int bch2_journal_flush_seq(struct journal *j, u64 seq) u64 start_time = local_clock(); int ret, ret2; + /* + * Don't update time_stats when @seq is already flushed: + */ + if (seq <= j->flushed_seq_ondisk) + return 0; + ret = wait_event_interruptible(j->wait, (ret2 = bch2_journal_flush_seq_async(j, seq, NULL))); if (!ret) diff --git a/fs/bcachefs/journal_io.c b/fs/bcachefs/journal_io.c index 680ddba1889d6..1a8c0a7eaca7c 100644 --- a/fs/bcachefs/journal_io.c +++ b/fs/bcachefs/journal_io.c @@ -1237,7 +1237,9 @@ static void journal_write_done(struct closure *cl) u64 v, seq; int err = 0; - bch2_time_stats_update(j->write_time, j->write_start_time); + bch2_time_stats_update(!JSET_NO_FLUSH(w->data) + ? j->flush_write_time + : j->noflush_write_time, j->write_start_time); if (!w->devs_written.nr) { bch_err(c, "unable to write journal to sufficient devices"); diff --git a/fs/bcachefs/journal_types.h b/fs/bcachefs/journal_types.h index 9f59e4889f521..0c4df603280d7 100644 --- a/fs/bcachefs/journal_types.h +++ b/fs/bcachefs/journal_types.h @@ -271,8 +271,8 @@ struct journal { u64 nr_flush_writes; u64 nr_noflush_writes; - struct bch2_time_stats *write_time; - struct bch2_time_stats *delay_time; + struct bch2_time_stats *flush_write_time; + struct bch2_time_stats *noflush_write_time; struct bch2_time_stats *blocked_time; struct bch2_time_stats *flush_seq_time; diff --git a/fs/bcachefs/opts.h b/fs/bcachefs/opts.h index aad57a82e5fd5..bb2ecc778a8c2 100644 --- a/fs/bcachefs/opts.h +++ b/fs/bcachefs/opts.h @@ -81,9 +81,9 @@ enum opt_type { */ #ifdef __KERNEL__ -#define RATELIMIT_ERRORS true +#define RATELIMIT_ERRORS_DEFAULT true #else -#define RATELIMIT_ERRORS false +#define RATELIMIT_ERRORS_DEFAULT false #endif #define BCH_OPTS() \ @@ -288,7 +288,7 @@ enum opt_type { x(ratelimit_errors, u8, \ OPT_FS|OPT_MOUNT, \ OPT_BOOL(), \ - NO_SB_OPT, RATELIMIT_ERRORS, \ + NO_SB_OPT, RATELIMIT_ERRORS_DEFAULT, \ NULL, "Ratelimit error messages during fsck") \ x(nochanges, u8, \ OPT_FS|OPT_MOUNT, \ diff --git a/fs/bcachefs/super.c b/fs/bcachefs/super.c index 22dbbf77d6877..afa1a8fa493b2 100644 --- a/fs/bcachefs/super.c +++ b/fs/bcachefs/super.c @@ -730,10 +730,10 @@ static struct bch_fs *bch2_fs_alloc(struct bch_sb *sb, struct bch_opts opts) c->rebalance.enabled = 1; c->promote_whole_extents = true; - c->journal.write_time = &c->times[BCH_TIME_journal_write]; - c->journal.delay_time = &c->times[BCH_TIME_journal_delay]; - c->journal.blocked_time = &c->times[BCH_TIME_blocked_journal]; - c->journal.flush_seq_time = &c->times[BCH_TIME_journal_flush_seq]; + c->journal.flush_write_time = &c->times[BCH_TIME_journal_flush_write]; + c->journal.noflush_write_time = &c->times[BCH_TIME_journal_noflush_write]; + c->journal.blocked_time = &c->times[BCH_TIME_blocked_journal]; + c->journal.flush_seq_time = &c->times[BCH_TIME_journal_flush_seq]; bch2_fs_btree_cache_init_early(&c->btree_cache);