Merge pull request #168 from solarwinds/NH-96740

prepare oboe_metal change for fork change

Author: xuan-cao-swi

CONFIGURATION.md

@@ -69,6 +69,7 @@ or in your initialization step:
 ENV['OTEL_RUBY_INSTRUMENTATION_SINATRA_ENABLED'] = 'false'
 ENV['OTEL_RUBY_INSTRUMENTATION_MYSQL2_CONFIG_OPTS'] = 'db_statement=include;'
 ```
+
 ## Programmatic Configuration
 
 Many OpenTelemetry instrumentation library configurations can be set within the `SolarWindsAPM::OTelConfig.initialize_with_config ... end` block, please consult the individual [instrumentation](https://github.com/open-telemetry/opentelemetry-ruby-contrib/tree/main/instrumentation) README pages for the options available. Note this takes lower precedence than the [environment varable](#instrumentation-libraries) settings.
@@ -128,6 +129,7 @@ Environment Variable | Config File Key | Description | Default
 `SW_APM_TRUSTEDPATH` | N/A | The library uses the host system's default trusted CA certificates to verify the TLS connection to the collector. To override the default, define the trusted certificate path configuration option with an absolute path to a specific trusted certificate file in PEM format. | None
 `SW_APM_LAMBDA_PRELOAD_DEPS` | N/A | This option only takes effect in the AWS Lambda runtime. Set to `false` to disable the attempt to preload function dependencies and install instrumentations. | `true`
 `SW_APM_TRANSACTION_NAME` | N/A | Customize the transaction name for all traces, typically used to target specific instrumented lambda functions. _Precedence order_: custom SDK > `SW_APM_TRANSACTION_NAME` > automatic naming | None
+`SW_APM_ENABLE_AFTER_FORK` | N/A | For background job systems (e.g. resque) that fork child processes as jobs are received. This option delays the library initialization to the start of the child process, to avoid issues associated with gRPC's weak support of forking and cleanup. | false
 N/A | `:log_args` | Enable/disable the collection of URL query parameters, set to boolean false to disable. | true
 N/A | `:log_traceId` | Configure the insertion of trace context into application logs, setting `:traced` would include the available context fields such as trace_id, span_id into log messages. | `:never`
 N/A | `:tracing_mode` | Enable/disable the tracing mode for this service, setting `:disabled` would suppress all trace spans and metrics. | `:enabled`
@@ -181,3 +183,38 @@ end
 ```
 
 Note that with Rails >= 7.1 the comment format can be specified via the `config.active_record.query_log_tags_format` option. SolarWinds Observability functionality depends on the default `:sqlcommenter` format, it is not recommended to change this value.
