Draft: Instrument GVL wait time in Puma processes
What does this MR do and why?
The GVL timers were only ever enabled from the Sidekiq server middleware, so gvl_thread_wait_s appeared in Sidekiq logs alone. The rest of the plumbing is already runtime-neutral:
Gitlab::Middleware::RequestContexttakes the thread timer baseline for every Rack request.InstrumentationHelper#add_instrumentation_dataalready writes the field into both the Rails (lograge) and Grape log payloads.
So this only reconciles the timers from Gitlab::Middleware::RequestContext as well. Web and API request logs then carry gvl_thread_wait_s, and RubySampler reports ruby_gvl_wait_seconds from Puma workers.
The toggle moves into Gitlab::Instrumentation::Gvl because both call sites have to enable the same pair: the thread timer feeds the log field, and the process timer feeds ruby_gvl_wait_seconds.
Why a separate ops flag
Puma gets enable_puma_gvl_metrics rather than sharing enable_sidekiq_gvl_metrics. The gem documents a 1-5% slowdown on a saturated multi-threaded process, and web latency and background job throughput deserve separate rollout control. A single :current_pod-scoped flag cannot express "web pods only", because a percentage rollout over pods is not selectable by runtime.
Reading the numbers
GVL wait counts thread-seconds, not elapsed time, so a process with several busy threads accumulates it faster than real time. Both timeslice preemption of CPU-bound work and re-acquisition after a blocking region contribute. Measured locally with four purely CPU-bound threads on Ruby 3.3: each accumulated ~2.23s of wait over 3.5s of wall clock, 9.0s in total, which is the ~3/4-of-the-time-waiting you would predict for four threads sharing one lock.
References
- Rollout issue for
enable_puma_gvl_metrics: #622752 - Depends on !251874 (merged), which this MR targets.
- Rollout issue for the Sidekiq ops flag: #577455
- Merge request that added the Sidekiq GVL instrumentation: !209086 (merged)
Screenshots or screen recordings
Not applicable, no user interface changes.
How to set up and validate locally
-
Enable the ops flag in the Rails console:
Feature.enable(:enable_puma_gvl_metrics) -
Restart Puma so it picks up the branch, and give it a moment to boot:
gdk restart rails-web -
Make a few requests. Any page works;
/-/livenessavoids needing Gitaly:for i in $(seq 1 5); do curl -s -o /dev/null -w "%{http_code} " https://gdk.test:3000/-/liveness; done -
Web request logs carry the field. In development the lograge output is
development_json.log:grep -o '"gvl_thread_wait_s":[0-9.e-]*' log/development_json.log | tail -5Expected, one entry per request:
"gvl_thread_wait_s":0.008686 "gvl_thread_wait_s":2.9e-05 -
API request logs carry the field too, through the Grape logger rather than lograge:
curl -s -o /dev/null https://gdk.test:3000/api/v4/projects?per_page=1 grep -o '"gvl_thread_wait_s":[0-9.e-]*' log/api_json.log | tail -3 -
The sampler now reports from Puma.
RubySamplerruns every 60s, so allow a minute after boot:curl -s https://gdk.test:3000/-/metrics | grep ruby_gvl_wait_secondsExpected, one series per Puma worker, increasing on repeated calls:
ruby_gvl_wait_seconds{pid="puma_0"} 0.020961 ruby_gvl_wait_seconds{pid="puma_1"} 0.018675 -
The process field is still absent from web logs, as removed in the parent MR. This should return nothing:
grep -c 'gvl_process_wait_s' log/development_json.log log/api_json.log -
Disabling the flag stops the instrumentation without a restart. The flag is reconciled per request, so the field disappears from log lines written after the next request:
Feature.disable(:enable_puma_gvl_metrics)curl -s -o /dev/null https://gdk.test:3000/-/liveness tail -1 log/development_json.log | grep -c gvl_thread_wait_s # expect 0 -
Sidekiq is unaffected. With
enable_sidekiq_gvl_metricsoff andenable_puma_gvl_metricson, Sidekiq job logs should still have nogvl_thread_wait_s, confirming the two flags are independent.
MR acceptance checklist
Evaluate this MR against the MR acceptance checklist. It helps you analyze changes to reduce risks in quality, performance, reliability, security, and maintainability.