What APM answers that logs do not

Free preview 4 min to read

Two courses ago you had structured logs, then traces. Both answer questions about one thing that happened. Neither answers the question you get asked first, which is some version of "is the site all right?"

A million log lines cannot answer that without being aggregated, and aggregating a million lines every minute is not what a log store is for. Metrics are: numbers, at intervals, small enough to keep forever and cheap enough to query on every dashboard refresh.

Application Performance Monitoring (APM) is metrics with a Rails-shaped opinion. It knows what a controller action is, what an N+1 looks like, and what "the average request" means, so its default view is about your application rather than about your CPU.

flowchart LR
  M["Metrics / APM: is something wrong, where roughly, and how bad?"] --> T["Traces: where exactly, in one request"]
  T --> L["Logs: what happened, with which values"]
  L -.->|"the fix"| C["Code"]
  M -.->|"alerts"| P["A person"]

The three questions APM answers

Is it healthy right now? Error rate, throughput and latency, updated every few seconds, against yesterday and against last week.

What is slow, in aggregate? Not "this request was slow" (traces do that) but "this endpoint is the slowest thing we serve, and it is 40% of our total time". That ranking is what turns performance work from a hunch into a queue.

Did the change help? A deploy marker on a latency chart, with a before and an after. Without it, "it feels faster" is the whole evidence available.

Where the numbers come from

Rails emits instrumentation events for everything an APM cares about, and every APM agent for Rails is built on the same mechanism you can use directly:

ActiveSupport::Notifications.subscribe("process_action.action_controller") do |event|
  # event.payload carries :controller, :action, :status,
  #                      :view_runtime, :db_runtime, :path, :method
  StatsD.timing("request.duration", event.duration,
                tags: ["controller:#{event.payload[:controller]}",
                       "action:#{event.payload[:action]}",
                       "status:#{event.payload[:status]}"])
end

That is close to what an APM does, more than a simplified illustration of it. The events are documented, and the ones that matter are few:

Event Carries
process_action.action_controller :controller, :action, :status, :view_runtime, :db_runtime, :path
sql.active_record :sql, :name, :cached, :row_count, :affected_rows
render_template.action_view :identifier, :layout, :locals
enqueue.active_job / perform.active_job :adapter, :job, and :db_runtime on perform
cache_read.active_support :key, :store, :hit

Take two things from that table beyond the names.

process_action.action_controller carries :view_runtime and :db_runtime separately, which means the split between rendering and database time is available without any tracing at all. That single ratio answers the question lesson 2 of the Puma course needed (is this application I/O-bound or CPU-bound?) from data Rails already emits.

And cache_read.active_support carries :hit, so your cache hit rate is a metric you can have today rather than a thing you assume.

Prefer monotonic time

A one-argument block, like the one above, receives an Event whose duration already comes from the monotonic clock. The trap is the five-argument form, where start and finish are wall-clock Time objects unless you ask otherwise:

ActiveSupport::Notifications.monotonic_subscribe("sql.active_record") do |name, start, finish, id, payload|
  # start and finish are monotonic floats here, not Time objects
end

A wall clock can move: NTP adjusts it, and it can go backwards. That produces durations that are negative or absurd, at a rate low enough to be dismissed as noise and high enough to distort a percentile. Monotonic time only moves forward, and for measuring durations it is the correct instrument.

What APM is not

  • Not a profiler. It tells you an endpoint is slow, not which line of Ruby is hot. That is a different tool with a different overhead.
  • Not a replacement for traces. Aggregates hide the individual request; you need both, which is why the previous course exists.
  • Not free. Per-host or per-request pricing, and a cardinality bill that behaves like the one in the logging course.

What this course covers

  1. What APM answers that logs do not (this lesson).
  2. The metrics worth having.
  3. Percentiles, averages, and Apdex.
  4. Instrumenting this application.
  5. Alerts that people act on.
  6. Choosing and paying for a tool.
  7. Putting it together: a monitoring setup.

Key takeaways

  • Metrics answer "is the system healthy?", which logs and traces cannot without aggregation they are not built for.
  • APM is metrics that understand Rails: controller actions, queries, views, jobs and cache.
  • ActiveSupport::Notifications is the mechanism every agent uses, and you can subscribe to it directly.
  • process_action.action_controller already separates :view_runtime from :db_runtime, and cache_read.active_support carries :hit.
  • A one-argument subscriber's event.duration is already monotonic; with the five-argument form, use monotonic_subscribe, because the wall clock can move backwards.
Lesson 1 of 7 · free

Keep going with lesson 2

The metrics worth having

Covers the four golden signals, Rails-specific metrics, RED and USE, and which numbers to leave off dashboards.

A free account also gives you the quizzes, your progress and notes, and the discussion.

Type to start searching...