Railyard’s dashboard had been getting slower for a couple of weeks. Clicking into an app took long enough that I noticed every time, the median page sat around 1.7 seconds, and every so often a page hung for five to thirteen seconds.

The control plane is a Rails 8 app with Hotwire on the front. It runs on a small 2-vCPU box next to a micro RDS instance. On that box: Puma with one process and five threads, the gRPC server the agents on customer servers talk to, the Solid Queue worker, a log forwarder, and during a release a second copy of the web app. On September 30 I measured, expecting one big cause, and found five. The worst one was outside the Rails app entirely.

Measuring before touching anything

I took the baseline from production, read-only, and wanted two numbers.

The first was request time per controller action. Rails already logs it. With config.log_tags = [ :request_id ], every request writes a tagged Processing by ApplicationsController#show line and later a Completed 200 OK in 1843ms line with the same tag. Pairing the two by request ID gives the action and its duration, and sorting the durations gives percentiles.

The second number came from the database. Railyard uses Solid Cable, the Rails 8 adapter that runs Action Cable (Rails’ WebSocket layer) on a database table instead of Redis. When code broadcasts, Solid Cable inserts a row into solid_cable_messages. Every process holding WebSocket connections polls that table and pushes new rows to the browsers subscribed to that channel. Counting rows by channel prefix shows what the real-time layer is spending its time on.

# p50 per action from the Rails log, pairing lines by request id
docker compose logs --since 30m app | awk '
  match($0, /\[[0-9a-f-]{36}\]/) { id = substr($0, RSTART, RLENGTH) }
  /Processing by/ { for (i = 1; i <= NF; i++) if ($i == "by") action[id] = $(i + 1) }
  /Completed [0-9]+ .* in [0-9]+ms/ && (id in action) {
    match($0, /in [0-9]+ms/); print action[id], substr($0, RSTART + 3, RLENGTH - 5) + 0
  }' | sort -k1,1 -k2,2n > timings.txt

# Solid Cable rows in the last hour, grouped by channel prefix
bin/rails runner 'puts SolidCable::Message.where(created_at: 1.hour.ago..)
  .pluck(:channel).map { _1.gsub(/\d+/, "N").split(":").first(3).join(":") }.tally'

The baseline:

The app page: p50 1,843 ms, p95 6,166 ms.
The endpoint that lists an app’s log sources: p95 30,759 ms. That is the 30-second deadline on agent calls being hit.
Solid Cable over the last hour: 4,552 messages, and 4,275 of them (94%) were per-line app log broadcasts.
The box had about 1 GB of swap in use.

The swap pointed at the spikes.

An image build on the live box

The control plane’s deploy script builds the Railyard Docker image on my laptop and ships the finished image to the box. If Docker on the laptop wasn’t running, the script fell back, quietly, to building the image on the box itself. That morning I had deployed a few times from my laptop with Docker off. Each deploy ran a full image build on the same two cores that serve the dashboard, and the spike window lined up with those deploys. A BuildKit container on the box had exited half an hour before I looked.

The fallback did have a limit, and the limit was the interesting bug. The builder was created with --driver-opt cpu-shares=128. I had read that as a cap. Docker documents cpu-shares as a relative weight: the kernel’s scheduler only applies it when containers compete for CPU, and then it divides time in proportion to the weights, 128 against the default 1024. Whenever the web process idles for a moment, the builder can take every core. A request that arrives mid-compile waits for a scheduler that is already busy. The memory limit allowed 700 MB plus up to 3 GB of swap on a machine already using most of its RAM, so the build pushed everything else into swap.

A hard cap uses the CFS quota instead. cpu-period=100000 with cpu-quota=50000 means the builder gets at most 50 ms of CPU in every 100 ms window, half a core, regardless of what else is running.

I kept that hard cap for the one case where building on the box is deliberate, behind an explicit opt-in. The default path stops doing it. If local Docker is down, the script starts it and waits up to two minutes, and if it is still down, the deploy stops with a message:

