Skip to content

Commit ee9b5be

Browse files
committed
Name Sidekiq delayed enqueues after their target
The server middleware decodes the Sidekiq delayed extensions' YAML payload to name the perform transaction after the real target and method, rather than the internal wrapper class. The client middleware titled the enqueue event with the raw wrapper class instead, so the enqueue and perform of the same delayed job read different names. Extract that name resolution into a `SidekiqActionName` module shared by both middlewares, and title the enqueue event with it. The two sides now agree on the name. Decoding the payload means deserializing YAML on the enqueue path, but that is the same YAML the server middleware already deserializes, and it runs only for delayed extension jobs. At enqueue the payload is the one we just built locally, so it carries no trust or missing-constant risk the perform side isn't already taking.
1 parent 5e9f3e1 commit ee9b5be

3 files changed

Lines changed: 122 additions & 36 deletions

File tree

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,9 @@
1+
---
2+
bump: patch
3+
type: change
4+
---
5+
6+
Title `enqueue.sidekiq` events for Sidekiq delayed extension jobs after the
7+
delayed target and method, such as `enqueue MyClass.my_method job`, instead of
8+
the internal wrapper class. This matches the name the job is given when it
9+
later performs, so the enqueue and perform of the same job read the same name.

lib/appsignal/integrations/sidekiq.rb

Lines changed: 53 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -49,6 +49,55 @@ def call(exception, sidekiq_context, _sidekiq_config = nil)
4949
end
5050
end
5151

52+
# Resolves the name of a Sidekiq job. That's normally the job class, but
53+
# the Sidekiq delayed extensions encode the real target and method as YAML
54+
# in the job's first argument, so those are decoded into a `Target.method`
55+
# (class) or `Target#method` (instance) name.
56+
#
57+
# Shared between the client middleware, which titles the enqueue event with
58+
# it, and the server middleware, which names the perform transaction with
59+
# it. The same job then reads the same name on both sides.
60+
#
61+
# @!visibility private
62+
module SidekiqActionName
63+
module_function
64+
65+
# Based on: https://github.com/mperham/sidekiq/blob/63ee43353bd3b753beb0233f64865e658abeb1c3/lib/sidekiq/api.rb#L316-L334
66+
def parse_action_name(job)
67+
args = job.fetch("args", [])
68+
job_class = job["class"]
69+
case job_class
70+
when "Sidekiq::Extensions::DelayedModel"
71+
safe_load(args[0], job_class) do |target, method, _|
72+
"#{target.class}##{method}"
73+
end
74+
when /\ASidekiq::Extensions::Delayed/
75+
safe_load(args[0], job_class) do |target, method, _|
76+
"#{target}.#{method}"
77+
end
78+
else
79+
job_class
80+
end
81+
end
82+
83+
# Based on: https://github.com/mperham/sidekiq/blob/63ee43353bd3b753beb0233f64865e658abeb1c3/lib/sidekiq/api.rb#L403-L412
84+
def safe_load(content, default)
85+
if Gem::Version.new(YAML::VERSION) >= Gem::Version.new("4.0.0")
86+
yield(*YAML.unsafe_load(content))
87+
else
88+
yield(*YAML.load(content)) # rubocop:disable Security/YAMLLoad
89+
end
90+
rescue => error
91+
# Sidekiq issue #1761: in dev mode, it's possible to have jobs enqueued
92+
# which haven't been loaded into memory yet so the YAML can't be
93+
# loaded.
94+
Appsignal.internal_logger.warn(
95+
"Unable to load YAML from Sidekiq delayed extension job: #{error.message}"
96+
)
97+
default
98+
end
99+
end
100+
52101
# Sidekiq client middleware that runs on enqueue. Records an
53102
# `enqueue.sidekiq` event so the enqueue shows up under the active
54103
# transaction.
@@ -65,7 +114,8 @@ def call(_worker_class, job, _queue, _redis_pool, &block)
65114
return yield if Appsignal::Transaction.current? &&
66115
Appsignal::Transaction.current.job_enqueue_events_suppressed?
67116

68-
Appsignal.instrument("enqueue.sidekiq", "enqueue #{job["class"]} job", &block)
117+
title = "enqueue #{SidekiqActionName.parse_action_name(job)} job"
118+
Appsignal.instrument("enqueue.sidekiq", title, &block)
69119
end
70120
end
71121

@@ -144,7 +194,7 @@ def increment_counter(key, value, tags = {})
144194
end
145195

146196
def formatted_action_name(job)
147-
sidekiq_action_name = parse_action_name(job)
197+
sidekiq_action_name = SidekiqActionName.parse_action_name(job)
148198
return unless sidekiq_action_name
149199

150200
complete_action = sidekiq_action_name =~ /\.|#/
@@ -163,30 +213,12 @@ def formatted_metadata(item)
163213
end
164214
end
165215

