RuntimeError: profile not started from a Sidekiq worker when profiling is enabled (Vernier)

[vittorius]

Issue Description

I have a project that uses sentry-ruby, sentry-rails, and sentry-sidekiq, all of version 5.21.0. When I enable Profiling according to the docs and deploy the application, I start getting the RuntimeError: profile not started from all of my Sidekiq workers

Reproduction Steps

1. Have a project with Sidekiq workers
2. Enable profiling according to the docs using the Vernier profiler
3. Try running workers

Expected Behavior

No errors, profile samples from workers are visible in Sentry UI

Actual Behavior

RuntimeError: profile not started

Ruby Version

3.3.4

SDK Version

5.21.0

Integration and Its Version

Rails 7.1.4.1, Sidekiq 7.1.6, Vernier 1.3.1

Sentry Config

# frozen_string_literal: true

if Global.sentry.enabled?
  Sentry.init do |config|
    config.dsn = Global.sentry.rails
    config.environment = Global.sentry.environment
    config.release = ENV['DEPLOY_SHA'] || 'no-release'

    # post body, cookies, user IP is not sent to Sentry (the default, but we explicitly agree)
    config.send_default_pii = false

    Warden::Manager.after_set_user do |user|
      Sentry.set_user(id: user&.id)
    end

    config.breadcrumbs_logger = %i[sentry_logger http_logger redis_logger active_support_logger]

    config.traces_sample_rate = 1.0
    config.profiles_sample_rate = 1.0
    config.profiler_class = Sentry::Vernier::Profiler

    config.sidekiq.report_after_job_retries = true
  end
end

[solnic]

Thanks for the report. I'll look into this!

[solnic]

I'm having trouble reproducing this exactly, but I did manage to see Vernier breaking when there's more than one worker running. I still need to investigate what exactly causes this. Will report back when I learn more!

[solnic]

Hey @jhawthorn and @mperham - any chance you could help me out here? What I discovered is that when there’s more than one worker running, profiling via Vernier is choking on either “Profile already started” or “profile not started” errors.

On Sentry side, we simply start a transaction which eventually calls Vernier::Profiler#start, then once transaction ends we stop it which eventually calls Venier::Profile#stop.

These two start/stop methods is where we get our crashes about profile either not started yet or already stopped. It seems like when multiple workers are running Vernier is silently failing maybe? Or maybe we’re not handling Vernier start/stop correctly?

I’d appreciate any guidance here 🙏🏻

[mperham]

Are you trying to profile two jobs concurrently in the same process? That sounds like a bad time, which is why the Sidekiq wiki page notes that you really should only profile manually, to keep contention down. You could also target different processes via queue selection.

Retries may automatically deal with this.

[mperham]

I missed the context here. Sidekiq will support Vernier natively in 8.0; it's already on the main branch. I have no knowledge of Sentry's implementation.

https://github.com/sidekiq/sidekiq/wiki/Profiling

PS "getsantry" above ^^^^^ looks very suspicious.

[solnic]

@mperham thank you!

@vittorius we should wait until sidekiq 8.0 is released and try it out, until then there's not much we can do on Sentry side.

[mperham]

My understanding is that Vernier is only designed to run globally. You can’t run it on multiple threads concurrently so I don’t think Sentry’s attempt to automatically profile every job will work. Sidekiq’s documentation explicitly says to only use this feature manually for this reason. Am I misunderstanding Vernier or your usage?

[sl0thentr0py]

@solnic it is fine to profile only one thread at a time and document that limitation.
However, we should fail gracefully in this case and not throw an exception (if we're doing so).

[vittorius]

@solnic thank you for the effort. This doesn't block me actually since it was only an experiment on my project. Good to know anyway.

[solnic]

@sl0thentr0py OK so just catch these errors and log them, yeah?