From d93066e2d329cd2f0770cbb548a55ace5f31a5ee Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 3 Oct 2024 08:57:02 -0500 Subject: [PATCH 01/26] Add tests for existing impl --- .../apple/episode_delivery_status_test.rb | 69 +++++++++++++++++++ 1 file changed, 69 insertions(+) create mode 100644 test/models/apple/episode_delivery_status_test.rb diff --git a/test/models/apple/episode_delivery_status_test.rb b/test/models/apple/episode_delivery_status_test.rb new file mode 100644 index 000000000..53b4a747f --- /dev/null +++ b/test/models/apple/episode_delivery_status_test.rb @@ -0,0 +1,69 @@ +require "test_helper" + +class Apple::EpisodeDeliveryStatusTest < ActiveSupport::TestCase + describe Apple::EpisodeDeliveryStatus do + let(:episode) { create(:episode) } + let(:delivery_status) { create(:apple_episode_delivery_status, episode: episode) } + + describe "associations" do + it "belongs to an episode" do + assert_equal episode, delivery_status.episode + end + end + + describe "scopes" do + it "orders by created_at desc by default" do + old_status = create(:apple_episode_delivery_status, episode: episode, created_at: 2.days.ago) + new_status = create(:apple_episode_delivery_status, episode: episode, created_at: 1.day.ago) + + assert_equal [new_status, old_status], episode.apple_episode_delivery_statuses.to_a + end + end + + describe "default values" do + it "sets asset_processing_attempts to 0 by default" do + new_status = Apple::EpisodeDeliveryStatus.new + assert_equal 0, new_status.asset_processing_attempts + end + end + + describe "#apple_update_delivery_status" do + it "creates a new status when none exists" do + episode.apple_episode_delivery_statuses.destroy_all + assert_difference "Apple::EpisodeDeliveryStatus.count", 1 do + episode.apple_update_delivery_status(delivered: true) + end + end + + it "creates a new status even when one already exists" do + _existing_status = create(:apple_episode_delivery_status, episode: episode) + assert_difference "Apple::EpisodeDeliveryStatus.count", 1 do + episode.apple_update_delivery_status(delivered: false) + end + end + + it "updates attributes of the new status" do + new_status = episode.apple_update_delivery_status( + delivered: true, + source_url: "http://example.com/audio.mp3", + source_size: 1024, + source_filename: "audio.mp3" + ) + + assert new_status.delivered + assert_equal "http://example.com/audio.mp3", new_status.source_url + assert_equal 1024, new_status.source_size + assert_equal "audio.mp3", new_status.source_filename + end + end + + describe "#apple_episode_delivery_status" do + it "returns the most recent status" do + _old_status = create(:apple_episode_delivery_status, episode: episode, created_at: 2.days.ago) + new_status = create(:apple_episode_delivery_status, episode: episode, created_at: 1.day.ago) + + assert_equal new_status, episode.apple_episode_delivery_status + end + end + end +end From 57db4079830eb2b061141de48ae2d9b8bcc02a94 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 3 Oct 2024 08:57:24 -0500 Subject: [PATCH 02/26] Extract and refactor --- app/models/apple/episode_delivery_status.rb | 8 ++++++++ app/models/concerns/apple_delivery.rb | 7 +------ 2 files changed, 9 insertions(+), 6 deletions(-) diff --git a/app/models/apple/episode_delivery_status.rb b/app/models/apple/episode_delivery_status.rb index db1fcbb95..dfa1ca26b 100644 --- a/app/models/apple/episode_delivery_status.rb +++ b/app/models/apple/episode_delivery_status.rb @@ -1,5 +1,13 @@ module Apple class EpisodeDeliveryStatus < ApplicationRecord belongs_to :episode, class_name: "::Episode" + + def self.update_status(episode, attrs) + new_status = (episode.apple_episode_delivery_status&.dup || new(episode: episode)) + new_status.assign_attributes(attrs) + new_status.save! + episode.apple_episode_delivery_statuses.reset + new_status + end end end diff --git a/app/models/concerns/apple_delivery.rb b/app/models/concerns/apple_delivery.rb index 25a76c282..0d6aa06f2 100644 --- a/app/models/concerns/apple_delivery.rb +++ b/app/models/concerns/apple_delivery.rb @@ -22,12 +22,7 @@ def publish_to_apple? end def apple_update_delivery_status(attrs) - new_status = (apple_episode_delivery_status&.dup || apple_episode_delivery_statuses.build) - new_status.assign_attributes(**attrs) - new_status.save! - - apple_episode_delivery_statuses.reset - new_status + Apple::EpisodeDeliveryStatus.update_status(self, attrs) end def apple_episode_delivery_status From b470697aa6dbfaca2eea08471eb06fd479d90bd9 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 3 Oct 2024 10:20:37 -0500 Subject: [PATCH 03/26] Set up the incrementing --- app/controllers/episodes_controller.rb | 2 +- app/models/apple/episode.rb | 2 +- app/models/apple/episode_delivery_status.rb | 8 +++ app/models/apple/publisher.rb | 10 ++- app/models/concerns/apple_delivery.rb | 6 +- ...essing_count_to_episode_delivery_status.rb | 5 ++ db/schema.rb | 3 +- test/factories/apple_episode_factory.rb | 6 +- .../apple/episode_delivery_status_test.rb | 65 +++++++++++++++++-- test/models/apple/episode_test.rb | 2 +- test/models/apple/publisher_test.rb | 35 +++++++++- test/models/episode_test.rb | 46 ++++++++++++- 12 files changed, 172 insertions(+), 18 deletions(-) create mode 100644 db/migrate/20241002215949_add_asset_processing_count_to_episode_delivery_status.rb diff --git a/app/controllers/episodes_controller.rb b/app/controllers/episodes_controller.rb index 53d16e877..305b0b05f 100644 --- a/app/controllers/episodes_controller.rb +++ b/app/controllers/episodes_controller.rb @@ -92,7 +92,7 @@ def destroy respond_to do |format| if @episode.destroy - @episode.publish! + @episode.podcast.publish! format.html { redirect_to podcast_episodes_url(@episode.podcast_id), notice: t(".notice") } else format.html do diff --git a/app/models/apple/episode.rb b/app/models/apple/episode.rb index 9d8a2c801..fd96f05ac 100644 --- a/app/models/apple/episode.rb +++ b/app/models/apple/episode.rb @@ -491,7 +491,7 @@ def audio_asset_state_success? end def has_media_version? - return false unless delivery_status.present? && delivery_status.source_media_version_id.present? + return false unless delivery_status.source_media_version_id.present? delivery_status.source_media_version_id == feeder_episode.media_version_id end diff --git a/app/models/apple/episode_delivery_status.rb b/app/models/apple/episode_delivery_status.rb index dfa1ca26b..01201865a 100644 --- a/app/models/apple/episode_delivery_status.rb +++ b/app/models/apple/episode_delivery_status.rb @@ -9,5 +9,13 @@ def self.update_status(episode, attrs) episode.apple_episode_delivery_statuses.reset new_status end + + def increment_asset_wait + self.class.update_status(episode, asset_processing_attempts: (asset_processing_attempts || 0) + 1) + end + + def reset_asset_wait + self.class.update_status(episode, asset_processing_attempts: 0) + end end end diff --git a/app/models/apple/publisher.rb b/app/models/apple/publisher.rb index bfb84474a..bdf70aae7 100644 --- a/app/models/apple/publisher.rb +++ b/app/models/apple/publisher.rb @@ -230,8 +230,14 @@ def wait_for_asset_state(eps) Rails.logger.tagged("##{__method__}") do eps = eps.filter { |e| e.podcast_delivery_files.any?(&:api_marked_as_uploaded?) } + # Mark the episodes as waiting again for asset processing + eps.each { |ep| ep.apple_episode_delivery_status.increment_asset_wait } + (waiting_timed_out, _) = Apple::Episode.wait_for_asset_state(api, eps) - raise "Timed out waiting for asset state" if waiting_timed_out + if waiting_timed_out + attempts = eps.max { |ep| ep.apple_episode_delivery_status.asset_processing_attempts } + raise "Timed out waiting for asset state. #{attempts} attempts so far" + end end end @@ -363,6 +369,8 @@ def publish_drafting!(eps) eps = eps.select { |ep| ep.drafting? && ep.container_upload_complete? } res = Apple::Episode.publish(api, show, eps) + eps.each { |ep| ep.apple_episode_delivery_status.reset_asset_wait } + Rails.logger.info("Published #{res.length} drafting episodes.") end end diff --git a/app/models/concerns/apple_delivery.rb b/app/models/concerns/apple_delivery.rb index 0d6aa06f2..f7ff901de 100644 --- a/app/models/concerns/apple_delivery.rb +++ b/app/models/concerns/apple_delivery.rb @@ -25,8 +25,12 @@ def apple_update_delivery_status(attrs) Apple::EpisodeDeliveryStatus.update_status(self, attrs) end + def build_initial_delivery_status + Apple::EpisodeDeliveryStatus.new(episode: self) + end + def apple_episode_delivery_status - apple_episode_delivery_statuses.order(created_at: :desc).first + apple_episode_delivery_statuses.order(created_at: :desc).first || build_initial_delivery_status end def apple_needs_delivery? diff --git a/db/migrate/20241002215949_add_asset_processing_count_to_episode_delivery_status.rb b/db/migrate/20241002215949_add_asset_processing_count_to_episode_delivery_status.rb new file mode 100644 index 000000000..56aaa8151 --- /dev/null +++ b/db/migrate/20241002215949_add_asset_processing_count_to_episode_delivery_status.rb @@ -0,0 +1,5 @@ +class AddAssetProcessingCountToEpisodeDeliveryStatus < ActiveRecord::Migration[7.2] + def change + add_column :apple_episode_delivery_statuses, :asset_processing_attempts, :integer, default: 0, null: false + end +end diff --git a/db/schema.rb b/db/schema.rb index a9023a1e5..f8706c810 100644 --- a/db/schema.rb +++ b/db/schema.rb @@ -10,7 +10,7 @@ # # It's strongly recommended that you check this file into your version control system. -ActiveRecord::Schema[7.1].define(version: 2024_08_21_135645) do +ActiveRecord::Schema[7.2].define(version: 2024_10_02_215949) do # These are extensions that must be enabled in order to support this database enable_extension "plpgsql" enable_extension "uuid-ossp" @@ -36,6 +36,7 @@ t.text "enclosure_url" t.integer "source_fetch_count", default: 0 t.bigint "source_media_version_id" + t.integer "asset_processing_attempts", default: 0, null: false t.index ["episode_id", "created_at"], name: "index_apple_episode_delivery_statuses_on_episode_id_created_at", include: ["delivered", "id"] t.index ["episode_id"], name: "index_apple_episode_delivery_statuses_on_episode_id" end diff --git a/test/factories/apple_episode_factory.rb b/test/factories/apple_episode_factory.rb index 04d9c612b..52a4aa928 100644 --- a/test/factories/apple_episode_factory.rb +++ b/test/factories/apple_episode_factory.rb @@ -22,7 +22,11 @@ after(:build) do |apple_episode, evaluator| container = create(:apple_podcast_container, episode: apple_episode.feeder_episode) delivery = create(:apple_podcast_delivery, episode: apple_episode.feeder_episode, podcast_container: container) - _delivery_file = create(:apple_podcast_delivery_file, delivery: delivery, episode: apple_episode.feeder_episode) + _delivery_file = create(:apple_podcast_delivery_file, + delivery: delivery, + episode: apple_episode.feeder_episode, + api_marked_as_uploaded: true, + upload_operations_complete: true) create(:content, episode: apple_episode.feeder_episode, position: 1, status: "complete") create(:content, episode: apple_episode.feeder_episode, position: 2, status: "complete") diff --git a/test/models/apple/episode_delivery_status_test.rb b/test/models/apple/episode_delivery_status_test.rb index 53b4a747f..8cc1c1835 100644 --- a/test/models/apple/episode_delivery_status_test.rb +++ b/test/models/apple/episode_delivery_status_test.rb @@ -27,37 +27,42 @@ class Apple::EpisodeDeliveryStatusTest < ActiveSupport::TestCase end end - describe "#apple_update_delivery_status" do + describe ".update_status" do it "creates a new status when none exists" do episode.apple_episode_delivery_statuses.destroy_all assert_difference "Apple::EpisodeDeliveryStatus.count", 1 do - episode.apple_update_delivery_status(delivered: true) + Apple::EpisodeDeliveryStatus.update_status(episode, delivered: true) end end it "creates a new status even when one already exists" do _existing_status = create(:apple_episode_delivery_status, episode: episode) assert_difference "Apple::EpisodeDeliveryStatus.count", 1 do - episode.apple_update_delivery_status(delivered: false) + Apple::EpisodeDeliveryStatus.update_status(episode, delivered: false) end end it "updates attributes of the new status" do - new_status = episode.apple_update_delivery_status( + new_status = Apple::EpisodeDeliveryStatus.update_status(episode, delivered: true, source_url: "http://example.com/audio.mp3", source_size: 1024, - source_filename: "audio.mp3" - ) + source_filename: "audio.mp3") assert new_status.delivered assert_equal "http://example.com/audio.mp3", new_status.source_url assert_equal 1024, new_status.source_size assert_equal "audio.mp3", new_status.source_filename end + + it "resets the episode's apple_episode_delivery_statuses association" do + episode.apple_episode_delivery_statuses.load + Apple::EpisodeDeliveryStatus.update_status(episode, delivered: true) + refute episode.apple_episode_delivery_statuses.loaded? + end end - describe "#apple_episode_delivery_status" do + describe "Episode#apple_episode_delivery_status" do it "returns the most recent status" do _old_status = create(:apple_episode_delivery_status, episode: episode, created_at: 2.days.ago) new_status = create(:apple_episode_delivery_status, episode: episode, created_at: 1.day.ago) @@ -65,5 +70,51 @@ class Apple::EpisodeDeliveryStatusTest < ActiveSupport::TestCase assert_equal new_status, episode.apple_episode_delivery_status end end + + describe "Asset waits and counting" do + describe "#increment_asset_wait" do + it "increments the asset_processing_attempts count" do + initial_count = delivery_status.asset_processing_attempts || 0 + new_status = delivery_status.increment_asset_wait + assert_equal initial_count + 1, new_status.asset_processing_attempts + end + + it "creates a new status entry" do + assert delivery_status.asset_processing_attempts.zero? + assert_difference "Apple::EpisodeDeliveryStatus.count", 1 do + delivery_status.increment_asset_wait + end + end + + it "maintains other attributes" do + delivery_status.update(delivered: true, source_url: "http://example.com/audio.mp3") + new_status = delivery_status.increment_asset_wait + assert new_status.delivered + assert_equal "http://example.com/audio.mp3", new_status.source_url + end + end + + describe "#reset_asset_wait" do + it "resets the asset_processing_attempts count to zero" do + delivery_status.update(asset_processing_attempts: 5) + new_status = delivery_status.reset_asset_wait + assert_equal 0, new_status.asset_processing_attempts + end + + it "creates a new status entry" do + assert delivery_status.asset_processing_attempts.zero? + assert_difference "Apple::EpisodeDeliveryStatus.count", 1 do + delivery_status.reset_asset_wait + end + end + + it "maintains other attributes" do + delivery_status.update(delivered: true, source_url: "http://example.com/audio.mp3") + new_status = delivery_status.reset_asset_wait + assert new_status.delivered + assert_equal "http://example.com/audio.mp3", new_status.source_url + end + end + end end end diff --git a/test/models/apple/episode_test.rb b/test/models/apple/episode_test.rb index ca43fa524..30e8d8feb 100644 --- a/test/models/apple/episode_test.rb +++ b/test/models/apple/episode_test.rb @@ -178,7 +178,7 @@ } it "should be true if the delivery status is nil or has nil attrs" do assert apple_episode.delivery_statuses.destroy_all - assert apple_episode.delivery_status.nil? + assert apple_episode.delivery_status.source_media_version_id.nil? assert_equal true, apple_episode.needs_media_version? end diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index c8d3885db..3f4186bca 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -344,12 +344,11 @@ describe "#publish_drafting!" do it "should call the episode publish drafting class method" do - ep = OpenStruct.new(drafting?: true, container_upload_complete?: true) mock = Minitest::Mock.new - mock.expect(:call, [], [apple_publisher.api, apple_publisher.show, [ep]]) + mock.expect(:call, [], [apple_publisher.api, apple_publisher.show, [episode1]]) Apple::Episode.stub(:publish, mock) do - apple_publisher.publish_drafting!([ep]) + apple_publisher.publish_drafting!([episode]) end assert mock.verify @@ -369,6 +368,36 @@ end end + describe "#wait_for_asset_state" do + let(:episode1) { build(:uploaded_apple_episode, show: apple_publisher.show) } + let(:episode2) { build(:uploaded_apple_episode, show: apple_publisher.show) } + let(:episodes) { [episode1, episode2] } + + it "should increment asset wait count for each episode" do + episodes.each do |ep| + assert_equal 0, ep.apple_episode_delivery_status.asset_processing_attempts + end + + Apple::Episode.stub(:wait_for_asset_state, [false, []]) do + apple_publisher.wait_for_asset_state(episodes) + end + + episodes.each do |ep| + assert_equal 1, ep.apple_episode_delivery_status.asset_processing_attempts + end + end + + it "should raise an error when wait times out" do + episode1.apple_episode_delivery_status.update!(asset_processing_attempts: 3) + + Apple::Episode.stub(:wait_for_asset_state, [true, episodes]) do + assert_raises(RuntimeError, "Timed out waiting for asset state. 3 attempts so far") do + apple_publisher.wait_for_asset_state(episodes) + end + end + end + end + describe "#raise_delivery_processing_errors" do let(:apple_episode) { build(:apple_episode, show: apple_publisher.show) } let(:asset_processing_state) { "COMPLETED" } diff --git a/test/models/episode_test.rb b/test/models/episode_test.rb index d484f82d8..bcc23dbd7 100644 --- a/test/models/episode_test.rb +++ b/test/models/episode_test.rb @@ -458,7 +458,7 @@ describe "#apple_needs_delivery?" do let(:episode) { create(:episode) } it "is true by default" do - assert_nil episode.apple_episode_delivery_status + refute episode.apple_episode_delivery_status.persisted? assert episode.apple_needs_delivery? end @@ -476,4 +476,48 @@ assert episode.apple_needs_delivery? end end + + describe "#increment_asset_wait" do + let(:episode) { create(:episode) } + + it "creates a new status with incremented asset_processing_attempts" do + assert_difference -> { episode.apple_episode_delivery_statuses.count }, 1 do + new_status = episode.apple_status.increment_asset_wait + assert_equal 1, new_status.asset_processing_attempts + end + end + + it "increments existing asset_processing_attempts" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 2) + new_status = episode.apple_status.increment_asset_wait + assert_equal 3, new_status.asset_processing_attempts + end + + it "maintains other attributes when incrementing" do + create(:apple_episode_delivery_status, + episode: episode, + delivered: true, + source_url: "http://example.com/audio.mp3", + asset_processing_attempts: 1) + + new_status = episode.apple_status.increment_asset_wait + assert_equal 2, new_status.asset_processing_attempts + assert new_status.delivered + assert_equal "http://example.com/audio.mp3", new_status.source_url + end + + it "creates a new status with asset_processing_attempts set to 1 if no previous status exists" do + episode.apple_episode_delivery_statuses.destroy_all + assert_difference -> { episode.apple_episode_delivery_statuses.count }, 1 do + new_status = episode.apple_status.increment_asset_wait + assert_equal 1, new_status.asset_processing_attempts + end + end + + it "returns the new status" do + result = episode.apple_status.increment_asset_wait + assert_instance_of Apple::EpisodeDeliveryStatus, result + assert_equal episode.apple_episode_delivery_statuses.last, result + end + end end From 67012e63eb8fda314e783a9ae0ae63224c97cc63 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 3 Oct 2024 14:19:16 -0500 Subject: [PATCH 04/26] Coverage for the publishing->attempt reset --- test/models/apple/publisher_test.rb | 21 +++++++++++++++++++-- 1 file changed, 19 insertions(+), 2 deletions(-) diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index 3f4186bca..77cbcedb2 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -343,16 +343,33 @@ end describe "#publish_drafting!" do + let(:episode1) { build(:uploaded_apple_episode, show: apple_publisher.show, api_response: build(:apple_episode_api_response, publishing_state: "DRAFTING")) } + let(:episode2) { build(:uploaded_apple_episode, show: apple_publisher.show, api_response: build(:apple_episode_api_response, publishing_state: "DRAFTING")) } + let(:episodes) { [episode1, episode2] } + it "should call the episode publish drafting class method" do mock = Minitest::Mock.new - mock.expect(:call, [], [apple_publisher.api, apple_publisher.show, [episode1]]) + mock.expect(:call, [], [Apple::Api, Apple::Show, episodes]) Apple::Episode.stub(:publish, mock) do - apple_publisher.publish_drafting!([episode]) + apple_publisher.publish_drafting!(episodes) end assert mock.verify end + + it "should reset the asset processing attempts" do + episodes.each do |ep| + ep.feeder_episode.apple_update_delivery_status(asset_processing_attempts: 3) + end + mock = Minitest::Mock.new + mock.expect(:call, [], [Apple::Api, Apple::Show, episodes]) + + Apple::Episode.stub(:publish, mock) { apple_publisher.publish_drafting!(episodes) } + + assert_equal 0, episode1.delivery_status.asset_processing_attempts + assert_equal 0, episode2.delivery_status.asset_processing_attempts + end end describe "#wait_for_upload_processing" do From 6e0f6ab60578b4dcd8494223fb86b71d86178d3f Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 3 Oct 2024 14:21:22 -0500 Subject: [PATCH 05/26] fixup! Set up the incrementing --- .../apple_episode_delivery_status_factory.rb | 14 ++++++++++++++ 1 file changed, 14 insertions(+) create mode 100644 test/factories/apple_episode_delivery_status_factory.rb diff --git a/test/factories/apple_episode_delivery_status_factory.rb b/test/factories/apple_episode_delivery_status_factory.rb new file mode 100644 index 000000000..45a927b33 --- /dev/null +++ b/test/factories/apple_episode_delivery_status_factory.rb @@ -0,0 +1,14 @@ +FactoryBot.define do + factory :apple_episode_delivery_status, class: "Apple::EpisodeDeliveryStatus" do + association :episode + + delivered { false } + asset_processing_attempts { 0 } + source_url { "http://example.com/audio.mp3" } + source_size { 1_048_576 } # 1 MB + source_filename { "episode_audio.mp3" } + enclosure_url { "http://cdn.example.com/audio.mp3" } + source_media_version_id { 1 } + source_fetch_count { 0 } + end +end From f71a7bc82a7d817b5b08faa8434d47ea5287edd6 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Mon, 7 Oct 2024 15:59:09 -0500 Subject: [PATCH 06/26] Fixup attempts logging add coverage --- app/models/apple/publisher.rb | 5 +++-- test/models/apple/publisher_test.rb | 30 +++++++++++++++++++++++++++-- 2 files changed, 31 insertions(+), 4 deletions(-) diff --git a/app/models/apple/publisher.rb b/app/models/apple/publisher.rb index bdf70aae7..4464d5819 100644 --- a/app/models/apple/publisher.rb +++ b/app/models/apple/publisher.rb @@ -235,8 +235,9 @@ def wait_for_asset_state(eps) (waiting_timed_out, _) = Apple::Episode.wait_for_asset_state(api, eps) if waiting_timed_out - attempts = eps.max { |ep| ep.apple_episode_delivery_status.asset_processing_attempts } - raise "Timed out waiting for asset state. #{attempts} attempts so far" + attempts = eps.map { |ep| ep.apple_episode_delivery_status.asset_processing_attempts }.max + Rails.logger.info("Timed out waiting for asset state", {attempts: attempts, episode_count: eps.length}) + raise "Timed out waiting for asset state" end end end diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index 77cbcedb2..b79fe75a9 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -1,5 +1,3 @@ -# frozen_string_literal: true - require "test_helper" describe Apple::Publisher do @@ -13,6 +11,8 @@ Apple::Publisher.new(api: apple_api, public_feed: public_feed, private_feed: private_feed) end + let(:publisher) { apple_publisher } + before do stub_request(:get, "https://api.podcastsconnect.apple.com/v1/countriesAndRegions?limit=200") .to_return(status: 200, body: json_file(:apple_countries_and_regions), headers: {}) @@ -404,6 +404,32 @@ end end + it "logs a timeout message with correct information" do + eps = [ + OpenStruct.new( + podcast_delivery_files: [OpenStruct.new(api_marked_as_uploaded?: true)], + apple_episode_delivery_status: OpenStruct.new( + increment_asset_wait: nil, + asset_processing_attempts: 3 + ) + ) + ] * 2 # Create two identical episode structures + + log_message = nil + Rails.logger.stub :tagged, nil do + Rails.logger.stub :info, ->(msg, data) { log_message = [msg, data] } do + Apple::Episode.stub :wait_for_asset_state, [true, nil] do + publisher.wait_for_asset_state(eps) + rescue RuntimeError + # Ignore the exception for this test + end + end + end + + assert_equal "Timed out waiting for asset state", log_message[0] + assert_equal({attempts: 3, episode_count: 2}, log_message[1]) + end + it "should raise an error when wait times out" do episode1.apple_episode_delivery_status.update!(asset_processing_attempts: 3) From bdf510f25200cfa72d01c70b15192e8f58f1e0cf Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Mon, 7 Oct 2024 16:06:47 -0500 Subject: [PATCH 07/26] Coverage for exception --- test/models/apple/publisher_test.rb | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index b79fe75a9..5c6c05246 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -419,9 +419,10 @@ Rails.logger.stub :tagged, nil do Rails.logger.stub :info, ->(msg, data) { log_message = [msg, data] } do Apple::Episode.stub :wait_for_asset_state, [true, nil] do - publisher.wait_for_asset_state(eps) - rescue RuntimeError - # Ignore the exception for this test + error = assert_raises(RuntimeError) do + publisher.wait_for_asset_state(eps) + end + assert_equal "Timed out waiting for asset state", error.message end end end From 8a4565c9400a9d1651bf1f10da9a22bb96c4661c Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Mon, 7 Oct 2024 09:43:04 -0500 Subject: [PATCH 08/26] Avoid logging error via job handling --- app/jobs/publish_apple_job.rb | 8 ++++++-- app/jobs/publish_feed_job.rb | 2 +- test/jobs/publish_feed_job_test.rb | 13 +++++++------ test/models/publishing_pipeline_state_test.rb | 2 +- 4 files changed, 15 insertions(+), 10 deletions(-) diff --git a/app/jobs/publish_apple_job.rb b/app/jobs/publish_apple_job.rb index ffb018097..ba43a635d 100644 --- a/app/jobs/publish_apple_job.rb +++ b/app/jobs/publish_apple_job.rb @@ -5,12 +5,16 @@ def self.publish_to_apple(apple_config) apple_config.build_publisher.publish! end - def perform(apple_config) + def self.do_perform(apple_config) if !apple_config.publish_to_apple? logger.info "Skipping publish to apple for #{apple_config.class.name} #{apple_config.id}" return end - self.class.publish_to_apple(apple_config) + publish_to_apple(apple_config) + end + + def perform(apple_config) + self.class.do_perform(apple_config) end end diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 06934f705..ae458f3a2 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -28,7 +28,7 @@ def perform(podcast, pub_item) def publish_apple(podcast, feed) return unless feed.publish_to_apple? - res = PublishAppleJob.perform_now(feed.apple_config) + res = PublishAppleJob.do_perform(feed.apple_config) PublishingPipelineState.publish_apple!(podcast) res rescue => e diff --git a/test/jobs/publish_feed_job_test.rb b/test/jobs/publish_feed_job_test.rb index 5ac462022..0f3a11cb5 100644 --- a/test/jobs/publish_feed_job_test.rb +++ b/test/jobs/publish_feed_job_test.rb @@ -96,7 +96,7 @@ it "does run the apple publishing if the config is present and marked as publishable" do assert apple_feed.apple_config.present? assert apple_feed.apple_config.publish_enabled - PublishAppleJob.stub(:perform_now, :publishing_apple!) do + PublishAppleJob.stub(:do_perform, :publishing_apple!) do assert_equal :publishing_apple!, job.publish_apple(podcast, apple_feed) end end @@ -108,14 +108,14 @@ # stub the two possible ways the job can be called # perform_later is not used. PublishAppleJob.stub(:perform_later, :perform_later) do - PublishAppleJob.stub(:perform_now, :perform_now) do + PublishAppleJob.stub(:do_perform, :do_perform) do apple_feed.apple_config.update!(sync_blocks_rss: true) - assert_equal :perform_now, job.publish_apple(podcast, apple_feed) + assert_equal :do_perform, job.publish_apple(podcast, apple_feed) apple_feed.apple_config.update!(sync_blocks_rss: false) feed.reload - assert_equal :perform_now, job.publish_apple(podcast, apple_feed) + assert_equal :do_perform, job.publish_apple(podcast, apple_feed) end end end @@ -127,11 +127,12 @@ PublishingPipelineState.attempt!(feed.podcast) PublishingPipelineState.start!(feed.podcast) end + it "raises an error if the apple publishing fails" do assert apple_feed.apple_config.present? assert apple_feed.apple_config.publish_enabled - PublishAppleJob.stub(:perform_now, ->(*, **) { raise "some apple error" }) do + PublishAppleJob.stub(:do_perform, ->(*, **) { raise "some apple error" }) do # it raises assert_raises(RuntimeError) { job.publish_apple(podcast, apple_feed) } @@ -147,7 +148,7 @@ mock = Minitest::Mock.new mock.expect(:call, nil, [RuntimeError]) - PublishAppleJob.stub(:perform_now, ->(*, **) { raise "some apple error" }) do + PublishAppleJob.stub(:do_perform, ->(*, **) { raise "some apple error" }) do NewRelic::Agent.stub(:notice_error, mock) do job.publish_apple(podcast, apple_feed) end diff --git a/test/models/publishing_pipeline_state_test.rb b/test/models/publishing_pipeline_state_test.rb index 4f3803f0c..ea5e7c613 100644 --- a/test/models/publishing_pipeline_state_test.rb +++ b/test/models/publishing_pipeline_state_test.rb @@ -303,7 +303,7 @@ it "can publish via the apple configs" do assert [f1, f2, f3] - PublishAppleJob.stub(:perform_now, "published apple!") do + PublishAppleJob.stub(:do_perform, "published apple!") do PublishFeedJob.stub_any_instance(:save_file, "saved rss!") do PublishingPipelineState.attempt!(podcast, perform_later: false) end From 1822900bcb7f0ece17981532d2767d9b62804ce6 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Mon, 7 Oct 2024 15:40:36 -0500 Subject: [PATCH 09/26] Avoid raising error to duplicate error line --- app/jobs/publish_feed_job.rb | 1 - 1 file changed, 1 deletion(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index ae458f3a2..f9b2349fe 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -21,7 +21,6 @@ def perform(podcast, pub_item) rescue => e PublishingPipelineState.error!(podcast) Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: e.message, backtrace: e.backtrace.join("\n")}) - raise e ensure PublishingPipelineState.settle_remaining!(podcast) end From c70e2643fb4c18ad755ba5c1c3cfc4bae4eadc0c Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Tue, 8 Oct 2024 12:29:56 -0500 Subject: [PATCH 10/26] Add comment --- app/jobs/publish_feed_job.rb | 1 + 1 file changed, 1 insertion(+) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index f9b2349fe..7ff0d44ad 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -20,6 +20,7 @@ def perform(podcast, pub_item) PublishingPipelineState.complete!(podcast) rescue => e PublishingPipelineState.error!(podcast) + # TODO, we can remove this once we have a better way to track errors Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: e.message, backtrace: e.backtrace.join("\n")}) ensure PublishingPipelineState.settle_remaining!(podcast) From 46592c9ce8d1155a4a091bf499c672e5534cc70b Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Wed, 9 Oct 2024 09:55:42 -0500 Subject: [PATCH 11/26] Thread through new error interface --- app/jobs/publish_feed_job.rb | 3 +++ app/models/apple/asset_state_timeout_error.rb | 15 +++++++++++ app/models/apple/publisher.rb | 8 +++--- test/models/apple/publisher_test.rb | 26 ++++++++++++------- test/models/publishing_pipeline_state_test.rb | 13 +++++++++- test/test_helper.rb | 13 ++++++++++ 6 files changed, 63 insertions(+), 15 deletions(-) create mode 100644 app/models/apple/asset_state_timeout_error.rb diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 7ff0d44ad..2157b9d95 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -18,6 +18,9 @@ def perform(podcast, pub_item) podcast.feeds.each { |feed| publish_apple(podcast, feed) } podcast.feeds.each { |feed| publish_rss(podcast, feed) } PublishingPipelineState.complete!(podcast) + rescue Apple::AssetStateTimeoutError => e + PublishingPipelineState.error!(podcast) + Rails.logger.error("Asset processing timeout", {podcast_id: podcast.id, error: e.message, backtrace: e.backtrace.join("\n")}) rescue => e PublishingPipelineState.error!(podcast) # TODO, we can remove this once we have a better way to track errors diff --git a/app/models/apple/asset_state_timeout_error.rb b/app/models/apple/asset_state_timeout_error.rb new file mode 100644 index 000000000..da981c256 --- /dev/null +++ b/app/models/apple/asset_state_timeout_error.rb @@ -0,0 +1,15 @@ +module Apple + class AssetStateTimeoutError < RuntimeError + attr_reader :episodes, :attempts + + def initialize(episodes) + @episodes = episodes + @attempts = episodes.map { |ep| ep.apple_episode_delivery_status.asset_processing_attempts }.max + super("Timeout waiting for asset state change: Episodes: #{episode_ids} Attempts: #{attempts}") + end + + def episode_ids + episodes.map(&:feeder_id) + end + end +end diff --git a/app/models/apple/publisher.rb b/app/models/apple/publisher.rb index 4464d5819..a2c1fbd37 100644 --- a/app/models/apple/publisher.rb +++ b/app/models/apple/publisher.rb @@ -233,11 +233,11 @@ def wait_for_asset_state(eps) # Mark the episodes as waiting again for asset processing eps.each { |ep| ep.apple_episode_delivery_status.increment_asset_wait } - (waiting_timed_out, _) = Apple::Episode.wait_for_asset_state(api, eps) + (waiting_timed_out, remaining_eps) = Apple::Episode.wait_for_asset_state(api, eps) if waiting_timed_out - attempts = eps.map { |ep| ep.apple_episode_delivery_status.asset_processing_attempts }.max - Rails.logger.info("Timed out waiting for asset state", {attempts: attempts, episode_count: eps.length}) - raise "Timed out waiting for asset state" + e = Apple::AssetStateTimeoutError.new(remaining_eps) + Rails.logger.info("Timed out waiting for asset state", {attempts: e.attempts, episode_count: e.episodes.length}) + raise e end end end diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index 5c6c05246..55f7e8f3c 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -414,21 +414,27 @@ ) ) ] * 2 # Create two identical episode structures + eps = eps.map.with_index do |e, i| # Set the feeder_id to a unique value + e = e.dup + e.feeder_id = i + 1 + e + end - log_message = nil - Rails.logger.stub :tagged, nil do - Rails.logger.stub :info, ->(msg, data) { log_message = [msg, data] } do - Apple::Episode.stub :wait_for_asset_state, [true, nil] do - error = assert_raises(RuntimeError) do - publisher.wait_for_asset_state(eps) - end - assert_equal "Timed out waiting for asset state", error.message + assert publisher + logs = capture_json_logs do + Apple::Episode.stub :wait_for_asset_state, [true, eps] do + error = assert_raises(RuntimeError) do + publisher.wait_for_asset_state(eps) end + assert_equal "Timeout waiting for asset state change: Episodes: [1, 2] Attempts: 3", error.message end end - assert_equal "Timed out waiting for asset state", log_message[0] - assert_equal({attempts: 3, episode_count: 2}, log_message[1]) + log = logs[0] + assert_equal "Timed out waiting for asset state", log[:msg] + assert_equal 30, log[:level] + assert_equal 3, log[:attempts] + assert_equal 2, log[:episode_count] end it "should raise an error when wait times out" do diff --git a/test/models/publishing_pipeline_state_test.rb b/test/models/publishing_pipeline_state_test.rb index ea5e7c613..70db46bd8 100644 --- a/test/models/publishing_pipeline_state_test.rb +++ b/test/models/publishing_pipeline_state_test.rb @@ -251,13 +251,24 @@ describe "error!" do it 'sets the status to "error"' do + pqi = nil PublishFeedJob.stub_any_instance(:save_file, nil) do PublishFeedJob.stub_any_instance(:publish_apple, ->(*args) { raise "error" }) do - assert_raises(RuntimeError) { PublishingPipelineState.attempt!(podcast, perform_later: false) } + pqi = PublishingQueueItem.ensure_queued!(podcast) + PublishingPipelineState.attempt!(podcast, perform_later: false) end end assert_equal ["created", "started", "error"].sort, PublishingPipelineState.where(podcast: podcast).map(&:status).sort + assert_equal "error", pqi.reload.last_pipeline_state + + # it retries + PublishingPipelineState.retry_failed_pipelines! + assert_equal ["created", "started", "error", "created"].sort, PublishingPipelineState.where(podcast: podcast).map(&:status).sort + res_pqi = PublishingQueueItem.current_unfinished_item(podcast) + + assert res_pqi.id > pqi.id + assert_equal "created", res_pqi.last_pipeline_state end end diff --git a/test/test_helper.rb b/test/test_helper.rb index 0efc19100..5e27ee50f 100644 --- a/test/test_helper.rb +++ b/test/test_helper.rb @@ -49,6 +49,19 @@ class Minitest::Spec include FactoryBot::Syntax::Methods end +def capture_json_logs(&block) + old_logger = Rails.logger + log = StringIO.new + feeder_logger = FeederLogger.new(log) + feeder_logger.formatter = Ougai::Formatters::Bunyan.new + Rails.logger = ActiveSupport::TaggedLogging.new(feeder_logger) + block.call + log.rewind + log.read.split("\n").map { |line| JSON.parse(line).with_indifferent_access } +ensure + Rails.logger = old_logger +end + def json_file(name) test_file("/fixtures/#{name}.json") end From 849cf4cde00b16a912add4c773e5325f3dc5740b Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Wed, 9 Oct 2024 10:57:52 -0500 Subject: [PATCH 12/26] Use custom log capturer --- test/models/apple/publisher_test.rb | 36 +++++++++++++---------------- test/test_helper.rb | 13 +++++++++++ 2 files changed, 29 insertions(+), 20 deletions(-) diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index 5c6c05246..606166ad5 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -414,31 +414,27 @@ ) ) ] * 2 # Create two identical episode structures + eps = eps.map.with_index do |e, i| # Set the feeder_id to a unique value + e = e.dup + e.feeder_id = i + 1 + e + end - log_message = nil - Rails.logger.stub :tagged, nil do - Rails.logger.stub :info, ->(msg, data) { log_message = [msg, data] } do - Apple::Episode.stub :wait_for_asset_state, [true, nil] do - error = assert_raises(RuntimeError) do - publisher.wait_for_asset_state(eps) - end - assert_equal "Timed out waiting for asset state", error.message + assert publisher + logs = capture_json_logs do + Apple::Episode.stub :wait_for_asset_state, [true, eps] do + error = assert_raises(RuntimeError) do + publisher.wait_for_asset_state(eps) end + assert_equal "Timed out waiting for asset state", error.message end end - assert_equal "Timed out waiting for asset state", log_message[0] - assert_equal({attempts: 3, episode_count: 2}, log_message[1]) - end - - it "should raise an error when wait times out" do - episode1.apple_episode_delivery_status.update!(asset_processing_attempts: 3) - - Apple::Episode.stub(:wait_for_asset_state, [true, episodes]) do - assert_raises(RuntimeError, "Timed out waiting for asset state. 3 attempts so far") do - apple_publisher.wait_for_asset_state(episodes) - end - end + log = logs[0] + assert_equal "Timed out waiting for asset state", log[:msg] + assert_equal 30, log[:level] + assert_equal 3, log[:attempts] + assert_equal 2, log[:episode_count] end end diff --git a/test/test_helper.rb b/test/test_helper.rb index 0efc19100..5e27ee50f 100644 --- a/test/test_helper.rb +++ b/test/test_helper.rb @@ -49,6 +49,19 @@ class Minitest::Spec include FactoryBot::Syntax::Methods end +def capture_json_logs(&block) + old_logger = Rails.logger + log = StringIO.new + feeder_logger = FeederLogger.new(log) + feeder_logger.formatter = Ougai::Formatters::Bunyan.new + Rails.logger = ActiveSupport::TaggedLogging.new(feeder_logger) + block.call + log.rewind + log.read.split("\n").map { |line| JSON.parse(line).with_indifferent_access } +ensure + Rails.logger = old_logger +end + def json_file(name) test_file("/fixtures/#{name}.json") end From e349c743eb6df0ebef5f89f6dc92b4e6f74ee28a Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Mon, 14 Oct 2024 13:56:05 -0500 Subject: [PATCH 13/26] Flatten error handling remove sync_blocks_rss from state flow --- app/jobs/publish_feed_job.rb | 45 +++-- test/jobs/publish_feed_job_test.rb | 165 +++++++++--------- test/models/publishing_pipeline_state_test.rb | 3 +- 3 files changed, 121 insertions(+), 92 deletions(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 2157b9d95..3545fe50d 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -19,32 +19,51 @@ def perform(podcast, pub_item) podcast.feeds.each { |feed| publish_rss(podcast, feed) } PublishingPipelineState.complete!(podcast) rescue Apple::AssetStateTimeoutError => e - PublishingPipelineState.error!(podcast) - Rails.logger.error("Asset processing timeout", {podcast_id: podcast.id, error: e.message, backtrace: e.backtrace.join("\n")}) + handle_apple_timeout_error(podcast, e) rescue => e - PublishingPipelineState.error!(podcast) - # TODO, we can remove this once we have a better way to track errors - Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: e.message, backtrace: e.backtrace.join("\n")}) + handle_error(podcast, e) ensure PublishingPipelineState.settle_remaining!(podcast) end def publish_apple(podcast, feed) return unless feed.publish_to_apple? - res = PublishAppleJob.do_perform(feed.apple_config) - PublishingPipelineState.publish_apple!(podcast) - res - rescue => e - NewRelic::Agent.notice_error(e) - res = PublishingPipelineState.error_apple!(podcast) - raise e if feed.apple_config.sync_blocks_rss? - res + + begin + res = PublishAppleJob.do_perform(podcast.apple_config) + PublishingPipelineState.publish_apple!(podcast) + res + rescue => e + PublishingPipelineState.error_apple!(podcast) + NewRelic::Agent.notice_error(e) + raise e + end end def publish_rss(podcast, feed) res = save_file(podcast, feed) PublishingPipelineState.publish_rss!(podcast) res + rescue => e + handle_rss_error(podcast, feed, e) + end + + def handle_apple_timeout_error(podcast, error, raise_error: true) + PublishingPipelineState.error!(podcast) + Rails.logger.error("Asset processing timeout", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) + raise error + end + + def handle_rss_error(podcast, feed, error) + PublishingPipelineState.error!(podcast) + Rails.logger.error("Error publishing RSS", {podcast_id: podcast.id, feed_id: feed.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) + raise error + end + + def handle_error(podcast, error) + PublishingPipelineState.error!(podcast) + Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) + raise error end def save_file(podcast, feed, options = {}) diff --git a/test/jobs/publish_feed_job_test.rb b/test/jobs/publish_feed_job_test.rb index 0f3a11cb5..693d975a6 100644 --- a/test/jobs/publish_feed_job_test.rb +++ b/test/jobs/publish_feed_job_test.rb @@ -4,7 +4,7 @@ let(:episode) { create(:episode, prx_uri: "/api/v1/stories/87683") } let(:podcast) { episode.podcast } let(:feed) { create(:feed, podcast: podcast, slug: "adfree") } - let(:private_feed) { create(:private_feed, podcast: podcast) } + let(:private_feed) { create(:apple_feed, podcast: podcast) } let(:job) { PublishFeedJob.new } @@ -25,71 +25,109 @@ end end - it "can process publishing a podcast" do + it "transitions to the error state upon rss error" do job.stub(:s3_client, stub_client) do - PublishFeedJob.stub(:perform_later, nil) do - PublishingPipelineState.start_pipeline!(podcast) - end - - pub_item = PublishingQueueItem.unfinished_items(podcast).first - - rss = job.perform(podcast, pub_item) - refute_nil rss - refute_nil job.put_object - assert_nil job.copy_object + PublishingPipelineState.start_pipeline!(podcast) + assert_raises(RuntimeError) { job.handle_rss_error(podcast, feed, RuntimeError.new("rss error")) } + assert_equal ["created", "error"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.pluck(:status) end end - it "will skip the publishing if the pub items are mismatched" do + it "transitions to the error state upon general error" do + # Simulate some method blowing up job.stub(:s3_client, stub_client) do - PublishFeedJob.stub(:perform_later, nil) do - PublishingPipelineState.start_pipeline!(podcast) + PublishingPipelineState.start_pipeline!(podcast) + PublishingPipelineState.stub(:publish_rss!, ->(*, **) { raise "some general" }) do + assert_raises(RuntimeError) { job.handle_rss_error(podcast, feed, RuntimeError.new("some general")) } + assert_equal ["created", "error"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.pluck(:status) end - - pub_item = PublishingQueueItem.create(podcast: podcast) - assert job.mismatched_publishing_item?(podcast, pub_item) - assert_equal :mismatched, job.perform(podcast, pub_item) end end - it "will skip the publishing if the pub items are null" do - job.stub(:s3_client, stub_client) do - assert PublishingQueueItem.unfinished_items(podcast).empty? + describe "validations of the publishing pipeline" do + it "can process publishing a podcast" do + job.stub(:s3_client, stub_client) do + PublishFeedJob.stub(:perform_later, nil) do + PublishingPipelineState.start_pipeline!(podcast) + end - assert job.null_publishing_item?(podcast, nil) - assert_equal :null, job.perform(podcast, nil) + pub_item = PublishingQueueItem.unfinished_items(podcast).first - # There is no currently running publishing pipeline - pub_item = PublishingQueueItem.create(podcast: podcast) - assert job.null_publishing_item?(podcast, pub_item) - assert_equal :null, job.perform(podcast, pub_item) + rss = job.perform(podcast, pub_item) + refute_nil rss + refute_nil job.put_object + assert_nil job.copy_object + end + end - # `settle_remaining` is called at the end of the publishing job - # This means pub_item has been picked up and scheduled - assert_equal "created", pub_item.reload.last_pipeline_state - PublishingPipelineState.complete!(podcast) - assert_equal "complete", pub_item.reload.last_pipeline_state + it "will skip the publishing if the pub items are mismatched" do + job.stub(:s3_client, stub_client) do + PublishFeedJob.stub(:perform_later, nil) do + PublishingPipelineState.start_pipeline!(podcast) + end - # Start a pipeline: Create publishing item and transition that item's pipeline to :created - queue_item = PublishingPipelineState.start_pipeline!(podcast) + pub_item = PublishingQueueItem.create(podcast: podcast) + assert job.mismatched_publishing_item?(podcast, pub_item) + assert_equal :mismatched, job.perform(podcast, pub_item) + end + end + + it "will skip the publishing if the pub items are null" do + job.stub(:s3_client, stub_client) do + assert PublishingQueueItem.unfinished_items(podcast).empty? + + assert job.null_publishing_item?(podcast, nil) + assert_equal :null, job.perform(podcast, nil) - refute job.null_publishing_item?(podcast, queue_item) - res = job.perform(podcast, queue_item) - refute_equal :null, res + # There is no currently running publishing pipeline + pub_item = PublishingQueueItem.create(podcast: podcast) + assert job.null_publishing_item?(podcast, pub_item) + + PublishAppleJob.stub(:do_perform, :publishing_apple!) do + assert_equal :null, job.perform(podcast, pub_item) + end + + # `settle_remaining` is called at the end of the publishing job + # This means pub_item has been picked up and scheduled + assert_equal "created", pub_item.reload.last_pipeline_state + PublishingPipelineState.complete!(podcast) + assert_equal "complete", pub_item.reload.last_pipeline_state + + # Start a pipeline: Create publishing item and transition that item's pipeline to :created + queue_item = PublishingPipelineState.start_pipeline!(podcast) + + refute job.null_publishing_item?(podcast, queue_item) + PublishAppleJob.stub(:do_perform, :publishing_apple!) do + refute_equal :null, job.perform(podcast, queue_item) + end + end end end end describe "publishing to apple" do - it "does not schedule publishing to apple if the feed is non-apple" do - assert_nil job.publish_apple(podcast, private_feed) + let(:apple_feed) { private_feed } + let(:apple_config) { podcast.apple_config } + + before do + assert private_feed.persisted? + assert podcast.reload.apple_config.present? end - describe "when the apple config is present" do - let(:apple_feed) { create(:apple_feed, podcast: podcast) } + it "does not schedule publishing to apple if the apple config prevents it" do + podcast.apple_config.update!(publish_enabled: false) + assert_nil job.publish_apple(podcast, apple_feed) + end + + it "does not schedule publishing to apple if the apple config is disabled" do + apple_config.update!(publish_enabled: false) + assert_nil job.publish_apple(podcast, apple_feed) + end + describe "when the apple config is present" do it "does not schedule publishing to apple if the config is marked as not publishable" do - apple_feed.apple_config.update!(publish_enabled: false) + podcast.apple_config.update!(publish_enabled: false) + assert_nil job.publish_apple(podcast, apple_feed) end @@ -101,31 +139,10 @@ end end - it "Performs the apple publishing job based regardless of sync_blocks_rss flag" do - assert apple_feed.apple_config.present? - assert apple_feed.apple_config.publish_enabled - - # stub the two possible ways the job can be called - # perform_later is not used. - PublishAppleJob.stub(:perform_later, :perform_later) do - PublishAppleJob.stub(:do_perform, :do_perform) do - apple_feed.apple_config.update!(sync_blocks_rss: true) - - assert_equal :do_perform, job.publish_apple(podcast, apple_feed) - - apple_feed.apple_config.update!(sync_blocks_rss: false) - feed.reload - assert_equal :do_perform, job.publish_apple(podcast, apple_feed) - end - end - end - describe "when the apple publishing fails" do before do # Simulate a publishing attempt PublishingQueueItem.create!(podcast: feed.podcast) - PublishingPipelineState.attempt!(feed.podcast) - PublishingPipelineState.start!(feed.podcast) end it "raises an error if the apple publishing fails" do @@ -133,29 +150,21 @@ assert apple_feed.apple_config.publish_enabled PublishAppleJob.stub(:do_perform, ->(*, **) { raise "some apple error" }) do - # it raises - assert_raises(RuntimeError) { job.publish_apple(podcast, apple_feed) } + assert_raises(RuntimeError) { PublishingPipelineState.attempt!(feed.podcast, perform_later: false) } - assert_equal ["created", "started", "error_apple"].sort, PublishingPipelineState.where(podcast: feed.podcast).latest_pipelines.pluck(:status).sort + assert_equal ["created", "started", "error", "error_apple"].sort, PublishingPipelineState.where(podcast: feed.podcast).latest_pipelines.pluck(:status).sort end end - it "does not raise an error if the apple publishing is not blocking RSS" do + it "raises an error if the apple publishing times out" do assert apple_feed.apple_config.present? assert apple_feed.apple_config.publish_enabled - apple_feed.apple_config.update!(sync_blocks_rss: false) - mock = Minitest::Mock.new - mock.expect(:call, nil, [RuntimeError]) + PublishAppleJob.stub(:do_perform, ->(*, **) { raise Apple::AssetStateTimeoutError.new([]) }) do + assert_raises(Apple::AssetStateTimeoutError) { PublishingPipelineState.attempt!(feed.podcast, perform_later: false) } - PublishAppleJob.stub(:do_perform, ->(*, **) { raise "some apple error" }) do - NewRelic::Agent.stub(:notice_error, mock) do - job.publish_apple(podcast, apple_feed) - end + assert_equal ["created", "started", "error", "error_apple"].sort, PublishingPipelineState.where(podcast: feed.podcast).latest_pipelines.pluck(:status).sort end - assert_equal ["created", "started", "error_apple"].sort, PublishingPipelineState.where(podcast: feed.podcast).latest_pipelines.pluck(:status).sort - - mock.verify end end end diff --git a/test/models/publishing_pipeline_state_test.rb b/test/models/publishing_pipeline_state_test.rb index 70db46bd8..820524a6d 100644 --- a/test/models/publishing_pipeline_state_test.rb +++ b/test/models/publishing_pipeline_state_test.rb @@ -255,7 +255,8 @@ PublishFeedJob.stub_any_instance(:save_file, nil) do PublishFeedJob.stub_any_instance(:publish_apple, ->(*args) { raise "error" }) do pqi = PublishingQueueItem.ensure_queued!(podcast) - PublishingPipelineState.attempt!(podcast, perform_later: false) + + assert_raises(RuntimeError) { PublishingPipelineState.attempt!(podcast, perform_later: false) } end end From 9e361ca2838882d18fa9aa585ae052bf651529b6 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Mon, 14 Oct 2024 14:31:07 -0500 Subject: [PATCH 14/26] Break out into separate methods Fix for reset of non-drafting --- app/models/apple/publisher.rb | 17 ++++++++++- test/models/apple/publisher_test.rb | 45 ++++++++++++++++++++++++----- 2 files changed, 54 insertions(+), 8 deletions(-) diff --git a/app/models/apple/publisher.rb b/app/models/apple/publisher.rb index 4464d5819..9c61a9d18 100644 --- a/app/models/apple/publisher.rb +++ b/app/models/apple/publisher.rb @@ -148,9 +148,12 @@ def deliver_and_publish!(eps) mark_delivery_files_uploaded!(eps) wait_for_upload_processing(eps) + + increment_asset_wait!(eps) wait_for_asset_state(eps) publish_drafting!(eps) + reset_asset_wait!(eps) raise_delivery_processing_errors(eps) end @@ -226,12 +229,18 @@ def wait_for_upload_processing(eps) end end - def wait_for_asset_state(eps) + def increment_asset_wait!(eps) Rails.logger.tagged("##{__method__}") do eps = eps.filter { |e| e.podcast_delivery_files.any?(&:api_marked_as_uploaded?) } # Mark the episodes as waiting again for asset processing eps.each { |ep| ep.apple_episode_delivery_status.increment_asset_wait } + end + end + + def wait_for_asset_state(eps) + Rails.logger.tagged("##{__method__}") do + eps = eps.filter { |e| e.podcast_delivery_files.any?(&:api_marked_as_uploaded?) } (waiting_timed_out, _) = Apple::Episode.wait_for_asset_state(api, eps) if waiting_timed_out @@ -376,6 +385,12 @@ def publish_drafting!(eps) end end + def reset_asset_wait!(eps) + Rails.logger.tagged("##{__method__}") do + eps.each { |ep| ep.apple_episode_delivery_status.reset_asset_wait } + end + end + # Not used in any of the polling or publish routines, but useful for # debugging. This removes the audio container reference from the episode, # but leaves the podcast container intact. diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index 606166ad5..e056abe2f 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -357,15 +357,35 @@ assert mock.verify end + end + + describe "#reset_asset_wait!" do + let(:episode1) { build(:uploaded_apple_episode, show: apple_publisher.show) } + let(:episode2) { build(:uploaded_apple_episode, show: apple_publisher.show) } + let(:episodes) { [episode1, episode2] } it "should reset the asset processing attempts" do episodes.each do |ep| ep.feeder_episode.apple_update_delivery_status(asset_processing_attempts: 3) end - mock = Minitest::Mock.new - mock.expect(:call, [], [Apple::Api, Apple::Show, episodes]) + assert_equal 3, episode1.delivery_status.asset_processing_attempts + assert_equal 3, episode2.delivery_status.asset_processing_attempts + + apple_publisher.reset_asset_wait!(episodes) + + assert_equal 0, episode1.delivery_status.asset_processing_attempts + assert_equal 0, episode2.delivery_status.asset_processing_attempts + end - Apple::Episode.stub(:publish, mock) { apple_publisher.publish_drafting!(episodes) } + it "should reset the asset processing attempts for non-drafting episodes" do + episodes.each do |ep| + ep.feeder_episode.apple_update_delivery_status(asset_processing_attempts: 3) + end + + assert_equal 3, episode1.delivery_status.asset_processing_attempts + assert_equal 3, episode2.delivery_status.asset_processing_attempts + + apple_publisher.reset_asset_wait!(episodes) assert_equal 0, episode1.delivery_status.asset_processing_attempts assert_equal 0, episode2.delivery_status.asset_processing_attempts @@ -385,7 +405,7 @@ end end - describe "#wait_for_asset_state" do + describe "#increment_asset_wait!" do let(:episode1) { build(:uploaded_apple_episode, show: apple_publisher.show) } let(:episode2) { build(:uploaded_apple_episode, show: apple_publisher.show) } let(:episodes) { [episode1, episode2] } @@ -395,15 +415,26 @@ assert_equal 0, ep.apple_episode_delivery_status.asset_processing_attempts end - Apple::Episode.stub(:wait_for_asset_state, [false, []]) do - apple_publisher.wait_for_asset_state(episodes) - end + apple_publisher.increment_asset_wait!(episodes) episodes.each do |ep| assert_equal 1, ep.apple_episode_delivery_status.asset_processing_attempts end end + it "should only increment the episodes that are still waiting" do + assert 1, episode1.podcast_delivery_files.length + assert 1, episode2.podcast_delivery_files.length + + episode2.podcast_delivery_files.first.stub(:api_marked_as_uploaded?, false) do + episode1.podcast_delivery_files.first.stub(:api_marked_as_uploaded?, true) do + apple_publisher.increment_asset_wait!(episodes) + end + end + + assert_equal [1, 0], [episode1, episode2].map { |ep| ep.apple_episode_delivery_status.asset_processing_attempts } + end + it "logs a timeout message with correct information" do eps = [ OpenStruct.new( From ccc9c62d7eb0f286b0896a34d2c992381c01071d Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 17 Oct 2024 15:58:38 -0500 Subject: [PATCH 15/26] Guard for deleted episodes --- app/controllers/episodes_controller.rb | 2 +- app/models/apple/episode_delivery_status.rb | 2 +- test/factories/apple_episode_factory.rb | 6 +++++- test/models/apple/episode_delivery_status_test.rb | 9 +++++++++ 4 files changed, 16 insertions(+), 3 deletions(-) diff --git a/app/controllers/episodes_controller.rb b/app/controllers/episodes_controller.rb index 305b0b05f..53d16e877 100644 --- a/app/controllers/episodes_controller.rb +++ b/app/controllers/episodes_controller.rb @@ -92,7 +92,7 @@ def destroy respond_to do |format| if @episode.destroy - @episode.podcast.publish! + @episode.publish! format.html { redirect_to podcast_episodes_url(@episode.podcast_id), notice: t(".notice") } else format.html do diff --git a/app/models/apple/episode_delivery_status.rb b/app/models/apple/episode_delivery_status.rb index 01201865a..f15f985ad 100644 --- a/app/models/apple/episode_delivery_status.rb +++ b/app/models/apple/episode_delivery_status.rb @@ -1,6 +1,6 @@ module Apple class EpisodeDeliveryStatus < ApplicationRecord - belongs_to :episode, class_name: "::Episode" + belongs_to :episode, -> { with_deleted }, class_name: "::Episode" def self.update_status(episode, attrs) new_status = (episode.apple_episode_delivery_status&.dup || new(episode: episode)) diff --git a/test/factories/apple_episode_factory.rb b/test/factories/apple_episode_factory.rb index 52a4aa928..ef8458758 100644 --- a/test/factories/apple_episode_factory.rb +++ b/test/factories/apple_episode_factory.rb @@ -11,7 +11,11 @@ # set a complete episode factory varient factory :uploaded_apple_episode do - feeder_episode { create(:episode, apple_episode_delivery_statuses: [Apple::EpisodeDeliveryStatus.new(delivered: true)]) } + feeder_episode do + ep = create(:episode) + ep.apple_has_delivery! + ep + end transient do api_response do build(:apple_episode_api_response, diff --git a/test/models/apple/episode_delivery_status_test.rb b/test/models/apple/episode_delivery_status_test.rb index 8cc1c1835..5dafad1e6 100644 --- a/test/models/apple/episode_delivery_status_test.rb +++ b/test/models/apple/episode_delivery_status_test.rb @@ -9,6 +9,15 @@ class Apple::EpisodeDeliveryStatusTest < ActiveSupport::TestCase it "belongs to an episode" do assert_equal episode, delivery_status.episode end + + it "can belong to deleted episodes" do + episode.destroy + assert_equal episode, delivery_status.episode + assert_difference "Apple::EpisodeDeliveryStatus.count", +1 do + episode.apple_needs_delivery! + end + assert_equal episode, episode.apple_episode_delivery_statuses.first.episode + end end describe "scopes" do From e1902721371ea899e62afdd9d76beb14f0ff8d1e Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 17 Oct 2024 16:02:23 -0500 Subject: [PATCH 16/26] Clarify that the default is used in both places --- app/models/apple/episode_delivery_status.rb | 6 +++++- app/models/concerns/apple_delivery.rb | 2 +- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/app/models/apple/episode_delivery_status.rb b/app/models/apple/episode_delivery_status.rb index f15f985ad..5781c180c 100644 --- a/app/models/apple/episode_delivery_status.rb +++ b/app/models/apple/episode_delivery_status.rb @@ -3,13 +3,17 @@ class EpisodeDeliveryStatus < ApplicationRecord belongs_to :episode, -> { with_deleted }, class_name: "::Episode" def self.update_status(episode, attrs) - new_status = (episode.apple_episode_delivery_status&.dup || new(episode: episode)) + new_status = (episode.apple_episode_delivery_status&.dup || default_status(episode)) new_status.assign_attributes(attrs) new_status.save! episode.apple_episode_delivery_statuses.reset new_status end + def self.default_status(episode) + new(episode: episode) + end + def increment_asset_wait self.class.update_status(episode, asset_processing_attempts: (asset_processing_attempts || 0) + 1) end diff --git a/app/models/concerns/apple_delivery.rb b/app/models/concerns/apple_delivery.rb index f7ff901de..afdfd8497 100644 --- a/app/models/concerns/apple_delivery.rb +++ b/app/models/concerns/apple_delivery.rb @@ -26,7 +26,7 @@ def apple_update_delivery_status(attrs) end def build_initial_delivery_status - Apple::EpisodeDeliveryStatus.new(episode: self) + Apple::EpisodeDeliveryStatus.default_status(self) end def apple_episode_delivery_status From 60db10185540d5922b4fc67fbf4879ebf523dba1 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 17 Oct 2024 16:50:06 -0500 Subject: [PATCH 17/26] Revert back to guard --- app/models/apple/episode.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/app/models/apple/episode.rb b/app/models/apple/episode.rb index fd96f05ac..9d8a2c801 100644 --- a/app/models/apple/episode.rb +++ b/app/models/apple/episode.rb @@ -491,7 +491,7 @@ def audio_asset_state_success? end def has_media_version? - return false unless delivery_status.source_media_version_id.present? + return false unless delivery_status.present? && delivery_status.source_media_version_id.present? delivery_status.source_media_version_id == feeder_episode.media_version_id end From fd6720692df522a623af4efae010c63aef0baf7a Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 17 Oct 2024 18:17:07 -0500 Subject: [PATCH 18/26] Log the duration also --- app/models/apple/publisher.rb | 3 +- app/models/concerns/apple_delivery.rb | 12 ++++ .../apple/episode_delivery_status_test.rb | 70 +++++++++++++++++++ test/models/apple/publisher_test.rb | 55 ++++++++------- 4 files changed, 112 insertions(+), 28 deletions(-) diff --git a/app/models/apple/publisher.rb b/app/models/apple/publisher.rb index 9c61a9d18..a46ab425f 100644 --- a/app/models/apple/publisher.rb +++ b/app/models/apple/publisher.rb @@ -245,7 +245,8 @@ def wait_for_asset_state(eps) (waiting_timed_out, _) = Apple::Episode.wait_for_asset_state(api, eps) if waiting_timed_out attempts = eps.map { |ep| ep.apple_episode_delivery_status.asset_processing_attempts }.max - Rails.logger.info("Timed out waiting for asset state", {attempts: attempts, episode_count: eps.length}) + max_duration = eps.map { |ep| ep.feeder_episode.measure_asset_processing_duration }.compact.max + Rails.logger.info("Timed out waiting for asset state", {attempts: attempts, duration: max_duration, episode_count: eps.length}) raise "Timed out waiting for asset state" end end diff --git a/app/models/concerns/apple_delivery.rb b/app/models/concerns/apple_delivery.rb index afdfd8497..e1ffc3859 100644 --- a/app/models/concerns/apple_delivery.rb +++ b/app/models/concerns/apple_delivery.rb @@ -46,4 +46,16 @@ def apple_needs_delivery! def apple_has_delivery! apple_update_delivery_status(delivered: true) end + + def measure_asset_processing_duration + statuses = apple_episode_delivery_statuses.to_a + + last_status = statuses.shift + return nil unless last_status&.asset_processing_attempts.to_i.positive? + + start_status = statuses.find { |status| status.asset_processing_attempts.to_i.zero? } + return nil unless start_status + + Time.now - start_status.created_at + end end diff --git a/test/models/apple/episode_delivery_status_test.rb b/test/models/apple/episode_delivery_status_test.rb index 5dafad1e6..04cf8e3e0 100644 --- a/test/models/apple/episode_delivery_status_test.rb +++ b/test/models/apple/episode_delivery_status_test.rb @@ -126,4 +126,74 @@ class Apple::EpisodeDeliveryStatusTest < ActiveSupport::TestCase end end end + + describe "#measure_asset_processing_duration" do + let(:episode) { create(:episode) } + + before do + travel_to Time.now + end + + after do + travel_back + end + + it "returns nil when there are no delivery statuses" do + assert_nil episode.measure_asset_processing_duration + end + + it "returns nil when the latest status has zero attempts" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 1.hour.ago) + assert_nil episode.measure_asset_processing_duration + end + + it "measures duration for contiguous increments" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 5.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 1, created_at: 4.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 2, created_at: 3.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 3, created_at: 2.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 4, created_at: 1.hour.ago) + + assert_equal 5, episode.reload.measure_asset_processing_duration / 1.hour + end + + it "measures duration for non-contiguous increments" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 3.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 4, created_at: 2.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 5, created_at: 1.hour.ago) + + assert_equal 3, episode.measure_asset_processing_duration / 1.hour + end + + it "handles reset attempts correctly" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 5.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 1, created_at: 4.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 2, created_at: 3.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 2.hours.ago) # reset + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 1, created_at: 1.hour.ago) + + assert_equal 2, episode.measure_asset_processing_duration / 1.hour + end + + it "returns nil when all attempts are zero" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 2.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 1.hour.ago) + + assert_nil episode.measure_asset_processing_duration + end + + it "handles nil asset_processing_attempts correctly" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 1, created_at: 1.hour.ago) + + assert_nil episode.measure_asset_processing_duration + end + + it "returns correct duration when latest attempt is zero" do + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 3.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 1, created_at: 2.hours.ago) + create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 0, created_at: 1.hour.ago) + + assert_nil episode.measure_asset_processing_duration + end + end end diff --git a/test/models/apple/publisher_test.rb b/test/models/apple/publisher_test.rb index e056abe2f..48ff43e5a 100644 --- a/test/models/apple/publisher_test.rb +++ b/test/models/apple/publisher_test.rb @@ -436,36 +436,37 @@ end it "logs a timeout message with correct information" do - eps = [ - OpenStruct.new( - podcast_delivery_files: [OpenStruct.new(api_marked_as_uploaded?: true)], - apple_episode_delivery_status: OpenStruct.new( - increment_asset_wait: nil, - asset_processing_attempts: 3 - ) - ) - ] * 2 # Create two identical episode structures - eps = eps.map.with_index do |e, i| # Set the feeder_id to a unique value - e = e.dup - e.feeder_id = i + 1 - e - end - - assert publisher - logs = capture_json_logs do - Apple::Episode.stub :wait_for_asset_state, [true, eps] do - error = assert_raises(RuntimeError) do - publisher.wait_for_asset_state(eps) + travel_to Time.now do + # Set up the delivery statuses + eps = [episode1, episode2] + eps.map { |e| e.feeder_episode.apple_episode_delivery_statuses.map(&:destroy) } + + # Here is the log of attempts + create(:apple_episode_delivery_status, episode: episode1.feeder_episode, asset_processing_attempts: 0, created_at: 4.hour.ago) + create(:apple_episode_delivery_status, episode: episode1.feeder_episode, asset_processing_attempts: 1, created_at: 3.hour.ago) + create(:apple_episode_delivery_status, episode: episode1.feeder_episode, asset_processing_attempts: 2, created_at: 2.hour.ago) + create(:apple_episode_delivery_status, episode: episode1.feeder_episode, asset_processing_attempts: 3, created_at: 1.hour.ago) + eps.map(&:feeder_episode).map(&:reload) + + # now simulate the asset timeout + assert publisher + logs = capture_json_logs do + Apple::Episode.stub :wait_for_asset_state, [true, eps] do + error = assert_raises(RuntimeError) do + publisher.wait_for_asset_state(eps) + end + assert_equal "Timed out waiting for asset state", error.message end - assert_equal "Timed out waiting for asset state", error.message end - end - log = logs[0] - assert_equal "Timed out waiting for asset state", log[:msg] - assert_equal 30, log[:level] - assert_equal 3, log[:attempts] - assert_equal 2, log[:episode_count] + # look at the logs + log = logs[0] + assert_equal "Timed out waiting for asset state", log[:msg] + assert_equal 30, log[:level] + assert_equal 3, log[:attempts] + assert_equal 4 * 60 * 60, log[:duration] + assert_equal 2, log[:episode_count] + end end end From 7f477f739cc89b6f47fc34b432d2ba162f5a01c9 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Fri, 18 Oct 2024 10:30:15 -0500 Subject: [PATCH 19/26] Remove whitespace --- test/models/episode_test.rb | 1 - 1 file changed, 1 deletion(-) diff --git a/test/models/episode_test.rb b/test/models/episode_test.rb index 12cd71169..0ef8f4d8e 100644 --- a/test/models/episode_test.rb +++ b/test/models/episode_test.rb @@ -491,7 +491,6 @@ episode.transcript.status = "complete" refute_nil episode.ready_transcript - end end From 4199fb8b82b5180c534bbd289ab50586af2d2da0 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Fri, 18 Oct 2024 11:16:43 -0500 Subject: [PATCH 20/26] Follow apple pattern for RSS --- app/jobs/publish_feed_job.rb | 12 ++++-- app/models/publishing_pipeline_state.rb | 7 +++- test/jobs/publish_feed_job_test.rb | 52 +++++++++++++++++-------- 3 files changed, 49 insertions(+), 22 deletions(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 3545fe50d..75eb2bc85 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -34,9 +34,7 @@ def publish_apple(podcast, feed) PublishingPipelineState.publish_apple!(podcast) res rescue => e - PublishingPipelineState.error_apple!(podcast) - NewRelic::Agent.notice_error(e) - raise e + handle_apple_error(podcast, e) end end @@ -54,8 +52,14 @@ def handle_apple_timeout_error(podcast, error, raise_error: true) raise error end + def handle_apple_error(podcast, error) + PublishingPipelineState.error_apple!(podcast) + NewRelic::Agent.notice_error(error) + raise error + end + def handle_rss_error(podcast, feed, error) - PublishingPipelineState.error!(podcast) + PublishingPipelineState.error_rss!(podcast) Rails.logger.error("Error publishing RSS", {podcast_id: podcast.id, feed_id: feed.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) raise error end diff --git a/app/models/publishing_pipeline_state.rb b/app/models/publishing_pipeline_state.rb index c6b82c0fe..3fcb5baf7 100644 --- a/app/models/publishing_pipeline_state.rb +++ b/app/models/publishing_pipeline_state.rb @@ -52,7 +52,8 @@ class PublishingPipelineState < ApplicationRecord :complete, :error, :expired, - :error_apple + :error_apple, + :error_rss ] validate :podcast_ids_match @@ -153,6 +154,10 @@ def self.error_apple!(podcast) state_transition(podcast, :error_apple) end + def self.error_rss!(podcast) + state_transition(podcast, :error_rss) + end + def self.complete!(podcast) state_transition(podcast, :complete) end diff --git a/test/jobs/publish_feed_job_test.rb b/test/jobs/publish_feed_job_test.rb index 693d975a6..6264c3c05 100644 --- a/test/jobs/publish_feed_job_test.rb +++ b/test/jobs/publish_feed_job_test.rb @@ -1,6 +1,7 @@ require "test_helper" describe PublishFeedJob do + let(:stub_client) { Aws::S3::Client.new(stub_responses: true) } let(:episode) { create(:episode, prx_uri: "/api/v1/stories/87683") } let(:podcast) { episode.podcast } let(:feed) { create(:feed, podcast: podcast, slug: "adfree") } @@ -16,7 +17,18 @@ end describe "saving the rss file" do - let(:stub_client) { Aws::S3::Client.new(stub_responses: true) } + describe "#perform" do + it "transitions to the error state upon general error" do + job.stub(:s3_client, stub_client) do + pqi = PublishingPipelineState.start_pipeline!(podcast) + # Simulate some method blowing up + PublishingPipelineState.stub(:publish_rss!, ->(*, **) { raise "some general" }) do + assert_raises(RuntimeError) { job.perform(podcast, pqi) } + assert_equal ["created", "started", "error_rss", "error"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.order(id: :asc).pluck(:status) + end + end + end + end it "can save a podcast file" do job.stub(:s3_client, stub_client) do @@ -26,22 +38,9 @@ end it "transitions to the error state upon rss error" do - job.stub(:s3_client, stub_client) do - PublishingPipelineState.start_pipeline!(podcast) - assert_raises(RuntimeError) { job.handle_rss_error(podcast, feed, RuntimeError.new("rss error")) } - assert_equal ["created", "error"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.pluck(:status) - end - end - - it "transitions to the error state upon general error" do - # Simulate some method blowing up - job.stub(:s3_client, stub_client) do - PublishingPipelineState.start_pipeline!(podcast) - PublishingPipelineState.stub(:publish_rss!, ->(*, **) { raise "some general" }) do - assert_raises(RuntimeError) { job.handle_rss_error(podcast, feed, RuntimeError.new("some general")) } - assert_equal ["created", "error"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.pluck(:status) - end - end + PublishingPipelineState.start_pipeline!(podcast) + assert_raises(RuntimeError) { job.handle_rss_error(podcast, feed, RuntimeError.new("rss error")) } + assert_equal ["created", "error_rss"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.order(id: :asc).pluck(:status) end describe "validations of the publishing pipeline" do @@ -114,6 +113,25 @@ assert podcast.reload.apple_config.present? end + describe "#perform" do + it "transitions to the error state upon general apple error" do + job.stub(:s3_client, stub_client) do + pqi = PublishingPipelineState.start_pipeline!(podcast) + # Simulate some method blowing up + PublishAppleJob.stub(:do_perform, ->(*, **) { raise "some apple error" }) do + assert_raises(RuntimeError) { job.perform(podcast, pqi) } + assert_equal ["created", "started", "error_apple", "error"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.order(id: :asc).pluck(:status) + end + end + end + end + + it "transitions to the apple_error state upon general apple error" do + PublishingPipelineState.start_pipeline!(podcast) + assert_raises(RuntimeError) { job.handle_apple_error(podcast, RuntimeError.new("apple error")) } + assert_equal ["created", "error_apple"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.pluck(:status) + end + it "does not schedule publishing to apple if the apple config prevents it" do podcast.apple_config.update!(publish_enabled: false) assert_nil job.publish_apple(podcast, apple_feed) From 30b37d21864bd9e2a9ac982609076679cdf4df80 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 24 Oct 2024 10:02:58 -0500 Subject: [PATCH 21/26] Move the job error handlers next to where they are used --- app/jobs/publish_feed_job.rb | 39 +++++++++++++++++++----------------- 1 file changed, 21 insertions(+), 18 deletions(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 75eb2bc85..f9e3700f9 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -26,6 +26,21 @@ def perform(podcast, pub_item) PublishingPipelineState.settle_remaining!(podcast) end + def handle_apple_timeout_error(podcast, error, raise_error: true) + PublishingPipelineState.error!(podcast) + Rails.logger.error("Asset processing timeout", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) + raise error + end + + def handle_error(podcast, error) + PublishingPipelineState.error!(podcast) + # Two error log lines here. + # 1) the error message and backtrace: + Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) + # 2) The second is from the job handler, which logs an error when this excetion is raised: + raise error + end + def publish_apple(podcast, feed) return unless feed.publish_to_apple? @@ -38,6 +53,12 @@ def publish_apple(podcast, feed) end end + def handle_apple_error(podcast, error) + PublishingPipelineState.error_apple!(podcast) + NewRelic::Agent.notice_error(error) + raise error + end + def publish_rss(podcast, feed) res = save_file(podcast, feed) PublishingPipelineState.publish_rss!(podcast) @@ -46,30 +67,12 @@ def publish_rss(podcast, feed) handle_rss_error(podcast, feed, e) end - def handle_apple_timeout_error(podcast, error, raise_error: true) - PublishingPipelineState.error!(podcast) - Rails.logger.error("Asset processing timeout", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) - raise error - end - - def handle_apple_error(podcast, error) - PublishingPipelineState.error_apple!(podcast) - NewRelic::Agent.notice_error(error) - raise error - end - def handle_rss_error(podcast, feed, error) PublishingPipelineState.error_rss!(podcast) Rails.logger.error("Error publishing RSS", {podcast_id: podcast.id, feed_id: feed.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) raise error end - def handle_error(podcast, error) - PublishingPipelineState.error!(podcast) - Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) - raise error - end - def save_file(podcast, feed, options = {}) rss = FeedBuilder.new(podcast, feed).to_feed_xml opts = default_options.merge(options) From aaa26061cd56246ae473a81a260aae6530ff34f1 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 31 Oct 2024 11:29:55 -0500 Subject: [PATCH 22/26] Extract apple related concerns --- app/models/concerns/apple_delivery.rb | 20 ++++++++ app/models/episode.rb | 20 -------- test/models/episode_test.rb | 73 --------------------------- 3 files changed, 20 insertions(+), 93 deletions(-) diff --git a/app/models/concerns/apple_delivery.rb b/app/models/concerns/apple_delivery.rb index e1ffc3859..0083481b7 100644 --- a/app/models/concerns/apple_delivery.rb +++ b/app/models/concerns/apple_delivery.rb @@ -58,4 +58,24 @@ def measure_asset_processing_duration Time.now - start_status.created_at end + + def apple_prepare_for_delivery! + # remove the previous delivery attempt (soft delete) + apple_podcast_deliveries.map(&:destroy) + apple_podcast_deliveries.reset + apple_podcast_delivery_files.reset + apple_podcast_container&.podcast_deliveries&.reset + end + + def apple_mark_for_reupload! + apple_needs_delivery! + end + + def apple_episode + return nil if !persisted? || !publish_to_apple? + + if (show = podcast.apple_config&.build_publisher&.show) + Apple::Episode.new(api: show.api, show: show, feeder_episode: self) + end + end end diff --git a/app/models/episode.rb b/app/models/episode.rb index e303459ce..36e9826e1 100644 --- a/app/models/episode.rb +++ b/app/models/episode.rb @@ -243,26 +243,6 @@ def copy_media(force = false) uncut&.copy_media(force) end - def apple_prepare_for_delivery! - # remove the previous delivery attempt (soft delete) - apple_podcast_deliveries.map(&:destroy) - apple_podcast_deliveries.reset - apple_podcast_delivery_files.reset - apple_podcast_container&.podcast_deliveries&.reset - end - - def apple_mark_for_reupload! - apple_needs_delivery! - end - - def apple_episode - return nil if !persisted? || !publish_to_apple? - - if (show = podcast.apple_config&.build_publisher&.show) - Apple::Episode.new(api: show.api, show: show, feeder_episode: self) - end - end - def publish! Rails.logger.tagged("Episode#publish!") do apple_mark_for_reupload! diff --git a/test/models/episode_test.rb b/test/models/episode_test.rb index 0ef8f4d8e..7b5be02e1 100644 --- a/test/models/episode_test.rb +++ b/test/models/episode_test.rb @@ -448,35 +448,6 @@ end end - describe "#apple_episode" do - let(:episode) { create(:episode) } - it "gets nil for no apple episode" do - assert_nil episode.apple_episode - end - end - - describe "#apple_needs_delivery?" do - let(:episode) { create(:episode) } - it "is true by default" do - refute episode.apple_episode_delivery_status.persisted? - assert episode.apple_needs_delivery? - end - - it "can be set to false" do - episode.apple_has_delivery! - refute episode.apple_needs_delivery? - end - - it "can be set to true" do - episode.apple_has_delivery! - refute episode.apple_needs_delivery? - - # now set it to true - episode.apple_needs_delivery! - assert episode.apple_needs_delivery? - end - end - describe "#ready_transcript" do let(:episode) { build_stubbed(:episode) } @@ -493,48 +464,4 @@ refute_nil episode.ready_transcript end end - - describe "#increment_asset_wait" do - let(:episode) { create(:episode) } - - it "creates a new status with incremented asset_processing_attempts" do - assert_difference -> { episode.apple_episode_delivery_statuses.count }, 1 do - new_status = episode.apple_status.increment_asset_wait - assert_equal 1, new_status.asset_processing_attempts - end - end - - it "increments existing asset_processing_attempts" do - create(:apple_episode_delivery_status, episode: episode, asset_processing_attempts: 2) - new_status = episode.apple_status.increment_asset_wait - assert_equal 3, new_status.asset_processing_attempts - end - - it "maintains other attributes when incrementing" do - create(:apple_episode_delivery_status, - episode: episode, - delivered: true, - source_url: "http://example.com/audio.mp3", - asset_processing_attempts: 1) - - new_status = episode.apple_status.increment_asset_wait - assert_equal 2, new_status.asset_processing_attempts - assert new_status.delivered - assert_equal "http://example.com/audio.mp3", new_status.source_url - end - - it "creates a new status with asset_processing_attempts set to 1 if no previous status exists" do - episode.apple_episode_delivery_statuses.destroy_all - assert_difference -> { episode.apple_episode_delivery_statuses.count }, 1 do - new_status = episode.apple_status.increment_asset_wait - assert_equal 1, new_status.asset_processing_attempts - end - end - - it "returns the new status" do - result = episode.apple_status.increment_asset_wait - assert_instance_of Apple::EpisodeDeliveryStatus, result - assert_equal episode.apple_episode_delivery_statuses.last, result - end - end end From 5efb84c201ae6711664fdf22fc8e881c2259b88a Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 31 Oct 2024 13:21:33 -0500 Subject: [PATCH 23/26] Follow sync_blocks_rss flag --- app/jobs/application_job.rb | 6 +++++- app/jobs/publish_feed_job.rb | 2 +- test/jobs/publish_feed_job_test.rb | 16 ++++++++++++++++ 3 files changed, 22 insertions(+), 2 deletions(-) diff --git a/app/jobs/application_job.rb b/app/jobs/application_job.rb index 36e8c29c3..6e629dd87 100644 --- a/app/jobs/application_job.rb +++ b/app/jobs/application_job.rb @@ -21,7 +21,7 @@ def s3_bucket ENV["FEEDER_STORAGE_BUCKET"] end - def s3_client + def self.s3_client if Rails.env.test? || ENV["AWS_ACCESS_KEY_ID"].present? Aws::S3::Client.new( credentials: Aws::Credentials.new(ENV["AWS_ACCESS_KEY_ID"], ENV["AWS_SECRET_ACCESS_KEY"]), @@ -31,4 +31,8 @@ def s3_client Aws::S3::Client.new end end + + def s3_client + self.class.s3_client + end end diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index f9e3700f9..a55fd2876 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -56,7 +56,7 @@ def publish_apple(podcast, feed) def handle_apple_error(podcast, error) PublishingPipelineState.error_apple!(podcast) NewRelic::Agent.notice_error(error) - raise error + raise error if podcast.apple_config.sync_blocks_rss end def publish_rss(podcast, feed) diff --git a/test/jobs/publish_feed_job_test.rb b/test/jobs/publish_feed_job_test.rb index 6264c3c05..59fc2b810 100644 --- a/test/jobs/publish_feed_job_test.rb +++ b/test/jobs/publish_feed_job_test.rb @@ -174,6 +174,22 @@ end end + it "does not raise an error if the apple publishing fails and apple sync does not block rss publishing" do + assert apple_feed.apple_config.present? + assert apple_feed.apple_config.publish_enabled + apple_feed.apple_config.update!(sync_blocks_rss: false) + feed.reload + + PublishFeedJob.stub(:s3_client, stub_client) do + PublishAppleJob.stub(:do_perform, ->(*, **) { raise "some apple error" }) do + # no error raised + PublishingPipelineState.attempt!(feed.podcast, perform_later: false) + + assert_equal ["created", "started", "error_apple", "published_rss", "published_rss", "published_rss", "complete"].sort, PublishingPipelineState.where(podcast: feed.podcast).latest_pipelines.pluck(:status).sort + end + end + end + it "raises an error if the apple publishing times out" do assert apple_feed.apple_config.present? assert apple_feed.apple_config.publish_enabled From c55a71dba65fca3721e5db05dca31d9314447847 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 31 Oct 2024 14:23:22 -0500 Subject: [PATCH 24/26] Try to simplify the error flow --- app/jobs/publish_feed_job.rb | 54 ++++++++++++------------------ test/jobs/publish_feed_job_test.rb | 12 ------- 2 files changed, 21 insertions(+), 45 deletions(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index a55fd2876..955e09de4 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -19,57 +19,45 @@ def perform(podcast, pub_item) podcast.feeds.each { |feed| publish_rss(podcast, feed) } PublishingPipelineState.complete!(podcast) rescue Apple::AssetStateTimeoutError => e - handle_apple_timeout_error(podcast, e) + fail_state(podcast, "apple_timeout", e) rescue => e - handle_error(podcast, e) + fail_state(podcast, "error", e) ensure PublishingPipelineState.settle_remaining!(podcast) end - def handle_apple_timeout_error(podcast, error, raise_error: true) - PublishingPipelineState.error!(podcast) - Rails.logger.error("Asset processing timeout", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) - raise error - end - - def handle_error(podcast, error) - PublishingPipelineState.error!(podcast) - # Two error log lines here. - # 1) the error message and backtrace: - Rails.logger.error("Error publishing podcast", {podcast_id: podcast.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) - # 2) The second is from the job handler, which logs an error when this excetion is raised: - raise error - end - def publish_apple(podcast, feed) return unless feed.publish_to_apple? - begin - res = PublishAppleJob.do_perform(podcast.apple_config) - PublishingPipelineState.publish_apple!(podcast) - res - rescue => e - handle_apple_error(podcast, e) + res = PublishAppleJob.do_perform(podcast.apple_config) + PublishingPipelineState.publish_apple!(podcast) + res + rescue => e + if podcast.apple_config.sync_blocks_rss + fail_state(podcast, "apple", e) + else + Rails.logger.error("Error publishing to Apple, but continuing to publish RSS", {podcast_id: podcast.id, error: e.message}) + PublishingPipelineState.error_apple!(podcast) end end - def handle_apple_error(podcast, error) - PublishingPipelineState.error_apple!(podcast) - NewRelic::Agent.notice_error(error) - raise error if podcast.apple_config.sync_blocks_rss - end - def publish_rss(podcast, feed) res = save_file(podcast, feed) PublishingPipelineState.publish_rss!(podcast) res rescue => e - handle_rss_error(podcast, feed, e) + fail_state(podcast, "rss", e) end - def handle_rss_error(podcast, feed, error) - PublishingPipelineState.error_rss!(podcast) - Rails.logger.error("Error publishing RSS", {podcast_id: podcast.id, feed_id: feed.id, error: error.message, backtrace: error&.backtrace&.join("\n")}) + def fail_state(podcast, type, error) + method = case type + when "apple" then :error_apple! + when "rss" then :error_rss! + when "apple_timeout", "error" then :error! + end + + PublishingPipelineState.public_send(method, podcast) + Rails.logger.error(error.message, {podcast_id: podcast.id, error_type: type}) raise error end diff --git a/test/jobs/publish_feed_job_test.rb b/test/jobs/publish_feed_job_test.rb index 59fc2b810..f21445bbf 100644 --- a/test/jobs/publish_feed_job_test.rb +++ b/test/jobs/publish_feed_job_test.rb @@ -37,12 +37,6 @@ end end - it "transitions to the error state upon rss error" do - PublishingPipelineState.start_pipeline!(podcast) - assert_raises(RuntimeError) { job.handle_rss_error(podcast, feed, RuntimeError.new("rss error")) } - assert_equal ["created", "error_rss"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.order(id: :asc).pluck(:status) - end - describe "validations of the publishing pipeline" do it "can process publishing a podcast" do job.stub(:s3_client, stub_client) do @@ -126,12 +120,6 @@ end end - it "transitions to the apple_error state upon general apple error" do - PublishingPipelineState.start_pipeline!(podcast) - assert_raises(RuntimeError) { job.handle_apple_error(podcast, RuntimeError.new("apple error")) } - assert_equal ["created", "error_apple"], PublishingPipelineState.where(podcast: podcast).latest_pipelines.pluck(:status) - end - it "does not schedule publishing to apple if the apple config prevents it" do podcast.apple_config.update!(publish_enabled: false) assert_nil job.publish_apple(podcast, apple_feed) From 0f6ac5683ef49abef8667d04d21fea6601e84464 Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 31 Oct 2024 14:51:01 -0500 Subject: [PATCH 25/26] Ensure a single error log line --- app/jobs/publish_feed_job.rb | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 955e09de4..083446a1d 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -50,14 +50,14 @@ def publish_rss(podcast, feed) end def fail_state(podcast, type, error) - method = case type - when "apple" then :error_apple! - when "rss" then :error_rss! - when "apple_timeout", "error" then :error! + (method, level) = case type + when "apple" then [:error_apple!, :warn] + when "rss" then [:error_rss!, :warn] + when "apple_timeout", "error" then [:error!, :error] end PublishingPipelineState.public_send(method, podcast) - Rails.logger.error(error.message, {podcast_id: podcast.id, error_type: type}) + Rails.logger.send(level, error.message, {podcast_id: podcast.id}) raise error end From f397ce9dda2af4a27cbb3d5dd867d2b3fdfc455d Mon Sep 17 00:00:00 2001 From: Sam Vevang Date: Thu, 31 Oct 2024 14:59:16 -0500 Subject: [PATCH 26/26] Clarify naming --- app/jobs/publish_feed_job.rb | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/app/jobs/publish_feed_job.rb b/app/jobs/publish_feed_job.rb index 083446a1d..d25f9e271 100644 --- a/app/jobs/publish_feed_job.rb +++ b/app/jobs/publish_feed_job.rb @@ -50,14 +50,14 @@ def publish_rss(podcast, feed) end def fail_state(podcast, type, error) - (method, level) = case type + (pipeline_method, log_level) = case type when "apple" then [:error_apple!, :warn] when "rss" then [:error_rss!, :warn] when "apple_timeout", "error" then [:error!, :error] end - PublishingPipelineState.public_send(method, podcast) - Rails.logger.send(level, error.message, {podcast_id: podcast.id}) + PublishingPipelineState.public_send(pipeline_method, podcast) + Rails.logger.send(log_level, error.message, {podcast_id: podcast.id}) raise error end