166-
# Based on: https://github.com/mperham/sidekiq/blob/63ee43353bd3b753beb0233f64865e658abeb1c3/lib/sidekiq/api.rb#L316-L334
167-
def parse_action_name(job)
168-
args = job.fetch("args", [])
169-
job_class = job["class"]
170-
case job_class
171-
when "Sidekiq::Extensions::DelayedModel"
172-
safe_load(args[0], job_class) do |target, method, _|
173-
"#{target.class}##{method}"
174-
end
175-
when /\ASidekiq::Extensions::Delayed/
176-
safe_load(args[0], job_class) do |target, method, _|
177-
"#{target}.#{method}"
178-
end
179-
else
180-
job_class
181-
end
182-
end
183-
184216
# Based on: https://github.com/mperham/sidekiq/blob/63ee43353bd3b753beb0233f64865e658abeb1c3/lib/sidekiq/api.rb#L336-L358
185217
def parse_arguments(job)
186218
args = job.fetch("args", [])
187219
case job["class"]
188220
when /\ASidekiq::Extensions::Delayed/
189-
safe_load(args[0], args) do |_, _, arg|
221+
SidekiqActionName.safe_load(args[0], args) do |_, _, arg|
190222
arg
191223
end
192224
else
@@ -199,21 +231,6 @@ def parse_arguments(job)
199231
args
200232
end
201233
end
202-
203-
# Based on: https://github.com/mperham/sidekiq/blob/63ee43353bd3b753beb0233f64865e658abeb1c3/lib/sidekiq/api.rb#L403-L412
204-
def safe_load(content, default)
205-
if YAML::VERSION >= "4.0.0"
206-
yield(*YAML.unsafe_load(content))
207-
else
208-
yield(*YAML.load(content)) # rubocop:disable Security/YAMLLoad
209-
end
210-
rescue => error
211-
# Sidekiq issue #1761: in dev mode, it's possible to have jobs enqueued
212-
# which haven't been loaded into memory yet so the YAML can't be
213-
# loaded.
214-
Appsignal.internal_logger.warn "Unable to load YAML: #{error.message}"
215-
default
216-
end
217234
end
218235
end
219236
end

spec/lib/appsignal/integrations/sidekiq_spec.rb

Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -198,6 +198,66 @@ def enqueue
198198
end
199199
end
200200

201+
context "when using the Sidekiq delayed extension" do
202+
let(:job) do
203+
{
204+
"class" => "Sidekiq::Extensions::DelayedClass",
205+
"args" => [
206+
"---\n- !ruby/class 'DelayedTestClass'\n- :foo_method\n- - :bar: baz\n"
207+
]
208+
}
209+
end
210+
211+
it "titles the enqueue event with the delayed class and method name" do
212+
transaction = http_request_transaction
213+
set_current_transaction(transaction)
214+
215+
expect(enqueue).to eq(:enqueued)
216+
217+
event = transaction.to_h["events"].find { |e| e["name"] == "enqueue.sidekiq" }
218+
expect(event["title"]).to eq("enqueue DelayedTestClass.foo_method job")
219+
end
220+
221+
context "when the delayed job arguments are malformed YAML" do
222+
before { job["args"] = [] }
223+
224+
it "logs a warning and titles the enqueue event with the job class" do
225+
transaction = http_request_transaction
226+
set_current_transaction(transaction)
227+
228+
logs = capture_logs { expect(enqueue).to eq(:enqueued) }
229+
230+
event = transaction.to_h["events"].find { |e| e["name"] == "enqueue.sidekiq" }
231+
expect(event["title"]).to eq("enqueue Sidekiq::Extensions::DelayedClass job")
232+
expect(logs).to contains_log(
233+
:warn,
234+
"Unable to load YAML from Sidekiq delayed extension job"
235+
)
236+
end
237+
end
238+
end
239+
240+
context "when using the Sidekiq ActiveRecord instance delayed extension" do
241+
let(:job) do
242+
{
243+
"class" => "Sidekiq::Extensions::DelayedModel",
244+
"args" => [
245+
"---\n- !ruby/object:DelayedTestClass {}\n- :foo_method\n- - :bar: :baz\n"
246+
]
247+
}
248+
end
249+
250+
it "titles the enqueue event with the delayed class and method name" do
251+
transaction = http_request_transaction
252+
set_current_transaction(transaction)
253+
254+
expect(enqueue).to eq(:enqueued)
255+
256+
event = transaction.to_h["events"].find { |e| e["name"] == "enqueue.sidekiq" }
257+
expect(event["title"]).to eq("enqueue DelayedTestClass#foo_method job")
258+
end
259+
end
260+
201261
context "without an active transaction" do
202262
it "passes through without recording" do
203263
expect { |block| plugin.call("TestClass", job, "default", nil, &block) }

0 commit comments

Comments
 (0)