Clear stale breadcrumbs and context after Sidekiq jobs

[drewish]

The error handler is only called after an exception so the context (specifically breadcrumbs) will carry over from previous jobs that completed successfully.

Fixes #636

I'm not sure this is exactly the way the maintainers would want to approach it but it seems to be working better for me. I'm not using ActiveJob so I don't know if that would play into this.

You can test this out by creating two new sidekiq jobs:

bundle exec rails g sidekiq:worker Happy
bundle exec rails g sidekiq:worker Sad

Then fill in some basic processing logic to have one record breadcrumbs and context:

class HappyWorker
  include Sidekiq::Worker

  def perform(*args)
    Raven.breadcrumbs.record do |crumb|
      crumb.message = "I'm happy!"
    end
    Raven.tags_context mood: 'happy'
  end
end

And the other just raise an exception and doesn't retry

class SadWorker
  include Sidekiq::Worker

  sidekiq_options :retry => false

  def perform(*args)
    raise "I'm sad!"
  end
end

Start up sidekiq with a single thread (so we don't have to worry about which worker picks up which job):

bundle exec sidekiq -c 1

Open up a rails console in another terminal window and queue up a couple of jobs:

HappyWorker.perform_async
HappyWorker.perform_async
SadWorker.perform_async

On the master branch the Sentry issue from SadWorker will include the breadcrumbs and tags from the HappyWorker:

[drewish]

I've provided some pretty detailed testing instructions so hopefully this will be easy enough to review.

[drewish]

Not sure what you think of these names. I was going for explicit to to make the role clear.

[tarmo]

Hi @drewish, did you explicitly also test the case that tags added in SadWorker actually end up recorded in Sentry with the exception raised by it (ie. not leaked tags from previous jobs but those that we intentionally want to report for the current job)?

From some limited testing it seems that the ensure block for SidekiqCleanupMiddleware actually gets called before Sidekiq calls any error handlers so all the context will be gone by the time the exception is reported to Sentry. This is confirmed by both adding debugger calls to the ensure block and exception reporting code and observing the former being called first and also having lost all tags attached to job exception reports after updating to a raven-ruby version containing this change.

[tarmo]

I think it might work if the middleware only cleared context when no exception was raised and the error handler also cleared context. I'll try if that works.

[drewish]

@tarmo Can you say more about how the tags would be provided? I was definitely testing that tags and breadcrumbs from the failed job were being reported. Now specifically it was picking up breadcrumbs from the failed jobs but the extra and tags were being passed in when capturing, e.g. Raven.capture_exception(exception, extra: extra, tags: tags, level: level).

[tarmo]

@drewish if you call Raven.capture_exception from within the job it would certainly work fine because the SidekiqCleanupMiddleware hasn't yet run and cleared the context. The problem only shows if you rely on the SidekiqErrorHandler (https://github.com/getsentry/raven-ruby/blob/master/lib/raven/integrations/sidekiq.rb#L19) to catch raised exceptions and report them with any tags added to Raven.tags_context within the job.

[drewish]

@tarmo Ah okay yeah I wasn't relying on the default capture so I understand the case you're highlighting now. Definitely a shortcoming in my testing.