add report_after_job_retries support for ActiveJob #2500

modosc · 2024-12-18T16:28:43Z

Description

this pr adds report_after_job_retries support to ActiveJob (configured via config.rails.active_job_report_after_job_retries).

the easiest way to do this would have been to use retry_on in the base ActiveJob class (similar to here) but that's difficult to do properly which is (i think) why the current ActiveJob integration doesn't do it.

instead we can take advantage of the retry_stopped.active_job notification that's published when a job runs out of retries. this makes our setup a single call to ActiveSupport::Notifications.subscribe.

fixes #2499

codecov · 2024-12-18T16:35:40Z

Codecov Report

Attention: Patch coverage is 65.00000% with 7 lines in your changes missing coverage. Please review.

Project coverage is 96.99%. Comparing base (a1d2941) to head (f8a24b2).
Report is 48 commits behind head on master.

Files with missing lines	Patch %	Lines
sentry-rails/lib/sentry/rails/active_job.rb	53.33%	7 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #2500      +/-   ##
==========================================
- Coverage   98.16%   96.99%   -1.18%     
==========================================
  Files         128      126       -2     
  Lines        4847     4787      -60     
==========================================
- Hits         4758     4643     -115     
- Misses         89      144      +55

Components	Coverage Δ
sentry-ruby	`98.57% <ø> (ø)`
sentry-rails	`87.26% <65.00%> (-9.81%)`	⬇️
sentry-sidekiq	`97.09% <ø> (ø)`
sentry-resque	`92.85% <ø> (ø)`
sentry-delayed_job	`95.65% <ø> (ø)`
sentry-opentelemetry	`99.31% <ø> (+0.68%)`	⬆️

Files with missing lines	Coverage Δ
sentry-rails/lib/sentry/rails/configuration.rb	`95.45% <100.00%> (-4.55%)`	⬇️
sentry-rails/lib/sentry/rails/railtie.rb	`87.95% <100.00%> (-10.80%)`	⬇️
sentry-rails/lib/sentry/rails/active_job.rb	`87.71% <53.33%> (-12.29%)`	⬇️

... and 10 files with indirect coverage changes

🚀 New features to boost your workflow:

❄ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

sl0thentr0py · 2025-01-13T09:48:57Z

@solnic could you review and get this merged if you have time?

solnic · 2025-01-20T12:05:50Z

@sl0thentr0py looking into it today

solnic

I've been digging into this and I don't think it works as expected and the test results are misleading. The spec actually ends up with 3 errors logged and I do not understand how it happens.

I added this pp statement to the spec:

    context "when active_job_report_after_job_retries is true" do
      before do
        Sentry.configuration.rails.active_job_report_after_job_retries = true
      end

      after do
        Sentry.configuration.rails.active_job_report_after_job_retries = false
      end

      it "reports 1 exception" do
        assert_performed_jobs 3 do
          FailedJobWithRetryOn.perform_later rescue nil
        end

        pp transport.events.first.exception.values

        expect(Sentry::Rails::ActiveJobExtensions::SentryReporter)
          .to have_received(:capture_exception)
          .exactly(1).times
      end

and here's the output:

