Telemetry Timers

When instrumenting code, timers offer a convenient way for measuring the duration of individual operations.

The metrics API in CAF includes histograms for sampling observations over time. For example, how long it takes to handle incoming requests or to perform some expensive operations.

Sampling time manually is quite tedious, though, as illustrated by this snippet:

caf::telemetry::dbl_histogram* my_histogram = nullptr;
// ... some place later ...
auto t0 = std::chrono::steady_clock::now();
// ... expensive operation ...
auto delta = std::chrono::steady_clock::now() - t0;
// ... convert delta to fractional seconds and pass to my_histogram ...

To automate this process, CAF includes timers. They simply store the current timestamp when created and pass the elapsed time since construction to a histogram when destroyed. Hence, we can replace the verbose version from before simply by putting a timer into the scope of the expensive option and take advantage of RAII:

caf::telemetry::dbl_histogram* my_histogram = nullptr;
// ... some place later ...
{
  auto t = caf::telemetry::timer{my_histogram};
  // ... expensive operation ...
}

By the way, passing a null pointer the constructor of timer is perfectly fine. This accounts for the fact that some metrics may be disabled by default.

In a more complete example, a worker that samples expensive operation may follow this template:

struct worker_state {
  explicit worker_state(caf::event_based_actor* self) {
    std::array<double, 6> default_time_buckets{{
      0.00001, //  10us
      0.0001,  // 100us
      0.001,   //   1ms
      0.01,    //  10ms
      0.1,     // 100ms
      1.,      //   1s
    }};
    processing_time = self->system().metrics().histogram_singleton<double>(
      "my-app", "processing-time", default_time_buckets,
      "Time the app needs to perform the expensive computation..", "seconds");
  }

  int32_t expensive_computation() {
    auto t = caf::telemetry::timer{processing_time};
    auto result = int32_t{42};
    // ... expensive number crunching on result ...
    return result;
  }

  caf::behavior make_behavior() {
    return {
      [this](caf::get_atom) {
        return expensive_computation();
      },
    };
  }

  caf::telemetry::dbl_histogram* processing_time;

  static inline const char* name = "worker";
};

After spinning up a worker and exporting your metrics to Prometheus, you can query the custom metric as my_app_processing_time_seconds.

Previous
Previous

JSON Serialization

Next
Next

Indenting Trace Logs