From 065b5f2d54e68805997133c2e3327e6749211486 Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Fri, 2 Feb 2024 17:35:50 -0500 Subject: [PATCH 01/11] send active support notifications on run events --- README.md | 34 +++++++++++++++++++ app/models/maintenance_tasks/run.rb | 10 ++++++ test/models/maintenance_tasks/run_test.rb | 40 +++++++++++++++++++---- 3 files changed, 77 insertions(+), 7 deletions(-) diff --git a/README.md b/README.md index cd37e2d2..2692dc4a 100644 --- a/README.md +++ b/README.md @@ -449,6 +449,40 @@ module Maintenance def process(post) post.update!(content: "updated content") end + +### Subscribing to instrumentation events + +If you are interested in actioning a specific task event, please refer to the `Task Callbacks` section below. However, if you want to subscribe to all events, irrespective of the task, you can use the following Active Support notifications: + +```ruby +maintenance_tasks.enqueued # This event is published when a task has been enqueued by the user. +maintenance_tasks.succeeded # This event is published when a task has finished without any errors. +maintenance_tasks.cancelled # This event is published when the user explicitly halts the execution of a task. +maintenance_tasks.paused # This event is published when a task is paused by the user in the middle of its run. +maintenance_tasks.errored # This event is published when the task's code produces an unhandled exception. +``` + +These notifications offer a way to monitor the lifecycle of maintenance tasks in your application. + +Usage example: + + ```ruby + ActiveSupport::Notifications.subscribe("maintenance_tasks.enqueued") do |*args| + payload = args.last + run = payload[:run] + run.task_name + run.arguments + run.metadata +end + +# or + +class MaintenanceTasksInstrumenter < ActiveSupport::Subscriber + attach_to :maintenance_tasks + + def enqueued(event) + run = event.payload[:run] + SlackNotifier.broadcast(SLACK_CHANNEL, "Job #{run.task_name} was started by #{run.metadata[:user_email]}} with arguments #{run.arguments.to_s.truncate(255)}") end end ``` diff --git a/app/models/maintenance_tasks/run.rb b/app/models/maintenance_tasks/run.rb index e684fa13..6ed8851d 100644 --- a/app/models/maintenance_tasks/run.rb +++ b/app/models/maintenance_tasks/run.rb @@ -39,6 +39,8 @@ class Run < ApplicationRecord enum status: STATUSES.to_h { |status| [status, status.to_s] } end + after_save :instrument_status_change + validate :task_name_belongs_to_a_valid_task, on: :create validate :csv_attachment_presence, on: :create validate :csv_content_type, on: :create @@ -452,6 +454,14 @@ def task private + def instrument_status_change + return if status.nil? || !status_previously_changed? + + ActiveSupport::Notifications.instrument("maintenance_tasks.#{status}", run: self) + rescue + nil + end + def run_task_callbacks(callback) task.run_callbacks(callback) rescue Task::NotFoundError diff --git a/test/models/maintenance_tasks/run_test.rb b/test/models/maintenance_tasks/run_test.rb index 6904d01e..0e1975f1 100644 --- a/test/models/maintenance_tasks/run_test.rb +++ b/test/models/maintenance_tasks/run_test.rb @@ -74,14 +74,18 @@ class RunTest < ActiveSupport::TestCase ) run.status = :interrupted run.task.expects(:after_interrupt_callback) - run.persist_transition + assert_notification_for("interrupted", run: run) do + run.persist_transition + end end test "#persist_transition calls the complete callback" do run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "running") run.status = :succeeded run.task.expects(:after_complete_callback) - run.persist_transition + assert_notification_for("succeeded", run: run) do + run.persist_transition + end end test "#persist_transition calls the cancel callback" do @@ -91,14 +95,18 @@ class RunTest < ActiveSupport::TestCase ) run.status = :cancelled run.task.expects(:after_cancel_callback) - run.persist_transition + assert_notification_for("cancelled", run: run) do + run.persist_transition + end end test "#persist_transition calls the pause callback" do run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "pausing") run.status = :paused run.task.expects(:after_pause_callback) - run.persist_transition + assert_notification_for("paused", run: run) do + run.persist_transition + end end test "#persist_transition with a race condition moves the run to the proper status and calls the right callback" do @@ -109,7 +117,9 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_cancel_callback) run.status = :interrupted - run.persist_transition + assert_notification_for("cancelled", run: run) do + run.persist_transition + end assert_predicate run.reload, :cancelled? end @@ -121,7 +131,9 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_complete_callback) run.status = :succeeded - run.persist_transition + assert_notification_for("succeeded", run: run) do + run.persist_transition + end assert_predicate run.reload, :succeeded? end @@ -171,7 +183,9 @@ class RunTest < ActiveSupport::TestCase error = ArgumentError.new("Something went wrong") error.set_backtrace(["lib/foo.rb:42:in `bar'"]) run.task.expects(:after_error_callback) - run.persist_error(error) + assert_notification_for("errored", run: run) do + run.persist_error(error) + end end test "#persist_error can handle error callback raising" do @@ -690,6 +704,18 @@ class RunTest < ActiveSupport::TestCase private + def assert_notification_for(name, expected_payload) + payload = nil + + notification = ActiveSupport::Notifications.subscribe("maintenance_tasks.#{name}") do |*args| + payload = args.last + end + yield + ActiveSupport::Notifications.unsubscribe(notification) + + assert_equal(expected_payload, payload) + end + def count_uncached_queries(&block) count = 0 From 94c2c44bfbe72279cc25cbef454e202bcfa52bae Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Tue, 6 Feb 2024 10:07:19 -0500 Subject: [PATCH 02/11] explicitly exclude states from notifications I'm excluding these states as they are easily confused with others and are likely to create confusion: - running vs enqueued - pausing vs paused - cancelling vs cancelled - interrupted vs paused If someone has a valid use case for these states, feel free to revert this commit and add them back --- app/models/maintenance_tasks/run.rb | 1 + test/models/maintenance_tasks/run_test.rb | 5 +---- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/app/models/maintenance_tasks/run.rb b/app/models/maintenance_tasks/run.rb index 6ed8851d..86c7823d 100644 --- a/app/models/maintenance_tasks/run.rb +++ b/app/models/maintenance_tasks/run.rb @@ -456,6 +456,7 @@ def task def instrument_status_change return if status.nil? || !status_previously_changed? + return if running? || pausing? || cancelling? || interrupted? ActiveSupport::Notifications.instrument("maintenance_tasks.#{status}", run: self) rescue diff --git a/test/models/maintenance_tasks/run_test.rb b/test/models/maintenance_tasks/run_test.rb index 0e1975f1..56acf84a 100644 --- a/test/models/maintenance_tasks/run_test.rb +++ b/test/models/maintenance_tasks/run_test.rb @@ -74,9 +74,7 @@ class RunTest < ActiveSupport::TestCase ) run.status = :interrupted run.task.expects(:after_interrupt_callback) - assert_notification_for("interrupted", run: run) do - run.persist_transition - end + run.persist_transition end test "#persist_transition calls the complete callback" do @@ -712,7 +710,6 @@ def assert_notification_for(name, expected_payload) end yield ActiveSupport::Notifications.unsubscribe(notification) - assert_equal(expected_payload, payload) end From 051a2a9110f4c85420f13d2e8655e34eb4b4f46b Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Mon, 12 Feb 2024 08:58:25 -0500 Subject: [PATCH 03/11] use ActiveSupport::Notification.subscribed https://github.com/Shopify/maintenance_tasks/pull/961#discussion_r1480462183 --- test/models/maintenance_tasks/run_test.rb | 21 ++++++++------------- 1 file changed, 8 insertions(+), 13 deletions(-) diff --git a/test/models/maintenance_tasks/run_test.rb b/test/models/maintenance_tasks/run_test.rb index 56acf84a..88cfa39a 100644 --- a/test/models/maintenance_tasks/run_test.rb +++ b/test/models/maintenance_tasks/run_test.rb @@ -81,7 +81,7 @@ class RunTest < ActiveSupport::TestCase run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "running") run.status = :succeeded run.task.expects(:after_complete_callback) - assert_notification_for("succeeded", run: run) do + assert_notification_for("maintenance_tasks.succeeded", run: run) do run.persist_transition end end @@ -93,7 +93,7 @@ class RunTest < ActiveSupport::TestCase ) run.status = :cancelled run.task.expects(:after_cancel_callback) - assert_notification_for("cancelled", run: run) do + assert_notification_for("maintenance_tasks.cancelled", run: run) do run.persist_transition end end @@ -102,7 +102,7 @@ class RunTest < ActiveSupport::TestCase run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "pausing") run.status = :paused run.task.expects(:after_pause_callback) - assert_notification_for("paused", run: run) do + assert_notification_for("maintenance_tasks.paused", run: run) do run.persist_transition end end @@ -115,7 +115,7 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_cancel_callback) run.status = :interrupted - assert_notification_for("cancelled", run: run) do + assert_notification_for("maintenance_tasks.cancelled", run: run) do run.persist_transition end assert_predicate run.reload, :cancelled? @@ -129,7 +129,7 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_complete_callback) run.status = :succeeded - assert_notification_for("succeeded", run: run) do + assert_notification_for("maintenance_tasks.succeeded", run: run) do run.persist_transition end assert_predicate run.reload, :succeeded? @@ -181,7 +181,7 @@ class RunTest < ActiveSupport::TestCase error = ArgumentError.new("Something went wrong") error.set_backtrace(["lib/foo.rb:42:in `bar'"]) run.task.expects(:after_error_callback) - assert_notification_for("errored", run: run) do + assert_notification_for("maintenance_tasks.errored", run: run) do run.persist_error(error) end end @@ -702,14 +702,9 @@ class RunTest < ActiveSupport::TestCase private - def assert_notification_for(name, expected_payload) + def assert_notification_for(name, expected_payload, &block) payload = nil - - notification = ActiveSupport::Notifications.subscribe("maintenance_tasks.#{name}") do |*args| - payload = args.last - end - yield - ActiveSupport::Notifications.unsubscribe(notification) + ActiveSupport::Notifications.subscribed(->(*args) { payload = args.last }, name, &block) assert_equal(expected_payload, payload) end From 107e7c190b7881fb625a077935ebbaab86c43b10 Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Mon, 12 Feb 2024 09:27:47 -0500 Subject: [PATCH 04/11] remove callback monkey patch example --- README.md | 15 --------------- 1 file changed, 15 deletions(-) diff --git a/README.md b/README.md index 2692dc4a..ff4033a8 100644 --- a/README.md +++ b/README.md @@ -537,21 +537,6 @@ end If any of the other callbacks cause an exception, it will be handled by the error handler, and will cause the task to stop running. -Callback behaviour can be shared across all tasks using an initializer. - -```ruby -# config/initializer/maintenance_tasks.rb -Rails.autoloaders.main.on_load("MaintenanceTasks::Task") do - MaintenanceTasks::Task.class_eval do - after_start(:notify) - - private - - def notify; end - end -end -``` - ### Considerations when writing Tasks Maintenance Tasks relies on the queue adapter configured for your application to From d2a6279f1afab2d2e5bccc01884ca0971bd8cdd9 Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Wed, 14 Feb 2024 10:38:10 -0500 Subject: [PATCH 05/11] improve code example in README.md MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Étienne Barrié --- README.md | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/README.md b/README.md index ff4033a8..a36581f4 100644 --- a/README.md +++ b/README.md @@ -467,8 +467,7 @@ These notifications offer a way to monitor the lifecycle of maintenance tasks in Usage example: ```ruby - ActiveSupport::Notifications.subscribe("maintenance_tasks.enqueued") do |*args| - payload = args.last + ActiveSupport::Notifications.subscribe("maintenance_tasks.enqueued") do |*, payload| run = payload[:run] run.task_name run.arguments From 8ac5110e794ce5f4c107f1d846719136eef24d3e Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Wed, 14 Feb 2024 13:13:13 -0500 Subject: [PATCH 06/11] define notification attributes explicitly the run model is not public https://github.com/Shopify/maintenance_tasks/pull/961#discussion_r1489838678 --- README.md | 22 ++++++++---- app/models/maintenance_tasks/run.rb | 19 +++++++++- test/models/maintenance_tasks/run_test.rb | 42 ++++++++++++++++++----- 3 files changed, 67 insertions(+), 16 deletions(-) diff --git a/README.md b/README.md index a36581f4..8ac65807 100644 --- a/README.md +++ b/README.md @@ -467,11 +467,15 @@ These notifications offer a way to monitor the lifecycle of maintenance tasks in Usage example: ```ruby - ActiveSupport::Notifications.subscribe("maintenance_tasks.enqueued") do |*, payload| - run = payload[:run] - run.task_name - run.arguments - run.metadata + ActiveSupport::Notifications.subscribe("maintenance_tasks.succeeded") do |*, payload| + task_name = payload[:task_name] + arguments = payload[:arguments] + metadata = payload[:metadata] + job_id = payload[:job_id] + run_id = payload[:run_id] + time_running = payload[:time_running] + started_at = payload[:started_at] + ended_at = payload[:ended_at] end # or @@ -480,8 +484,12 @@ class MaintenanceTasksInstrumenter < ActiveSupport::Subscriber attach_to :maintenance_tasks def enqueued(event) - run = event.payload[:run] - SlackNotifier.broadcast(SLACK_CHANNEL, "Job #{run.task_name} was started by #{run.metadata[:user_email]}} with arguments #{run.arguments.to_s.truncate(255)}") + task_name = event.payload[:task_name] + arguments = event.payload[:arguments] + metadata = event.payload[:metadata] + + SlackNotifier.broadcast(SLACK_CHANNEL, + "Job #{task_name} was started by #{metadata[:user_email]}} with arguments #{arguments.to_s.truncate(255)}") end end ``` diff --git a/app/models/maintenance_tasks/run.rb b/app/models/maintenance_tasks/run.rb index 86c7823d..c7512f74 100644 --- a/app/models/maintenance_tasks/run.rb +++ b/app/models/maintenance_tasks/run.rb @@ -458,7 +458,24 @@ def instrument_status_change return if status.nil? || !status_previously_changed? return if running? || pausing? || cancelling? || interrupted? - ActiveSupport::Notifications.instrument("maintenance_tasks.#{status}", run: self) + attr = { + run_id: id, + job_id: job_id, + task_name: task_name, + arguments: arguments, + metadata: metadata, + time_running: time_running, + started_at: started_at, + ended_at: ended_at, + } + + attr[:error] = { + message: error_message, + class: error_class, + backtrace: backtrace, + } if errored? + + ActiveSupport::Notifications.instrument("maintenance_tasks.#{status}", attr) rescue nil end diff --git a/test/models/maintenance_tasks/run_test.rb b/test/models/maintenance_tasks/run_test.rb index 88cfa39a..3ee9aaac 100644 --- a/test/models/maintenance_tasks/run_test.rb +++ b/test/models/maintenance_tasks/run_test.rb @@ -81,9 +81,11 @@ class RunTest < ActiveSupport::TestCase run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "running") run.status = :succeeded run.task.expects(:after_complete_callback) - assert_notification_for("maintenance_tasks.succeeded", run: run) do + + payload = subscribe_to_notification("maintenance_tasks.succeeded") do run.persist_transition end + assert_equal(expected_notification(run), payload) end test "#persist_transition calls the cancel callback" do @@ -93,18 +95,20 @@ class RunTest < ActiveSupport::TestCase ) run.status = :cancelled run.task.expects(:after_cancel_callback) - assert_notification_for("maintenance_tasks.cancelled", run: run) do + payload = subscribe_to_notification("maintenance_tasks.cancelled") do run.persist_transition end + assert_equal(expected_notification(run), payload) end test "#persist_transition calls the pause callback" do run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "pausing") run.status = :paused run.task.expects(:after_pause_callback) - assert_notification_for("maintenance_tasks.paused", run: run) do + payload = subscribe_to_notification("maintenance_tasks.paused") do run.persist_transition end + assert_equal(expected_notification(run), payload) end test "#persist_transition with a race condition moves the run to the proper status and calls the right callback" do @@ -115,9 +119,10 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_cancel_callback) run.status = :interrupted - assert_notification_for("maintenance_tasks.cancelled", run: run) do + payload = subscribe_to_notification("maintenance_tasks.cancelled") do run.persist_transition end + assert_equal(expected_notification(run), payload) assert_predicate run.reload, :cancelled? end @@ -129,9 +134,10 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_complete_callback) run.status = :succeeded - assert_notification_for("maintenance_tasks.succeeded", run: run) do + payload = subscribe_to_notification("maintenance_tasks.succeeded") do run.persist_transition end + assert_equal(expected_notification(run), payload) assert_predicate run.reload, :succeeded? end @@ -181,9 +187,15 @@ class RunTest < ActiveSupport::TestCase error = ArgumentError.new("Something went wrong") error.set_backtrace(["lib/foo.rb:42:in `bar'"]) run.task.expects(:after_error_callback) - assert_notification_for("maintenance_tasks.errored", run: run) do + payload = subscribe_to_notification("maintenance_tasks.errored") do run.persist_error(error) end + + error = payload.delete(:error) + assert_equal(expected_notification(run), payload) + assert_equal "ArgumentError", error[:class] + assert_equal "Something went wrong", error[:message] + assert_equal ["lib/foo.rb:42:in `bar'"], error[:backtrace] end test "#persist_error can handle error callback raising" do @@ -702,10 +714,24 @@ class RunTest < ActiveSupport::TestCase private - def assert_notification_for(name, expected_payload, &block) + def subscribe_to_notification(name, &block) payload = nil ActiveSupport::Notifications.subscribed(->(*args) { payload = args.last }, name, &block) - assert_equal(expected_payload, payload) + + payload + end + + def expected_notification(run) + { + run_id: run.id, + job_id: run.job_id, + task_name: run.task_name, + arguments: run.arguments, + metadata: run.metadata, + time_running: run.time_running, + started_at: run.started_at, + ended_at: run.ended_at, + } end def count_uncached_queries(&block) From 21c8fa00a0a52b48925843407ed6e765414263be Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Wed, 14 Feb 2024 14:42:17 -0500 Subject: [PATCH 07/11] add example for maintenance_tasks.errored --- README.md | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/README.md b/README.md index 8ac65807..b2a13ac4 100644 --- a/README.md +++ b/README.md @@ -449,10 +449,13 @@ module Maintenance def process(post) post.update!(content: "updated content") end + end +end +``` ### Subscribing to instrumentation events -If you are interested in actioning a specific task event, please refer to the `Task Callbacks` section below. However, if you want to subscribe to all events, irrespective of the task, you can use the following Active Support notifications: +If you are interested in actioning a specific task event, please refer to the [Using Task Callbacks](#using-task-callbacks) section below. However, if you want to subscribe to all events, irrespective of the task, you can use the following Active Support notifications: ```ruby maintenance_tasks.enqueued # This event is published when a task has been enqueued by the user. @@ -478,6 +481,14 @@ Usage example: ended_at = payload[:ended_at] end +ActiveSupport::Notifications.subscribe("maintenance_tasks.errored") do |*, payload| + task_name = payload[:task_name] + error = payload[:error] + error_message = error[:message] + error_class = error[:class] + error_backtrace = error[:backtrace] +end + # or class MaintenanceTasksInstrumenter < ActiveSupport::Subscriber From e97088d2f4c1b8dcfea02b559de7fbd95bd38dfd Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Wed, 14 Feb 2024 17:18:42 -0500 Subject: [PATCH 08/11] invert the instrumentation name to work with subscribers https://github.com/rails/rails/blob/36c1591bcb5e0ee3084759c7f42a706fe5bb7ca7/activesupport/lib/active_support/subscriber.rb#L116 --- README.md | 14 ++--- app/models/maintenance_tasks/run.rb | 2 +- test/models/maintenance_tasks/run_test.rb | 66 ++++++++++++----------- 3 files changed, 44 insertions(+), 38 deletions(-) diff --git a/README.md b/README.md index b2a13ac4..21f991be 100644 --- a/README.md +++ b/README.md @@ -458,11 +458,11 @@ end If you are interested in actioning a specific task event, please refer to the [Using Task Callbacks](#using-task-callbacks) section below. However, if you want to subscribe to all events, irrespective of the task, you can use the following Active Support notifications: ```ruby -maintenance_tasks.enqueued # This event is published when a task has been enqueued by the user. -maintenance_tasks.succeeded # This event is published when a task has finished without any errors. -maintenance_tasks.cancelled # This event is published when the user explicitly halts the execution of a task. -maintenance_tasks.paused # This event is published when a task is paused by the user in the middle of its run. -maintenance_tasks.errored # This event is published when the task's code produces an unhandled exception. +enqueued.maintenance_tasks # This event is published when a task has been enqueued by the user. +succeeded.maintenance_tasks # This event is published when a task has finished without any errors. +cancelled.maintenance_tasks # This event is published when the user explicitly halts the execution of a task. +paused.maintenance_tasks # This event is published when a task is paused by the user in the middle of its run. +errored.maintenance_tasks # This event is published when the task's code produces an unhandled exception. ``` These notifications offer a way to monitor the lifecycle of maintenance tasks in your application. @@ -470,7 +470,7 @@ These notifications offer a way to monitor the lifecycle of maintenance tasks in Usage example: ```ruby - ActiveSupport::Notifications.subscribe("maintenance_tasks.succeeded") do |*, payload| + ActiveSupport::Notifications.subscribe("succeeded.maintenance_tasks") do |*, payload| task_name = payload[:task_name] arguments = payload[:arguments] metadata = payload[:metadata] @@ -481,7 +481,7 @@ Usage example: ended_at = payload[:ended_at] end -ActiveSupport::Notifications.subscribe("maintenance_tasks.errored") do |*, payload| +ActiveSupport::Notifications.subscribe("errored.maintenance_tasks") do |*, payload| task_name = payload[:task_name] error = payload[:error] error_message = error[:message] diff --git a/app/models/maintenance_tasks/run.rb b/app/models/maintenance_tasks/run.rb index c7512f74..a3656394 100644 --- a/app/models/maintenance_tasks/run.rb +++ b/app/models/maintenance_tasks/run.rb @@ -475,7 +475,7 @@ def instrument_status_change backtrace: backtrace, } if errored? - ActiveSupport::Notifications.instrument("maintenance_tasks.#{status}", attr) + ActiveSupport::Notifications.instrument("#{status}.maintenance_tasks", attr) rescue nil end diff --git a/test/models/maintenance_tasks/run_test.rb b/test/models/maintenance_tasks/run_test.rb index 3ee9aaac..ffc4de9d 100644 --- a/test/models/maintenance_tasks/run_test.rb +++ b/test/models/maintenance_tasks/run_test.rb @@ -3,6 +3,30 @@ require "test_helper" module MaintenanceTasks + class Notifier < ActiveSupport::Subscriber + NOTIFICATIONS = [ + :enqueued, + :succeeded, + :paused, + :cancelled, + :errored, + ].freeze + + attach_to :maintenance_tasks + + class << self + def payload + Thread.current[:payload] ||= {} + end + end + + NOTIFICATIONS.each do |notification| + define_method(notification) do |event| + self.class.payload.merge!("#{notification}.maintenance_tasks" => event.payload) + end + end + end + class RunTest < ActiveSupport::TestCase test "invalid if the task doesn't exist" do run = Run.new(task_name: "Maintenance::DoesNotExist") @@ -82,10 +106,8 @@ class RunTest < ActiveSupport::TestCase run.status = :succeeded run.task.expects(:after_complete_callback) - payload = subscribe_to_notification("maintenance_tasks.succeeded") do - run.persist_transition - end - assert_equal(expected_notification(run), payload) + run.persist_transition + assert_equal(expected_notification(run), Notifier.payload.fetch("succeeded.maintenance_tasks")) end test "#persist_transition calls the cancel callback" do @@ -95,20 +117,16 @@ class RunTest < ActiveSupport::TestCase ) run.status = :cancelled run.task.expects(:after_cancel_callback) - payload = subscribe_to_notification("maintenance_tasks.cancelled") do - run.persist_transition - end - assert_equal(expected_notification(run), payload) + run.persist_transition + assert_equal(expected_notification(run), Notifier.payload.fetch("cancelled.maintenance_tasks")) end test "#persist_transition calls the pause callback" do run = Run.create!(task_name: "Maintenance::CallbackTestTask", status: "pausing") run.status = :paused run.task.expects(:after_pause_callback) - payload = subscribe_to_notification("maintenance_tasks.paused") do - run.persist_transition - end - assert_equal(expected_notification(run), payload) + run.persist_transition + assert_equal(expected_notification(run), Notifier.payload.fetch("paused.maintenance_tasks")) end test "#persist_transition with a race condition moves the run to the proper status and calls the right callback" do @@ -119,10 +137,8 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_cancel_callback) run.status = :interrupted - payload = subscribe_to_notification("maintenance_tasks.cancelled") do - run.persist_transition - end - assert_equal(expected_notification(run), payload) + run.persist_transition + assert_equal(expected_notification(run), Notifier.payload.fetch("cancelled.maintenance_tasks")) assert_predicate run.reload, :cancelled? end @@ -134,10 +150,8 @@ class RunTest < ActiveSupport::TestCase run.task.expects(:after_complete_callback) run.status = :succeeded - payload = subscribe_to_notification("maintenance_tasks.succeeded") do - run.persist_transition - end - assert_equal(expected_notification(run), payload) + run.persist_transition + assert_equal(expected_notification(run), Notifier.payload.fetch("succeeded.maintenance_tasks")) assert_predicate run.reload, :succeeded? end @@ -187,10 +201,9 @@ class RunTest < ActiveSupport::TestCase error = ArgumentError.new("Something went wrong") error.set_backtrace(["lib/foo.rb:42:in `bar'"]) run.task.expects(:after_error_callback) - payload = subscribe_to_notification("maintenance_tasks.errored") do - run.persist_error(error) - end + run.persist_error(error) + payload = Notifier.payload.fetch("errored.maintenance_tasks") error = payload.delete(:error) assert_equal(expected_notification(run), payload) assert_equal "ArgumentError", error[:class] @@ -714,13 +727,6 @@ class RunTest < ActiveSupport::TestCase private - def subscribe_to_notification(name, &block) - payload = nil - ActiveSupport::Notifications.subscribed(->(*args) { payload = args.last }, name, &block) - - payload - end - def expected_notification(run) { run_id: run.id, From 74acc6b45863805728c2138e13c90b7cb787a7e6 Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Thu, 15 Feb 2024 11:17:59 -0500 Subject: [PATCH 09/11] fix enqueued notifications --- app/models/maintenance_tasks/run.rb | 2 +- test/models/maintenance_tasks/run_test.rb | 6 ++++++ 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/app/models/maintenance_tasks/run.rb b/app/models/maintenance_tasks/run.rb index a3656394..474483c6 100644 --- a/app/models/maintenance_tasks/run.rb +++ b/app/models/maintenance_tasks/run.rb @@ -455,7 +455,7 @@ def task private def instrument_status_change - return if status.nil? || !status_previously_changed? + return unless status_previously_changed? || id_previously_changed? return if running? || pausing? || cancelling? || interrupted? attr = { diff --git a/test/models/maintenance_tasks/run_test.rb b/test/models/maintenance_tasks/run_test.rb index ffc4de9d..7490ade9 100644 --- a/test/models/maintenance_tasks/run_test.rb +++ b/test/models/maintenance_tasks/run_test.rb @@ -620,6 +620,12 @@ class RunTest < ActiveSupport::TestCase end end + test "#create defaults to the enqueued status" do + run = Run.create!(task_name: "Maintenance::CallbackTestTask") + assert_predicate(run, :enqueued?) + assert_equal(expected_notification(run), Notifier.payload.fetch("enqueued.maintenance_tasks")) + end + test "#task returns Task instance for Run" do run = Run.new(task_name: "Maintenance::UpdatePostsTask") assert_kind_of Maintenance::UpdatePostsTask, run.task From 3354bacb03d2d964679a3ff1bb8e5e0b8c16e023 Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Fri, 16 Feb 2024 13:48:11 -0500 Subject: [PATCH 10/11] don't rescue exceptions in instrument_status_change --- app/models/maintenance_tasks/run.rb | 2 -- test/jobs/maintenance_tasks/task_job_test.rb | 8 ++++++-- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/app/models/maintenance_tasks/run.rb b/app/models/maintenance_tasks/run.rb index 474483c6..44b6c2d4 100644 --- a/app/models/maintenance_tasks/run.rb +++ b/app/models/maintenance_tasks/run.rb @@ -476,8 +476,6 @@ def instrument_status_change } if errored? ActiveSupport::Notifications.instrument("#{status}.maintenance_tasks", attr) - rescue - nil end def run_task_callbacks(callback) diff --git a/test/jobs/maintenance_tasks/task_job_test.rb b/test/jobs/maintenance_tasks/task_job_test.rb index b13cf7dc..c4dcee7d 100644 --- a/test/jobs/maintenance_tasks/task_job_test.rb +++ b/test/jobs/maintenance_tasks/task_job_test.rb @@ -499,7 +499,9 @@ class << self JobIteration.stubs(interruption_adapter: -> { true }) # Simulate cancel happening after we've already checked @run.cancelling? - @run.expects(:cancelling?).twice.with do + @run.expects(:cancelling?).at_least(2).with do + next true if caller.any?(/`instrument_status_change'\z/) # avoid endless loop + Run.find(@run.id).cancel end.returns(false).then.returns(true) @@ -512,7 +514,9 @@ class << self JobIteration.stubs(interruption_adapter: -> { true }) # Simulate pause happening after we've already checked @run.pausing? - @run.expects(:pausing?).twice.with do + @run.expects(:pausing?).at_least(2).with do + next true if caller.any?(/`instrument_status_change'\z/) # avoid endless loop + Run.find(@run.id).pausing! end.returns(false).then.returns(true) From 36d7c08385d9e12bc2810c0d666911e1d493d0fc Mon Sep 17 00:00:00 2001 From: Michael Elfassy Date: Fri, 16 Feb 2024 13:53:47 -0500 Subject: [PATCH 11/11] add rescue to readme examples it's subscriber's responsibility to catch any potential issues otherwise it risks breaking the tasks's run state https://github.com/Shopify/maintenance_tasks/pull/961#discussion_r1489694176 --- README.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/README.md b/README.md index 21f991be..4a4e6d45 100644 --- a/README.md +++ b/README.md @@ -479,6 +479,8 @@ Usage example: time_running = payload[:time_running] started_at = payload[:started_at] ended_at = payload[:ended_at] +rescue => e + Rails.logger.error(e) end ActiveSupport::Notifications.subscribe("errored.maintenance_tasks") do |*, payload| @@ -487,6 +489,8 @@ ActiveSupport::Notifications.subscribe("errored.maintenance_tasks") do |*, paylo error_message = error[:message] error_class = error[:class] error_backtrace = error[:backtrace] +rescue => e + Rails.logger.error(e) end # or @@ -501,6 +505,8 @@ class MaintenanceTasksInstrumenter < ActiveSupport::Subscriber SlackNotifier.broadcast(SLACK_CHANNEL, "Job #{task_name} was started by #{metadata[:user_email]}} with arguments #{arguments.to_s.truncate(255)}") + rescue => e + Rails.logger.error(e) end end ```