if ! docker info >/dev/null 2>&1; then
  say "starting Docker so the image builds here, not on the live box"
  open -a Docker >/dev/null 2>&1 || true
  for _ in $(seq 60); do
    docker info >/dev/null 2>&1 && break
    sleep 2
  done
  docker info >/dev/null 2>&1 || die "Docker isn't running here; start it before deploying"
fi

The website build moved off the box in the same change.

A tab nobody opened

With builds gone, the median was still bad, and the Solid Cable numbers explained most of it.

The app page has an Overview and fourteen other tabs: Deploys, Logs, Metrics, Environment and so on. The tabs were a Stimulus controller that showed and hid panels in the browser. Every panel was rendered on the server and sent down on every request, visible or not.

That included Logs. When the Logs panel’s HTML landed in the page, its Stimulus controller connected, and connecting did two things. It fetched the list of log sources, a gRPC call to the agent on the app’s server that ran docker inspect and then a docker exec ls per container, one after another: 0.8 to 4 seconds, holding a Puma thread. Then it subscribed to the logs channel, which opened a follow-mode log stream from the agent and broadcast every line to a per-subscriber stream key. Every view of any app page opened a live log tail that nobody was looking at, and every log line became an INSERT into solid_cable_messages that every cable process then polled and read back.

Action Cable has two ways to send data, and the difference is the whole fix. broadcast publishes to a named stream through the adapter, here the database, so any process can reach any subscriber. transmit writes directly to the one WebSocket connection that channel instance belongs to. The log stream’s pump thread runs in the same process as that connection, so it never needed pub/sub at all:

class AppLogsChannel < ApplicationCable::Channel
  # before: a private stream key, a database row per line
  #   stream_from @stream_key
  #   ActionCable.server.broadcast(@stream_key, payload)

  def push(payload)
    transmit(payload)
  rescue StandardError => e
    logger.debug "[applogs] transmit dropped: #{e.class}"
  end
end

Server metrics could not do the same. Heartbeats arrive at the gRPC process while the browser is connected to the web process, so metrics need broadcast to cross that gap. What they did not need was to broadcast when nobody had a chart open. Each heartbeat broadcast a point regardless, 360 messages an hour per server. Now subscribing to the metrics channel writes a key with a two-minute expiry into the shared cache, the chart sends a watching ping every 60 seconds to keep it alive, and the heartbeat handler checks the key before building a point. The watch state lives in the cache because the process that receives heartbeats is a different process from the one holding the socket, so memory in either one would be invisible to the other.

The same change made the server page fetch Docker disk usage only when its Maintenance tab is opened, and made log reads fail immediately for an offline server instead of waiting out the 30-second deadline.

Fourteen hidden tabs

Even without the log stream, rendering every tab on every request was expensive: about 60 partials and 150 to 200 queries. A check in production showed the app page ran 115 queries, 103 of them distinct. So this was no N+1 (the same query repeated once per row). Each tab was cheap, and there were fifteen of them.

Turbo Frames solve this directly. A <turbo-frame> with a src and loading="lazy" renders a placeholder and fetches its content when the frame becomes visible. A panel hidden with the hidden attribute is never visible, so its frame does not load until someone opens the tab. Every tab except Overview became one of these:

<div data-tabs-target="panel" data-tab="logs" hidden>
  <%= turbo_frame_tag dom_id(@application, :section_logs),
        src: application_section_path(@application, :logs, request.query_parameters),
        loading: :lazy, target: "_top" do %>
    <p class="text-xs py-4">Loading…</p>
  <% end %>
</div>

The frames are served by a new REST resource, GET /applications/:id/sections/:id, with an allowlist of sections and the role each one requires. That fixed something besides speed. Before, settings tabs were hidden from viewers by the view template. Now the server checks the role on every section request. target: "_top" makes a form inside a lazy section redirect the whole page, so saving an environment variable still lands you on the right tab with its flash message. Passing the query string through kept deep links working; a test caught that regression before I shipped it.