+
+### Background Jobs
+
+#### Resque
+
+[Resque](https://github.com/resque/resque) is a Redis-backed library for creating background jobs, queuing them on multiple queues, and processing them later.
+
+When starting the Resque worker, it is necessary to set two options: `SW_APM_ENABLE_AFTER_FORK=true` and `RUN_AT_EXIT_HOOKS=1`.
+
+For example:
+
+```console
+SW_APM_ENABLE_AFTER_FORK=true RUN_AT_EXIT_HOOKS=1 QUEUE=${QUEUE_NAME} ${EXTRA_OPTIONS} bundle exec rake resque:work
+```
+
+Explanation:
+
+* `SW_APM_ENABLE_AFTER_FORK`: This option delays initialization of the library's C extension and gRPC-based reporter from the start of the parent worker process to the start of the child process, which is crucial to avoid issues associated with gRPC's weak support of forking and cleanup.
+* `RUN_AT_EXIT_HOOKS`: This option, provided by Resque, ensures that the forked processes shut down gracefully (i.e., no immediate `exit!`).
+
+Additionally, you need to configure the Resque initializer in your Rails application by adding the following code to `config/initializers/resque.rb`. It's recommended to have a upper bound time (e.g. 8 seconds) to avoid infinited loop if something wrong with `solarwinds_apm` initialization.
+
+```ruby
+require 'resque'
+
+Resque.after_fork do
+  unless SolarWindsAPM::API.solarwinds_ready?(8_000)
+    puts "SolarWindsAPM is not ready, this job will not be traced."
+  end
+end
+```
+
+Explanation:
+
+* Since Resque forks a new process for each task, `solarwinds_apm` needs a certain amount of time to complete initialization at the start of each child process [before it is ready to trace](https://github.com/solarwinds/apm-ruby/blob/main/README.md#check-if-solarwinds_apm-is-ready). This `solarwinds_ready?` check in the [`after_fork` hook](https://github.com/resque/resque/blob/master/docs/HOOKS.md) ensures the library is ready for instrumentation to collect metrics and sample for traces.

SECURITY.md

@@ -15,12 +15,15 @@ Our security strategy covers all aspects of our business, including:
 * Data protection
 
 ## Security Documents
+
 [Security Statement](https://www.solarwinds.com/security/security-statement)
 
 [Vendor Data Protection Requirements](https://www.solarwinds.com/security/vendor-data-protection-requirements)
 
 ## Vulnerability Disclosure Policy
+
 [SolarWinds Vulnerability Disclosure Policy](https://www.solarwinds.com/information-security/vulnerability-disclosure-policy)
 
 ## Want to report a security concern?
+
 SolarWinds reviews all reports of security vulnerabilities submitted to it affecting SolarWinds products and services. To report a vulnerability in one of our products or solutions or a vulnerability in one of our corporate websites, please contact our Product Security Incident Response Team (PSIRT) at [psirt@solarwinds.com](mailto:psirt@solarwinds.com).

lib/oboe_metal.rb

@@ -14,9 +14,10 @@ module SolarWindsAPM
   @loaded    = false
   @reporter  = nil
   @oboe_api  = nil
+  @init_sent = false
 
   class << self
-    attr_accessor :reporter, :loaded, :oboe_api
+    attr_accessor :reporter, :loaded, :oboe_api, :init_sent
 
     def sample_rate(rate)
       return unless SolarWindsAPM.loaded
@@ -38,7 +39,7 @@ def start
         options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe # creates an array with the options in the right order
         SolarWindsAPM.reporter = Oboe_metal::Reporter.new(*options)
         SolarWindsAPM.loaded = true
-        report_init
+        report_init if (options[22]).zero? # report init at beginning if no after fork enabled
       rescue StandardError => e
         warn e.message
         SolarWindsAPM.loaded = false
@@ -70,12 +71,15 @@ def send_status(evt, context = nil, with_system_timestamp: true)
       # layer.
       #
       def report_init(layer = :rack) # :nodoc:
-        # Don't send __Init in test or if SolarWindsAPM
-        # isn't fully loaded (e.g. missing c-extension)
+        # Don't send __Init in test or if SolarWindsAPM isn't fully loaded (e.g. missing c-extension)
+        # or if already sent (e.g. SolarWindsAPM.init_sent = true)
+        return if SolarWindsAPM.init_sent
         return unless SolarWindsAPM.loaded
 
         platform_info = build_swo_init_report
         log_init(layer, platform_info)
+
+        SolarWindsAPM.init_sent = true
         SolarWindsAPM.logger.debug { "[#{self.class}/#{__method__}] Init message has been sent." }
       end
 

lib/solarwinds_apm/oboe_init_options.rb

@@ -67,6 +67,8 @@ def initialize
       @metric_format = determine_the_metric_model
       # log type (0 = stderr; 1 = stdout; 2 = file; 3 = null; 4 = disabled; default = 0)
       @log_type = determine_oboe_log_type
+      # after fork enablement (0 = disable; 1 = enabled, parent process will not init oboe but fork child process will init oboe; default = 0)
+      @after_fork = determine_oboe_after_fork
     end
 
     # for testing with changed ENV vars
@@ -97,7 +99,8 @@ def array_for_oboe
         @grpc_proxy,             # 18
         0,                       # 19 arg for lambda (no lambda for ruby yet)
         @metric_format,          # 20
-        @log_type                # 21
+        @log_type,               # 21
+        @after_fork              # 22
       ]
     end
 
@@ -211,5 +214,9 @@ def determine_lambda
         true
       end
     end
+
+    def determine_oboe_after_fork
+      ENV['SW_APM_ENABLE_AFTER_FORK'].to_s == 'true' ? 1 : 0
+    end
   end
 end

lib/solarwinds_apm/opentelemetry/solarwinds_sampler.rb

@@ -55,6 +55,8 @@ def should_sample?(trace_id:, parent_context:, links:, name:, kind:, attributes:
                                         attributes: #{attributes}"
         end
 
+        SolarWindsAPM::Reporter.send(:report_init) # This only happens if after_fork enabled
+
         parent_span_context = ::OpenTelemetry::Trace.current_span(parent_context).context
         xtraceoptions       = ::SolarWindsAPM::XTraceOptions.new(parent_context)
         SolarWindsAPM.logger.debug do

test/run_tests.sh

@@ -66,8 +66,8 @@ for gemfile in "${gemfiles[@]}" ; do
     continue
   fi
   # and here we are finally running the tests!!!
-  BUNDLE_GEMFILE=$gemfile bundle exec rake test
   check_file_name=$gemfile
+  BUNDLE_GEMFILE=$gemfile bundle exec rake test
   check_status
 done
 
@@ -81,8 +81,8 @@ fi
 # for dbo patch test
 PATCH_TEST_FILE=$(find test/patch/*_test.rb -type f)
 for file in $PATCH_TEST_FILE; do
-  BUNDLE_GEMFILE=gemfiles/test_gems.gemfile bundle exec ruby -I test $file
   check_file_name=$file
+  BUNDLE_GEMFILE=gemfiles/test_gems.gemfile bundle exec ruby -I test $file
   check_status
 done
 
@@ -95,8 +95,8 @@ echo "Fake libsolarwinds_apm.so created"
 
 NUMBER_FILE=$(find test/solarwinds_apm/init_test/*_test.rb -type f | wc -l)
 for ((i = 1; i <= $NUMBER_FILE; i++)); do
-  BUNDLE_GEMFILE=gemfiles/test_gems.gemfile bundle exec ruby -I test test/solarwinds_apm/init_test/init_${i}_test.rb
   check_file_name=init_${i}_test.rb
+  BUNDLE_GEMFILE=gemfiles/test_gems.gemfile bundle exec ruby -I test test/solarwinds_apm/init_test/init_${i}_test.rb
   check_status
 done
 

test/solarwinds_apm/oboe_init_options_test.rb

@@ -52,7 +52,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[0]).must_equal 'string_4'
     _(options[1]).must_equal 2
     _(options[2]).must_equal 'string_5'
@@ -94,7 +94,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
 
     _(options[0]).must_equal 'string_0'
     _(options[1]).must_equal 1
@@ -110,7 +110,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[20]).must_equal 2
   end
 
@@ -121,7 +121,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[20]).must_equal 2
   end
 
@@ -132,7 +132,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[20]).must_equal 2
   end
 
@@ -142,7 +142,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[20]).must_equal 2
   end
 
@@ -154,7 +154,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[10]).must_equal "-----BEGIN CERTIFICATE-----\nMIID8TCCAtmgAwIBAgIJAMoDz7Npas2/MA0GCSqGSIb3DQEBCwUAMIGOMQswCQYD\nVQQGEwJVUzETMBEGA1UECAwKQ2FsaWZvcm5pYTEWMBQGA1UEBwwNU2FuIEZyYW5j\naXNjbzEVMBMGA1UECgwMTGlicmF0byBJbmMuMRUwEwYDVQQDDAxBcHBPcHRpY3Mg\nQ0ExJDAiBgkqhkiG9w0BCQEWFXN1cHBvcnRAYXBwb3B0aWNzLmNvbTAeFw0xNzA5\nMTUyMjAxMzlaFw0yNzA5MTMyMjAxMzlaMIGOMQswCQYDVQQGEwJVUzETMBEGA1UE\nCAwKQ2FsaWZvcm5pYTEWMBQGA1UEBwwNU2FuIEZyYW5jaXNjbzEVMBMGA1UECgwM\nTGlicmF0byBJbmMuMRUwEwYDVQQDDAxBcHBPcHRpY3MgQ0ExJDAiBgkqhkiG9w0B\nCQEWFXN1cHBvcnRAYXBwb3B0aWNzLmNvbTCCASIwDQYJKoZIhvcNAQEBBQADggEP\nADCCAQoCggEBAOxO0wsGba3iI4r3L5BMST0rAO/gGaUhpQre6nRwVTmPCnLw1bmn\nGdiFgYv/oRRwU+VieumHSQqoOmyFrg+ajGmvUDp2WqQ0It+XhcbaHFiAp2H7+mLf\ncUH6S43/em0WUxZHeRzRupRDyO1bX6Hh2jgxykivlFrn5HCIQD5Hx1/SaZoW9v2n\noATCbgFOiPW6kU/AVs4R0VBujon13HCehVelNKkazrAEBT1i6RvdOB6aQQ32seW+\ngLV5yVWSPEJvA9ZJqad/nQ8EQUMSSlVN191WOjp4bGpkJE1svs7NmM+Oja50W56l\nqOH5eWermr/8qWjdPlDJ+I0VkgN0UyHVuRECAwEAAaNQME4wHQYDVR0OBBYEFOuL\nKDTFhRQXwlBRxhPqhukrNYeRMB8GA1UdIwQYMBaAFOuLKDTFhRQXwlBRxhPqhukr\nNYeRMAwGA1UdEwQFMAMBAf8wDQYJKoZIhvcNAQELBQADggEBAJQtH446NZhjusy6\niCyvmnD95ybfNPDpjHmNx5n9Y6w9n+9y1o3732HUJE+WjvbLS3h1o7wujGKMcRJn\n7I7eTDd26ZhLvnh5/AitYjdxrtUkQDgyxwLFJKhZu0ik2vXqj0fL961/quJL8Gyp\nhNj3Nf7WMohQMSohEmCCX2sHyZGVGYmQHs5omAtkH/NNySqmsWNcpgd3M0aPDRBZ\n5VFreOSGKBTJnoLNqods/S9RV0by84hm3j6aQ/tMDIVE9VCJtrE6evzC0MWyVFwR\nftgwcxyEq5SkiR+6BCwdzAMqADV37TzXDHLjwSrMIrgLV5xZM20Kk6chxI5QAr/f\n7tsqAxw=\n-----END CERTIFICATE-----"
   end
 
@@ -166,7 +166,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[10]).must_equal ''
   end
 
@@ -177,7 +177,7 @@
     SolarWindsAPM::OboeInitOptions.instance.re_init
     options = SolarWindsAPM::OboeInitOptions.instance.array_for_oboe
 
-    _(options.size).must_equal 22
+    _(options.size).must_equal 23
     _(options[10]).must_equal "-----BEGIN CERTIFICATE-----\nMIID8TCCAtmgAwIBAgIJAMoDz7Npas2/MA0GCSqGSIb3DQEBCwUAMIGOMQswCQYD\n-----END CERTIFICATE-----"
   end
 

test/solarwinds_apm/oboe_metal_test.rb

@@ -29,15 +29,19 @@ def sendReport(*) # rubocop:disable Naming/MethodName
       log_output = StringIO.new
       SolarWindsAPM.logger = Logger.new(log_output)
       SolarWindsAPM.loaded = true
+      SolarWindsAPM.init_sent = false
       SolarWindsAPM::Reporter.send(:report_init, :rack)
       assert_includes log_output.string, 'Init message has been sent.'
+      _(SolarWindsAPM.init_sent).must_equal true
     end
 
     it 'test_reporter_start' do
       log_output = StringIO.new
       SolarWindsAPM.logger = Logger.new(log_output)
+      SolarWindsAPM.init_sent = false
       SolarWindsAPM::Reporter.start
       assert_includes log_output.string, 'Init message has been sent.'
+      _(SolarWindsAPM.init_sent).must_equal true
     end
 
     it 'test_build_swo_init_report_with_error' do