From eec80944cd35d8e54c83b561a654e0a92e497fc5 Mon Sep 17 00:00:00 2001 From: Zygo Blaxell Date: Tue, 6 Dec 2016 00:20:05 -0500 Subject: [PATCH] roots: add a counter for crawl_ms, open_root and open_root_ino Linux kernel commit 7f8e406 ("btrfs: improve delayed refs iterations") seems to dramatically improve LOGICAL_INO performance. Hopefully this commit will find its way into mainline Linux soon. This means that most of the time in Bees is now spent on block reading (50-75%); however, there is still a big gap between block read and the sum of everything else we are measuring with the "*_ms" counters. This gap is about 30% of the run time, so it would be good to find out what's in the gap. Add ms counters around the crawl and open calls to capture where we are spending all the time. --- src/bees-context.cc | 10 ++++++++-- src/bees-roots.cc | 2 ++ 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/src/bees-context.cc b/src/bees-context.cc index c0f4e4e..babee3f 100644 --- a/src/bees-context.cc +++ b/src/bees-context.cc @@ -24,10 +24,16 @@ getenv_or_die(const char *name) BeesFdCache::BeesFdCache() { m_root_cache.func([&](shared_ptr ctx, uint64_t root) -> Fd { - return ctx->roots()->open_root_nocache(root); + Timer open_timer; + auto rv = ctx->roots()->open_root_nocache(root); + BEESCOUNTADD(open_root_ms, open_timer.age() * 1000); + return rv; }); m_file_cache.func([&](shared_ptr ctx, uint64_t root, uint64_t ino) -> Fd { - return ctx->roots()->open_root_ino_nocache(root, ino); + Timer open_timer; + auto rv = ctx->roots()->open_root_ino_nocache(root, ino); + BEESCOUNTADD(open_ino_ms, open_timer.age() * 1000); + return rv; }); } diff --git a/src/bees-roots.cc b/src/bees-roots.cc index 7ca9b96..251374c 100644 --- a/src/bees-roots.cc +++ b/src/bees-roots.cc @@ -661,7 +661,9 @@ BeesCrawl::fetch_extents() { BEESNOTE("searching crawl sk " << static_cast(sk)); BEESTOOLONG("Searching crawl sk " << static_cast(sk)); + Timer crawl_timer; ioctl_ok = sk.do_ioctl_nothrow(m_ctx->root_fd()); + BEESCOUNTADD(crawl_ms, crawl_timer.age() * 1000); } if (ioctl_ok) {