[#<Sentry::SingleExceptionInterface @type="FailedJob::TestError", @value="Boom! (FailedJob::TestError)", @module="FailedJob", @thread_id=12700, @mechanism=#<Sentry::Mechanism:0x0000ffff6340aa70 @type="rails", @handled=false>>,
 #<Sentry::SingleExceptionInterface @type="FailedJob::TestError", @value="Boom! (FailedJob::TestError)", @module="FailedJob", @thread_id=12700, @mechanism=#<Sentry::Mechanism:0x0000ffff6340aa70 @type="rails", @handled=false>>,
 #<Sentry::SingleExceptionInterface @type="FailedJob::TestError", @value="Boom! (FailedJob::TestError)", @module="FailedJob", @thread_id=12700, @mechanism=#<Sentry::Mechanism:0x0000ffff6340aa70 @type="rails", @handled=false>>]

Any ideas what is reporting these errors? It happens regardless if we use mocks or not.

modosc · 2025-01-21T23:29:02Z

@solnic which version of rails / ruby are you testing against? in the automated tests i see seemingly random counts in the failures:

64
127
111
60
33

note that i only used expect(Sentry::Rails::ActiveJobExtensions::SentryReporter) because i got similar results using expect(transport.events.size).to eq - i just assumed i was doing something else wrong.

it's also possible that the event publishing changed in between rails versions? if that's the case then i think we'd have to use the other approach i mentioned.

also fwiw i can confirm that subscribing to this event and sending an error to sentry does perform as expected in rails 8.0.1 / ruby 3.4.1 (we're using this now in production at my workplace) so it's quite possible the issue lies in the test tooling (maybe assert_performed_jobs runs in a separate thread or something)?

solnic · 2025-01-22T14:04:37Z

also fwiw i can confirm that subscribing to this event and sending an error to sentry does perform as expected in rails 8.0.1 / ruby 3.4.1 (we're using this now in production at my workplace) so it's quite possible the issue lies in the test tooling (maybe assert_performed_jobs runs in a separate thread or something)?

It fails when I run both scenarios, passes when I run individually:

     reports 3 exceptions
    when active_job_report_after_job_retries is true
      reports 1 exception (FAILED - 1)

Failures:

  1) ActiveJob integration active_job_report_after_job_retries when active_job_report_after_job_retries is true reports 1 exception
     Failure/Error:
       expect(Sentry::Rails::ActiveJobExtensions::SentryReporter)
         .to have_received(:capture_exception)
         .exactly(1).times
     
       (Sentry::Rails::ActiveJobExtensions::SentryReporter (class)).capture_exception(*(any args))
           expected: 1 time with any arguments
           received: 2 times with any arguments
     # ./spec/sentry/rails/activejob_spec.rb:425:in `block (4 levels) in <top (required)>'
     # /usr/local/rvm/gems/default/gems/rspec-retry-0.6.2/lib/rspec/retry.rb:124:in `block in run'
     # /usr/local/rvm/gems/default/gems/rspec-retry-0.6.2/lib/rspec/retry.rb:110:in `run'
     # /usr/local/rvm/gems/default/gems/rspec-retry-0.6.2/lib/rspec_ext/rspec_ext.rb:12:in `run_with_retry'
     # /usr/local/rvm/gems/default/gems/rspec-retry-0.6.2/lib/rspec/retry.rb:37:in `block (2 levels) in setup'

Finished in 0.28003 seconds (files took 0.76855 seconds to load)
2 examples, 1 failure

Failed examples:

rspec ./spec/sentry/rails/activejob_spec.rb:420 # ActiveJob integration active_job_report_after_job_retries when active_job_report_after_job_retries is true reports 1 exception

This is latest rails and latest ruby.

solnic · 2025-01-22T14:06:25Z

This is SO strange. When I run all tests from that file I get this:

       (Sentry::Rails::ActiveJobExtensions::SentryReporter (class)).capture_exception(*(any args))
           expected: 1 time with any arguments
           received: 23 times with any arguments

So it's like we get rspec's mocked calls count from all tests, and they just leak between the spec runs 🙈

solnic · 2025-03-10T14:57:58Z

Closing this in favor of #2573 where I fixed issues with specs and handling of AS notification

This has been around the houses a little recently in [sentry-ruby]: - [#2500] - [#2573] - [#2617] but the TLDR seems to be we should enable a configuration option `active_job_report_on_retry_error` if we want to report errors when jobs are retried in `ActiveJob`. This enables the configuration. We want to do this, because it gives us better observablity of when things are going wrong (e.g we're not sending OTP emails due to errors). [sentry-ruby]: https://github.com/getsentry/sentry-ruby [#2500]: getsentry/sentry-ruby#2500 [#2573]: getsentry/sentry-ruby#2573 [#2617]: getsentry/sentry-ruby#2617

modosc force-pushed the active-job-report_after_job_retries branch from 5ecd340 to 2be327a Compare December 18, 2024 16:31

modosc force-pushed the active-job-report_after_job_retries branch from 79897d2 to 0ce620d Compare December 18, 2024 16:39

modosc changed the title ~~add report_after_job_retries support for activejob~~ add report_after_job_retries support for ActiveJob Dec 18, 2024

modosc mentioned this pull request Dec 18, 2024

implement report_after_job_retries in ActiveJob adapter #2499

Closed

modosc closed this Dec 18, 2024

sl0thentr0py reopened this Dec 19, 2024

sl0thentr0py self-requested a review December 19, 2024 06:47

sl0thentr0py self-assigned this Dec 19, 2024

modosc added 9 commits January 10, 2025 16:12

add report_after_job_retries support for activejob

2f59090

require configuration

62bdc4d

handle already_supported_by_sentry_integration

3c2f78a

copy other logic

dd2a2f5

changelog

b243abb

changelog

d495c11

flatten configuration to rails.actibve_job_report_after_job_retries

08d3b40

add config default / spec

6d0cc35

add tests

daee3d8

modosc force-pushed the active-job-report_after_job_retries branch from 923d2d3 to daee3d8 Compare January 11, 2025 00:14

skip retry_on tests with rails < 5.1

b069570

sl0thentr0py assigned solnic and unassigned sl0thentr0py Jan 13, 2025

sl0thentr0py requested a review from solnic January 13, 2025 09:49

modosc added 2 commits January 13, 2025 08:49

move class declaration into rail > 5.1 block

8c05200

try a different way

f8a24b2

solnic reviewed Jan 20, 2025

View reviewed changes

solnic mentioned this pull request Mar 6, 2025

[active_job] support exception reporting only after last retry failed #2573

Merged

solnic closed this Mar 10, 2025

solnic mentioned this pull request May 5, 2025

Introduce active_job_report_on_retry_error #2617

Merged

cpjmcquillan mentioned this pull request Jul 21, 2025

Report errors to Sentry even when jobs are retried DFE-Digital/register-early-career-teachers-public#981

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

add report_after_job_retries support for ActiveJob #2500

add report_after_job_retries support for ActiveJob #2500

Uh oh!

modosc commented Dec 18, 2024 •

edited

Loading

Uh oh!

codecov bot commented Dec 18, 2024 •

edited

Loading

Uh oh!

sl0thentr0py commented Jan 13, 2025

Uh oh!

solnic commented Jan 20, 2025

Uh oh!

solnic left a comment

Uh oh!

modosc commented Jan 21, 2025

Uh oh!

solnic commented Jan 22, 2025

Uh oh!

solnic commented Jan 22, 2025

Uh oh!

solnic commented Mar 10, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Uh oh!

add report_after_job_retries support for ActiveJob #2500

add report_after_job_retries support for ActiveJob #2500

Uh oh!

Conversation

modosc commented Dec 18, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Uh oh!

codecov bot commented Dec 18, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

sl0thentr0py commented Jan 13, 2025

Uh oh!

solnic commented Jan 20, 2025

Uh oh!

solnic left a comment

Choose a reason for hiding this comment

Uh oh!

modosc commented Jan 21, 2025

Uh oh!

solnic commented Jan 22, 2025

Uh oh!

solnic commented Jan 22, 2025

Uh oh!

solnic commented Mar 10, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

modosc commented Dec 18, 2024 •

edited

Loading

codecov bot commented Dec 18, 2024 •

edited

Loading