Create Performance Benchmarks to measure ActivityBuffer overhead

Summary:
In order to help with retroactive debugging of EdenFS, we recently set up support for an eden trace inode --retroactive command to retrieve information about the last n inode materializations. In order to do this, an ActivityBuffer in each EdenMount subscribes to an InodeTraceBus to receive and store information about inode materializations as they occur to be viewed retroactively by the eden trace inode --retroactive command.

In this diff, we set up performance benchmarks that measure the time needed to publish Inode events to an EdenMount's inodeTraceBus as well as read these events into the subscribed ActivityBuffer. This is done through the materialization paths of creating a directory and writing to a file where we expect activitybuffer overheads to be relatively largest. Specifically, the benchmark first times creating a large number of files, then unmaterializes the files by committing them, checking out the base parent commit, and checking back into the new commit, and then times writing to each file. Additionally, the unmaterializing and writing portion of the benchmark is repeated through several iterations. This benchmark is run both with the ActivityBuffer enabled and disabled to measure the overheads from adding to the ActivityBuffer.

Also, this benchmark currently does not run on windows due to folly include errors, though a task is set up to fix this in the future.

Reviewed By: chadaustin

Differential Revision: D37857084

fbshipit-source-id: 0bbde7d66ff07cb22546bb5fdbaadc4c1494b60c

eden/fs/telemetry/test/ActivityBufferBenchmark.cpp

@@ -0,0 +1,109 @@
+/*
+ * Copyright (c) Meta Platforms, Inc. and affiliates.
+ *
+ * This software may be used and distributed according to the terms of the
+ * GNU General Public License version 2.
+ */
+
+#include <folly/File.h>
+#include <folly/init/Init.h>
+#include <folly/portability/GFlags.h>
+#include <folly/stop_watch.h>
+#include "eden/fs/utils/SpawnedProcess.h"
+
+using namespace facebook::eden;
+
+namespace {
+
+constexpr uint32_t kNumFiles = 500;
+constexpr uint32_t kNumWriteIterations = 10;
+constexpr size_t kPageSize = 4096;
+
+DEFINE_uint64(filesize, kPageSize, "File size in bytes");
+
+SpawnedProcess::Options pipe_stdout_opts() {
+  SpawnedProcess::Options opts;
+  opts.pipeStdout();
+  return opts;
+}
+
+std::string get_checkout_id() {
+  SpawnedProcess whereamiProcess({"hg", "whereami"}, pipe_stdout_opts());
+  std::string id = whereamiProcess.communicate().first;
+  whereamiProcess.wait();
+  return id;
+}
+
+std::string file_name(uint32_t id) {
+  return fmt::format("{}{}{}", "activity_buffer_benchmark_file", id, ".txt");
+}
+
+struct TemporaryFile {
+  explicit TemporaryFile(uint32_t id)
+      : file{file_name(id), O_CREAT | O_EXCL | O_WRONLY | O_CLOEXEC} {
+    if (FLAGS_filesize == 0 || (FLAGS_filesize % kPageSize)) {
+      throw std::invalid_argument{"file size must be multiple of page size"};
+    }
+    folly::checkUnixError(ftruncate(file.fd(), FLAGS_filesize), "ftruncate");
+  }
+
+  folly::File file;
+};
+
+double get_time_elapsed(folly::stop_watch<> watch) {
+  return std::chrono::duration_cast<std::chrono::duration<double>>(
+             watch.elapsed())
+      .count();
+}
+
+void ActivityBuffer_repeatedly_create_inodes() {
+  printf("Creating files...\n");
+  folly::stop_watch<> file_create_timer;
+  for (uint32_t id = 0; id < kNumFiles; id++) {
+    TemporaryFile{id};
+  }
+  printf(
+      "Average elapsed time for creating a file: %.6f s\n",
+      get_time_elapsed(file_create_timer) / kNumFiles);
+
+  printf("Committing changes...\n");
+  auto parent_id = get_checkout_id();
+  SpawnedProcess({"hg", "add", "."}, pipe_stdout_opts()).wait();
+  SpawnedProcess({"hg", "commit", "-m", "ActivityBufferBenchmark In Progress"})
+      .wait();
+  auto child_id = get_checkout_id();
+
+  char s[] = "Test Message";
+  double total_write_time = 0;
+  printf("Unmaterializing and Writing to Files...\n");
+  for (uint32_t iteration = 0; iteration < kNumWriteIterations; iteration++) {
+    SpawnedProcess({"hg", "checkout", "--clean", parent_id}, pipe_stdout_opts())
+        .wait();
+    SpawnedProcess({"hg", "checkout", child_id}, pipe_stdout_opts()).wait();
+    for (uint32_t id = 0; id < kNumFiles; id++) {
+      folly::File file{file_name(id), O_WRONLY};
+      folly::stop_watch<> file_write_timer;
+      folly::checkUnixError(pwrite(file.fd(), s, sizeof(s), 0));
+      total_write_time += get_time_elapsed(file_write_timer);
+    }
+  }
+  printf(
+      "Average elapsed time for writing to a file: %.6f s\n",
+      total_write_time / (kNumFiles * kNumWriteIterations));
+
+  printf("Uncommitting changes and deleting files...\n");
+  SpawnedProcess({"hg", "uncommit"}).wait();
+  for (uint32_t id = 0; id < kNumFiles; id++) {
+    folly::checkUnixError(std::remove(file_name(id).c_str()));
+  }
+  SpawnedProcess({"hg", "addremove"}, pipe_stdout_opts()).wait();
+  printf("ActivityBufferBenchmark finished\n");
+}
+
+} // namespace
+
+int main(int argc, char* argv[]) {
+  folly::init(&argc, &argv);
+  ActivityBuffer_repeatedly_create_inodes();
+  return 0;
+}

eden/fs/telemetry/test/ActivityBufferTest.cpp

@@ -8,8 +8,10 @@
 #include "eden/fs/telemetry/ActivityBuffer.h"
 #include <folly/portability/GTest.h>
 
-constexpr uint32_t kMaxBufLength = 10;
 using namespace facebook::eden;
+namespace {
+
+constexpr uint32_t kMaxBufLength = 10;
 
 bool buffer_contains_event_with_ino(ActivityBuffer& buff, InodeNumber ino) {
   auto events = buff.getAllEvents();
@@ -28,6 +30,8 @@ InodeTraceEvent create_inode_trace_event(InodeNumber ino) {
       std::chrono::microseconds(1000)};
 }
 
+} // namespace
+
 TEST(ActivityBufferTest, initialize_buffer) {
   ActivityBuffer buff(kMaxBufLength);
 }