From e8f7b62752a65e33aa1cee748fc966c4ad14b1ee Mon Sep 17 00:00:00 2001 From: Alan Guo Xiang Tan Date: Wed, 2 Aug 2023 09:16:32 +0800 Subject: [PATCH] DEV: Add site setting to allow collection of GC stats during requests (#22898) What does this change do? This change adds a hidden `track_gc_stat_per_request` site setting which when enabled will track the time spent in GC, major GC count and minor GC count during a request. Why is this change needed? We have plans to tune our GC in production but without any instrumentation, we will not be able to know if our tuning is effective or not. This commit takes the first step at instrumenting some basic GC stats in core during a request which can then be consumed by the discourse-prometheus plugin. --- config/site_settings.yml | 3 +++ lib/method_profiler.rb | 20 ++++++++++++++++++-- spec/lib/method_profiler_spec.rb | 20 ++++++++++++++++++++ 3 files changed, 41 insertions(+), 2 deletions(-) diff --git a/config/site_settings.yml b/config/site_settings.yml index 3196e8a10bd..27b6558b0ae 100644 --- a/config/site_settings.yml +++ b/config/site_settings.yml @@ -2148,6 +2148,9 @@ developer: max_sidebar_section_links: default: 50 hidden: true + track_gc_stat_per_request: + default: false + hidden: true navigation: navigation_menu: diff --git a/lib/method_profiler.rb b/lib/method_profiler.rb index aa0836278dc..221f26f14d6 100644 --- a/lib/method_profiler.rb +++ b/lib/method_profiler.rb @@ -89,8 +89,13 @@ class MethodProfiler end def self.start(transfer = nil) - Thread.current[:_method_profiler] = transfer || - { __start: Process.clock_gettime(Process::CLOCK_MONOTONIC) } + Thread.current[:_method_profiler] = if transfer + transfer + else + data = { __start: Process.clock_gettime(Process::CLOCK_MONOTONIC) } + data[:gc_stat] = GC.stat if SiteSetting.track_gc_stat_per_request + data + end end def self.clear @@ -99,11 +104,22 @@ class MethodProfiler def self.stop finish = Process.clock_gettime(Process::CLOCK_MONOTONIC) + if data = Thread.current[:_method_profiler] Thread.current[:_method_profiler] = nil start = data.delete(:__start) data[:total_duration] = finish - start + + if start_gc_stat = data.delete(:gc_stat) + end_gc_stat = GC.stat + + data[:gc] ||= {} + data[:gc][:time] = (end_gc_stat[:time] - start_gc_stat[:time]) / 1000.0 + data[:gc][:major_count] = end_gc_stat[:major_gc_count] - start_gc_stat[:major_gc_count] + data[:gc][:minor_count] = end_gc_stat[:minor_gc_count] - start_gc_stat[:minor_gc_count] + end end + data end diff --git a/spec/lib/method_profiler_spec.rb b/spec/lib/method_profiler_spec.rb index 408a52defb5..4324c3ccdb7 100644 --- a/spec/lib/method_profiler_spec.rb +++ b/spec/lib/method_profiler_spec.rb @@ -37,4 +37,24 @@ RSpec.describe MethodProfiler do expect(result[:at_beach][:calls]).to eq(2) end + + it "profiles GC stat information when `track_gc_stat_per_request` site setting has been enabled" do + MethodProfiler.start + GC.start(full_mark: false) # Minor GC + result = MethodProfiler.stop + + expect(result[:gc]).not_to be_present + + SiteSetting.track_gc_stat_per_request = true + + MethodProfiler.start + GC.start(full_mark: true) # Major GC + GC.start(full_mark: false) # Minor GC + result = MethodProfiler.stop + + expect(result[:gc]).to be_present + expect(result[:gc][:time]).to be >= 0.0 + expect(result[:gc][:major_count]).to eq(1) + expect(result[:gc][:minor_count]).to eq(1) + end end