diff --git a/.changesets/fix-garbage-collection-profiler.md b/.changesets/fix-garbage-collection-profiler.md new file mode 100644 index 000000000..1a91d8185 --- /dev/null +++ b/.changesets/fix-garbage-collection-profiler.md @@ -0,0 +1,6 @@ +--- +bump: "patch" +type: "fix" +--- + +Fix the MRI probe using the Garbage Collection profiler instead of the NilProfiler when garbage collection instrumentation is not enabled for MRI probe. This caused unnecessary overhead. diff --git a/lib/appsignal.rb b/lib/appsignal.rb index 5a2d678c9..2ca8ccf76 100644 --- a/lib/appsignal.rb +++ b/lib/appsignal.rb @@ -298,7 +298,7 @@ def collect_environment_metadata require "appsignal/probes" require "appsignal/marker" require "appsignal/minutely" -require "appsignal/garbage_collection_profiler" +require "appsignal/garbage_collection" require "appsignal/integrations/railtie" if defined?(::Rails) require "appsignal/transaction" require "appsignal/version" diff --git a/lib/appsignal/garbage_collection.rb b/lib/appsignal/garbage_collection.rb new file mode 100644 index 000000000..3d7865826 --- /dev/null +++ b/lib/appsignal/garbage_collection.rb @@ -0,0 +1,81 @@ +# frozen_string_literal: true + +module Appsignal + # @api private + module GarbageCollection + # Return the GC profiler wrapper. + # + # Returns {Profiler} if `enable_gc_instrumentation` is enabled and + # {NilProfiler} if it is disabled. + # + # GC profiling is disabled by default due to the overhead it causes. Do not + # enable this in production for long periods of time. + def self.profiler(appsignal = Appsignal) + @profiler ||= + if appsignal.config[:enable_gc_instrumentation] + Profiler.new + else + NilProfiler.new + end + end + + # Unset the currently cached profiler + # + # @return [void] + def self.clear_profiler! + @profiler = nil + end + + # A wrapper around Ruby's `GC::Profiler` that tracks garbage collection + # time, while clearing `GC::Profiler`'s total_time to make sure it doesn't + # leak memory by keeping garbage collection run samples in memory. + class Profiler + def self.lock + @lock ||= Mutex.new + end + + def initialize + @total_time = 0 + end + + # Whenever {#total_time} is called, the current `GC::Profiler#total_time` + # gets added to `@total_time`, after which `GC::Profiler.clear` is called + # to prevent it from leaking memory. A class-level lock is used to make + # sure garbage collection time is never counted more than once. + # + # Whenever `@total_time` gets above two billion milliseconds (about 23 + # days), it's reset to make sure the result fits in a signed 32-bit + # integer. + # + # @return [Integer] + def total_time + lock.synchronize do + @total_time += (internal_profiler.total_time * 1000).round + internal_profiler.clear + end + + @total_time = 0 if @total_time > 2_000_000_000 + + @total_time + end + + private + + def internal_profiler + GC::Profiler + end + + def lock + self.class.lock + end + end + + # A dummy profiler that always returns 0 as the total time. Used when GC + # profiler is disabled. + class NilProfiler + def total_time + 0 + end + end + end +end diff --git a/lib/appsignal/garbage_collection_profiler.rb b/lib/appsignal/garbage_collection_profiler.rb deleted file mode 100644 index df02f7356..000000000 --- a/lib/appsignal/garbage_collection_profiler.rb +++ /dev/null @@ -1,61 +0,0 @@ -# frozen_string_literal: true - -module Appsignal - # {Appsignal::GarbageCollectionProfiler} wraps Ruby's `GC::Profiler` to be - # able to track garbage collection time for multiple transactions, while - # constantly clearing `GC::Profiler`'s total_time to make sure it doesn't - # leak memory by keeping garbage collection run samples in memory. - # - # @api private - class GarbageCollectionProfiler - def self.lock - @lock ||= Mutex.new - end - - def initialize - @total_time = 0 - end - - # Whenever {#total_time} is called, the current `GC::Profiler#total_time` - # gets added to `@total_time`, after which `GC::Profiler.clear` is called - # to prevent it from leaking memory. A class-level lock is used to make - # sure garbage collection time is never counted more than once. - # - # Whenever `@total_time` gets above two billion milliseconds (about 23 - # days), it's reset to make sure the result fits in a signed 32-bit - # integer. - # - # @return [Integer] - def total_time - lock.synchronize do - @total_time += (internal_profiler.total_time * 1000).round - internal_profiler.clear - end - - @total_time = 0 if @total_time > 2_000_000_000 - - @total_time - end - - private - - def internal_profiler - GC::Profiler - end - - def lock - self.class.lock - end - end - - # {Appsignal::NilGarbageCollectionProfiler} is a dummy profiler - # that always returns 0 as the total time. - # Used when we don't want any profile information - # - # @api private - class NilGarbageCollectionProfiler - def total_time - 0 - end - end -end diff --git a/lib/appsignal/probes/mri.rb b/lib/appsignal/probes/mri.rb index b7a86502c..34e8a9dd5 100644 --- a/lib/appsignal/probes/mri.rb +++ b/lib/appsignal/probes/mri.rb @@ -8,7 +8,7 @@ def self.dependencies_present? defined?(::RubyVM) && ::RubyVM.respond_to?(:stat) end - def initialize(appsignal: Appsignal, gc_profiler: Appsignal::GarbageCollectionProfiler.new) + def initialize(appsignal: Appsignal, gc_profiler: Appsignal::GarbageCollection.profiler) Appsignal.logger.debug("Initializing VM probe") @appsignal = appsignal @gc_profiler = gc_profiler diff --git a/lib/appsignal/transaction.rb b/lib/appsignal/transaction.rb index 185328f85..13521b70f 100644 --- a/lib/appsignal/transaction.rb +++ b/lib/appsignal/transaction.rb @@ -68,8 +68,7 @@ def clear_current_transaction! end def garbage_collection_profiler - @garbage_collection_profiler ||= - Appsignal.config[:enable_gc_instrumentation] ? Appsignal::GarbageCollectionProfiler.new : NilGarbageCollectionProfiler.new + Appsignal::GarbageCollection.profiler end end diff --git a/spec/lib/appsignal/garbage_collection_profiler_spec.rb b/spec/lib/appsignal/garbage_collection_spec.rb similarity index 59% rename from spec/lib/appsignal/garbage_collection_profiler_spec.rb rename to spec/lib/appsignal/garbage_collection_spec.rb index ab3f4f0ff..0c960db8b 100644 --- a/spec/lib/appsignal/garbage_collection_profiler_spec.rb +++ b/spec/lib/appsignal/garbage_collection_spec.rb @@ -1,4 +1,34 @@ -describe Appsignal::GarbageCollectionProfiler do +describe Appsignal::GarbageCollection do + describe ".profiler" do + let(:appsignal) { class_double("Appsignal") } + before do + # Unset the internal memoized variable to avoid state leaking + described_class.clear_profiler! + end + + context "when GC instrumentation is disabled" do + let(:config) { Appsignal::Config.new("production", Dir.pwd, :enable_gc_instrumentation => false) } + + it "returns the NilProfiler" do + allow(appsignal).to receive(:config).and_return(config) + + expect(described_class.profiler(appsignal)).to be_a(Appsignal::GarbageCollection::NilProfiler) + end + end + + context "when GC profiling is enabled" do + let(:config) { Appsignal::Config.new("production", Dir.pwd, :enable_gc_instrumentation => true) } + + it "returns the Profiler" do + allow(appsignal).to receive(:config).and_return(config) + + expect(described_class.profiler(appsignal)).to be_a(Appsignal::GarbageCollection::Profiler) + end + end + end +end + +describe Appsignal::GarbageCollection::Profiler do let(:internal_profiler) { FakeGCProfiler.new } let(:profiler) { described_class.new } @@ -52,7 +82,7 @@ 2.times do threads << Thread.new do - profiler = Appsignal::GarbageCollectionProfiler.new + profiler = Appsignal::GarbageCollection::Profiler.new results << profiler.total_time end end @@ -63,7 +93,7 @@ end end -describe Appsignal::NilGarbageCollectionProfiler do +describe Appsignal::GarbageCollection::NilProfiler do let(:profiler) { described_class.new } describe "#total_time" do diff --git a/spec/lib/appsignal/transaction_spec.rb b/spec/lib/appsignal/transaction_spec.rb index c90a6f63d..fe3ad081b 100644 --- a/spec/lib/appsignal/transaction_spec.rb +++ b/spec/lib/appsignal/transaction_spec.rb @@ -792,23 +792,6 @@ def to_s end end - describe "#garbage_collection_profiler" do - before { Appsignal::Transaction.instance_variable_set(:@garbage_collection_profiler, nil) } - - it "returns the NilGarbageCollectionProfiler" do - expect(Appsignal::Transaction.garbage_collection_profiler).to be_a(Appsignal::NilGarbageCollectionProfiler) - end - - context "when gc profiling is enabled" do - before { Appsignal.config.config_hash[:enable_gc_instrumentation] = true } - after { Appsignal.config.config_hash[:enable_gc_instrumentation] = false } - - it "returns the GarbageCollectionProfiler" do - expect(Appsignal::Transaction.garbage_collection_profiler).to be_a(Appsignal::GarbageCollectionProfiler) - end - end - end - describe "#start_event" do it "starts the event in the extension" do expect(transaction.ext).to receive(:start_event).with(0).and_call_original