[Ehnacement] More gracefully handle Sponsorblock failures (#169)

* Updated downloader and runner to handle sponsorblock failures more gracefully

* stopped download worker from running if a media item is preventing download

lib/pinchflat/downloading/media_download_worker.ex

@@ -40,8 +40,8 @@ defmodule Pinchflat.Downloading.MediaDownloadWorker do
       |> Media.get_media_item!()
       |> Repo.preload(:source)
 
-    # If the source is set to not download media, perform a no-op
+    # If the source or media item is set to not download media, perform a no-op unless forced
-    if media_item.source.download_media || args["force"] do
+    if (media_item.source.download_media && !media_item.prevent_download) || args["force"] do
       download_media_and_schedule_jobs(media_item)
     else
       :ok
@@ -58,9 +58,10 @@ defmodule Pinchflat.Downloading.MediaDownloadWorker do
 
         {:ok, updated_media_item}
 
-      err ->
+      {:recovered, _} ->
-        Logger.error("Failed to download media for media item #{media_item.id}: #{inspect(err)}")
+        {:error, :retry}
 
+      {:error, _message} ->
         {:error, :download_failed}
     end
   end

lib/pinchflat/downloading/media_downloader.ex

@@ -5,12 +5,15 @@ defmodule Pinchflat.Downloading.MediaDownloader do
   to download the media with the desired options.
   """
 
+  require Logger
+
   alias Pinchflat.Repo
   alias Pinchflat.Media
   alias Pinchflat.Media.MediaItem
   alias Pinchflat.Metadata.NfoBuilder
   alias Pinchflat.Metadata.MetadataParser
   alias Pinchflat.Metadata.MetadataFileHelpers
+  alias Pinchflat.Filesystem.FilesystemHelpers
   alias Pinchflat.Downloading.DownloadOptionBuilder
 
   alias Pinchflat.YtDlp.Media, as: YtDlpMedia
@@ -27,33 +30,69 @@ defmodule Pinchflat.Downloading.MediaDownloader do
   Returns {:ok, %MediaItem{}} | {:error, any, ...any}
   """
   def download_for_media_item(%MediaItem{} = media_item) do
-    item_with_preloads = Repo.preload(media_item, [:metadata, source: :media_profile])
+    output_filepath = FilesystemHelpers.generate_metadata_tmpfile(:json)
+    media_with_preloads = Repo.preload(media_item, [:metadata, source: :media_profile])
 
-    case download_with_options(media_item.original_url, item_with_preloads) do
+    case download_with_options(media_item.original_url, media_with_preloads, output_filepath) do
       {:ok, parsed_json} ->
-        parsed_attrs =
+        update_media_item_from_parsed_json(media_with_preloads, parsed_json)
-          parsed_json
-          |> MetadataParser.parse_for_media_item()
-          |> Map.merge(%{
-            media_downloaded_at: DateTime.utc_now(),
-            nfo_filepath: determine_nfo_filepath(item_with_preloads, parsed_json),
-            metadata: %{
-              # IDEA: might be worth kicking off a job for this since thumbnail fetching
-              # could fail and I want to handle that in isolation
-              metadata_filepath: MetadataFileHelpers.compress_and_store_metadata_for(media_item, parsed_json),
-              thumbnail_filepath: MetadataFileHelpers.download_and_store_thumbnail_for(media_item, parsed_json)
-            }
-          })
 
-        # Don't forgor to use preloaded associations or updates to
+      {:error, message, _exit_code} ->
-        # associations won't work!
+        Logger.error("yt-dlp download error for media item ##{media_with_preloads.id}: #{inspect(message)}")
-        Media.update_media_item(item_with_preloads, parsed_attrs)
+
+        if String.contains?(to_string(message), recoverable_errors()) do
+          attempt_update_media_item(media_with_preloads, output_filepath)
+
+          {:recovered, message}
+        else
+          {:error, message}
+        end
 
       err ->
-        err
+        Logger.error("Unknown error downloading media item ##{media_with_preloads.id}: #{inspect(err)}")
+
+        {:error, "Unknown error: #{inspect(err)}"}
     end
   end
 
+  defp attempt_update_media_item(media_with_preloads, output_filepath) do
+    with {:ok, contents} <- File.read(output_filepath),
+         {:ok, parsed_json} <- Phoenix.json_library().decode(contents) do
+      Logger.info("""
+      Recovery from yt-dlp error seems possible. Updating media item ##{media_with_preloads.id}
+      with parsed JSON from partial download attempt. Full download will be re-attemted in future
+      anyway
+      """)
+
+      update_media_item_from_parsed_json(media_with_preloads, parsed_json)
+    else
+      err ->
+        Logger.error("Unable to recover error for media item ##{media_with_preloads.id}: #{inspect(err)}")
+
+        {:error, :retry_failed}
+    end
+  end
+
+  defp update_media_item_from_parsed_json(media_with_preloads, parsed_json) do
+    parsed_attrs =
+      parsed_json
+      |> MetadataParser.parse_for_media_item()
+      |> Map.merge(%{
+        media_downloaded_at: DateTime.utc_now(),
+        nfo_filepath: determine_nfo_filepath(media_with_preloads, parsed_json),
+        metadata: %{
+          # IDEA: might be worth kicking off a job for this since thumbnail fetching
+          # could fail and I want to handle that in isolation
+          metadata_filepath: MetadataFileHelpers.compress_and_store_metadata_for(media_with_preloads, parsed_json),
+          thumbnail_filepath: MetadataFileHelpers.download_and_store_thumbnail_for(media_with_preloads, parsed_json)
+        }
+      })
+
+    # Don't forgor to use preloaded associations or updates to
+    # associations won't work!
+    Media.update_media_item(media_with_preloads, parsed_attrs)
+  end
+
   defp determine_nfo_filepath(media_item, parsed_json) do
     if media_item.source.media_profile.download_nfo do
       filepath = Path.rootname(parsed_json["filepath"]) <> ".nfo"
@@ -64,9 +103,15 @@ defmodule Pinchflat.Downloading.MediaDownloader do
     end
   end
 
-  defp download_with_options(url, item_with_preloads) do
+  defp download_with_options(url, item_with_preloads, output_filepath) do
     {:ok, options} = DownloadOptionBuilder.build(item_with_preloads)
 
-    YtDlpMedia.download(url, options)
+    YtDlpMedia.download(url, options, output_filepath: output_filepath)
+  end
+
+  defp recoverable_errors do
+    [
+      "Unable to communicate with SponsorBlock"
+    ]
   end
 end

lib/pinchflat/yt_dlp/command_runner.ex

@@ -29,7 +29,7 @@ defmodule Pinchflat.YtDlp.CommandRunner do
     command = backend_executable()
     # These must stay in exactly this order, hence why I'm giving it its own variable.
     # Also, can't use RAM file since yt-dlp needs a concrete filepath.
-    output_filepath = Keyword.get(addl_opts, :output_filepath, FSUtils.generate_metadata_tmpfile(:json))
+    output_filepath = generate_output_filepath(addl_opts)
     print_to_file_opts = [{:print_to_file, output_template}, output_filepath]
     cookie_opts = build_cookie_options()
     formatted_command_opts = [url] ++ parse_options(command_opts ++ print_to_file_opts ++ cookie_opts)
@@ -61,6 +61,13 @@ defmodule Pinchflat.YtDlp.CommandRunner do
     end
   end
 
+  defp generate_output_filepath(addl_opts) do
+    case Keyword.get(addl_opts, :output_filepath) do
+      nil -> FSUtils.generate_metadata_tmpfile(:json)
+      path -> path
+    end
+  end
+
   defp build_cookie_options do
     base_dir = Application.get_env(:pinchflat, :extras_directory)
     cookie_file = Path.join(base_dir, "cookies.txt")

lib/pinchflat/yt_dlp/media.ex

@@ -35,10 +35,10 @@ defmodule Pinchflat.YtDlp.Media do
 
   Returns {:ok, map()} | {:error, any, ...}.
   """
-  def download(url, command_opts \\ []) do
+  def download(url, command_opts \\ [], addl_opts \\ []) do
     opts = [:no_simulate] ++ command_opts
 
-    with {:ok, output} <- backend_runner().run(url, opts, "after_move:%()j"),
+    with {:ok, output} <- backend_runner().run(url, opts, "after_move:%()j", addl_opts),
          {:ok, parsed_json} <- Phoenix.json_library().decode(output) do
       {:ok, parsed_json}
     else

test/pinchflat/downloading/media_download_worker_test.exs

@@ -4,6 +4,7 @@ defmodule Pinchflat.Downloading.MediaDownloadWorkerTest do
   import Mox
   import Pinchflat.MediaFixtures
 
+  alias Pinchflat.Media
   alias Pinchflat.Sources
   alias Pinchflat.Filesystem.FilesystemHelpers
   alias Pinchflat.Downloading.MediaDownloadWorker
@@ -55,7 +56,7 @@ defmodule Pinchflat.Downloading.MediaDownloadWorkerTest do
 
   describe "perform/1" do
     test "it saves attributes to the media_item", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         {:ok, render_metadata(:media_metadata)}
       end)
 
@@ -65,7 +66,7 @@ defmodule Pinchflat.Downloading.MediaDownloadWorkerTest do
     end
 
     test "it saves the metadata to the media_item", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         {:ok, render_metadata(:media_metadata)}
       end)
 
@@ -82,7 +83,19 @@ defmodule Pinchflat.Downloading.MediaDownloadWorkerTest do
     end
 
     test "it sets the job to retryable if the download fails", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot -> {:error, "error"} end)
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl -> {:error, "error"} end)
+
+      Oban.Testing.with_testing_mode(:inline, fn ->
+        {:ok, job} = Oban.insert(MediaDownloadWorker.new(%{id: media_item.id}))
+
+        assert job.state == "retryable"
+      end)
+    end
+
+    test "sets the job to retryable if the download failed and was retried", %{media_item: media_item} do
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
+        {:error, "Unable to communicate with SponsorBlock", 1}
+      end)
 
       Oban.Testing.with_testing_mode(:inline, fn ->
         {:ok, job} = Oban.insert(MediaDownloadWorker.new(%{id: media_item.id}))
@@ -92,29 +105,38 @@ defmodule Pinchflat.Downloading.MediaDownloadWorkerTest do
     end
 
     test "it ensures error are returned in a 2-item tuple", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot -> {:error, "error", 1} end)
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl -> {:error, "error", 1} end)
 
       assert {:error, :download_failed} = perform_job(MediaDownloadWorker, %{id: media_item.id})
     end
 
     test "it does not download if the source is set to not download", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, 0, fn _url, _opts, _ot -> :ok end)
+      expect(YtDlpRunnerMock, :run, 0, fn _url, _opts, _ot, _addl -> :ok end)
 
       Sources.update_source(media_item.source, %{download_media: false})
 
       perform_job(MediaDownloadWorker, %{id: media_item.id})
     end
 
+    test "does not download if the media item is set to not download", %{media_item: media_item} do
+      expect(YtDlpRunnerMock, :run, 0, fn _url, _opts, _ot, _addl -> :ok end)
+
+      Media.update_media_item(media_item, %{prevent_download: true})
+
+      perform_job(MediaDownloadWorker, %{id: media_item.id})
+    end
+
     test "downloads anyway if forced", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot -> :ok end)
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl -> :ok end)
 
       Sources.update_source(media_item.source, %{download_media: false})
+      Media.update_media_item(media_item, %{prevent_download: true})
 
       perform_job(MediaDownloadWorker, %{id: media_item.id, force: true})
     end
 
     test "it saves the file's size to the database", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         metadata = render_parsed_metadata(:media_metadata)
         FilesystemHelpers.write_p!(metadata["filepath"], "test")
 

test/pinchflat/downloading/media_downloader_test.exs

@@ -25,9 +25,11 @@ defmodule Pinchflat.Downloading.MediaDownloaderTest do
 
   describe "download_for_media_item/3" do
     test "it calls the backend runner", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn url, _opts, ot ->
+      expect(YtDlpRunnerMock, :run, fn url, _opts, ot, addl ->
         assert url == media_item.original_url
         assert ot == "after_move:%()j"
+        assert [{:output_filepath, filepath}] = addl
+        assert is_binary(filepath)
 
         {:ok, render_metadata(:media_metadata)}
       end)
@@ -36,7 +38,7 @@ defmodule Pinchflat.Downloading.MediaDownloaderTest do
     end
 
     test "it saves the metadata filepath to the database", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         {:ok, render_metadata(:media_metadata)}
       end)
 
@@ -47,18 +49,56 @@ defmodule Pinchflat.Downloading.MediaDownloaderTest do
       assert updated_media_item.metadata.thumbnail_filepath =~ "media_items/#{media_item.id}/maxresdefault.jpg"
     end
 
-    test "errors are passed through", %{media_item: media_item} do
+    test "non-recoverable errors are passed through", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
-        {:error, :some_error}
+        {:error, :some_error, 1}
       end)
 
       assert {:error, :some_error} = MediaDownloader.download_for_media_item(media_item)
     end
+
+    test "unknown errors are passed through", %{media_item: media_item} do
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
+        {:error, :some_error}
+      end)
+
+      assert {:error, message} = MediaDownloader.download_for_media_item(media_item)
+      assert message == "Unknown error: {:error, :some_error}"
+    end
+  end
+
+  describe "download_for_media_item/3 when testing retries" do
+    test "returns a recovered tuple on recoverable errors", %{media_item: media_item} do
+      message = "Unable to communicate with SponsorBlock"
+
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
+        {:error, message, 1}
+      end)
+
+      assert {:recovered, ^message} = MediaDownloader.download_for_media_item(media_item)
+    end
+
+    test "attempts to update the media item on recoverable errors", %{media_item: media_item} do
+      message = "Unable to communicate with SponsorBlock"
+
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, addl ->
+        [{:output_filepath, filepath}] = addl
+        File.write(filepath, render_metadata(:media_metadata))
+
+        {:error, message, 1}
+      end)
+
+      assert {:recovered, ^message} = MediaDownloader.download_for_media_item(media_item)
+      media_item = Repo.reload(media_item)
+
+      assert DateTime.diff(DateTime.utc_now(), media_item.media_downloaded_at) < 2
+      assert String.ends_with?(media_item.media_filepath, ".mkv")
+    end
   end
 
   describe "download_for_media_item/3 when testing media_item attributes" do
     setup do
-      stub(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      stub(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         {:ok, render_metadata(:media_metadata)}
       end)
 
@@ -100,7 +140,7 @@ defmodule Pinchflat.Downloading.MediaDownloaderTest do
     end
 
     test "it extracts the thumbnail_filepath", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         metadata = render_parsed_metadata(:media_metadata)
 
         thumbnail_filepath =
@@ -124,7 +164,7 @@ defmodule Pinchflat.Downloading.MediaDownloaderTest do
     end
 
     test "it extracts the metadata_filepath", %{media_item: media_item} do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         metadata = render_parsed_metadata(:media_metadata)
 
         infojson_filepath = metadata["infojson_filename"]
@@ -143,7 +183,7 @@ defmodule Pinchflat.Downloading.MediaDownloaderTest do
 
   describe "download_for_media_item/3 when testing NFO generation" do
     setup do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         {:ok, render_metadata(:media_metadata)}
       end)
 

test/pinchflat/yt_dlp/media_test.exs

@@ -11,9 +11,10 @@ defmodule Pinchflat.YtDlp.MediaTest do
 
   describe "download/2" do
     test "it calls the backend runner with the expected arguments" do
-      expect(YtDlpRunnerMock, :run, fn @media_url, opts, ot ->
+      expect(YtDlpRunnerMock, :run, fn @media_url, opts, ot, addl ->
         assert [:no_simulate] = opts
         assert "after_move:%()j" = ot
+        assert addl == []
 
         {:ok, render_metadata(:media_metadata)}
       end)
@@ -22,17 +23,18 @@ defmodule Pinchflat.YtDlp.MediaTest do
     end
 
     test "it passes along additional options" do
-      expect(YtDlpRunnerMock, :run, fn _url, opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, opts, _ot, addl ->
         assert [:no_simulate, :custom_arg] = opts
+        assert [addl_arg: true] = addl
 
         {:ok, "{}"}
       end)
 
-      assert {:ok, _} = Media.download(@media_url, [:custom_arg])
+      assert {:ok, _} = Media.download(@media_url, [:custom_arg], addl_arg: true)
     end
 
     test "it parses and returns the generated file as JSON" do
-      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opts, _ot, _addl ->
         {:ok, render_metadata(:media_metadata)}
       end)
 
@@ -41,7 +43,7 @@ defmodule Pinchflat.YtDlp.MediaTest do
     end
 
     test "it returns errors" do
-      expect(YtDlpRunnerMock, :run, fn _url, _opt, _ot ->
+      expect(YtDlpRunnerMock, :run, fn _url, _opt, _ot, _addl ->
         {:error, "something"}
       end)