In development the app page went to 46 queries and about 112 ms.

Queries that grow with history

The last cause explains “slower over time.” The applications list and the dashboard both used includes(:deploys) to show each app’s latest deploy. Eager loading is the standard cure for N+1, but it loads the entire association you name, so every deploy of every app ever made came back on every request. With little history it costs nothing visible. A year of deploys would make it the slowest thing on the page.

Railyard already had a better helper. It fetches each app’s latest, currently serving and last released deploy with DISTINCT ON (application_id): three queries, however much history exists.

# before: every deploy of every app
apps = team_applications.active.includes(:server, :app_processes, :deploys).to_a

# after: three queries, one row per app each
apps = team_applications.active.includes(:server, :app_processes).to_a
Application.preload_deploys(apps)

def self.preload_deploys(apps)
  latest = ->(scope) do
    scope.where(application_id: apps.map(&:id))
         .select("DISTINCT ON (application_id) deploys.*")
         .reorder(:application_id, created_at: :desc).index_by(&:application_id)
  end
  newest, serving = latest.(Deploy), latest.(Deploy.serving)
  apps.each { |app| app.preloaded_deploys = { latest: newest[app.id], serving: serving[app.id] } }
end

I wrote a test that loads the list with 30 old deploys and then 60, and asserts the same number of deploy rows come back each time. The old code fails it, 34 rows against 64. The same change stopped the deploy page from eager-loading every log line it only ever polls for as JSON, and cached failed GitHub branch lookups. An app with a broken token had been calling GitHub, with 5- and 15-second timeouts, on every page render.

Reading that code also turned up a bug: def team_applications = current_membership&.applications || team_applications. For a user with no membership it calls itself until the stack overflows. Nobody had hit it because every user had a membership. It now falls back to Application.none.

After

All of it went out that afternoon. I compared the 30 minutes before the deploy with the first 10 minutes after, using the same log script and the same cable count:

Solid Cable went from 4,779 messages in 30 minutes (3,439 of them log lines) to 45 in 10 minutes, with zero log lines.
The dashboard’s p50 went from 1,674 ms to 15 ms.
The log-sources call went from running on every app page view to zero until someone opens Logs.
Memory available on the box went from 400 MB to 682 MB.

Traffic right after a deploy is thin, and the page timings are small samples. The dashboard figure comes from two requests, 15 ms and 972 ms, and the first app page view after the restart took 848 ms on a cold process. Tabs now load on demand at a p50 of 75 ms each. The cable count, the missing log calls and the memory figure do not depend on sample size.

Is Rails the cost driver

A slow Rails dashboard invites the question of whether Rails was the wrong choice. I spent part of that day on it, and the answer from the data is no. Dashboard traffic is a few people clicking around. None of the five causes was Ruby executing slowly. All five were work done when nobody needed it: a build on the wrong machine, a log stream for an invisible tab, metric points for charts nobody had open, fourteen tabs rendered for nobody, a whole table of history loaded to show one row.

What does grow is the work the control plane does per server: heartbeats, metric points, log lines, health probes, recurring sweeps. That cost scales with servers times streams, and it is where a Ruby process on a small box runs out first. Ruby’s gRPC server uses a thread per call and shares one interpreter lock, while a Go process can hold tens of thousands of streams on the same hardware. My plan is to move only those hot paths to Go when the server count calls for it: a small gateway that terminates agent streams, batches heartbeats and metrics and writes them in bulk, while Rails keeps every piece of product logic. Solid Cable stays, because at 45 messages in ten minutes it has nothing left to prove.

Before rewriting anything there is more Ruby to fix. A few controller actions still call the agent inside a web request and hold a Puma thread for the whole call, and those move to background jobs next. YJIT and jemalloc were already on, so the remaining speed comes from doing less.

The script that deploys Railyard now refuses to build on the machine it deploys to unless I tell it to.