Merge pull request #3918 from nulib/4529-ark-notification-logging

Add more logging to ARK listener

app/lib/meadow/ark_listener.ex

@@ -12,17 +12,25 @@ defmodule Meadow.ArkListener do
 
   @impl true
   def handle_notification(:works, :delete, %{id: id}, state) do
-    Arks.work_deleted(id)
-    {:noreply, state}
+    with_log_metadata module: __MODULE__, id: id do
+      Logger.info("Received DELETE notification for ARK on work #{id}")
+      Arks.work_deleted(id)
+      {:noreply, state}
+    end
   end
 
   def handle_notification(:works, :insert, %{id: id}, state) do
-    Works.get_work(id) |> Arks.mint_ark()
-    {:noreply, state}
+    with_log_metadata module: __MODULE__, id: id do
+      Logger.info("Received INSERT notification for ARK on work #{id}")
+      Works.get_work(id) |> Arks.mint_ark()
+      {:noreply, state}
+    end
   end
 
-  def handle_notification(:works, _op, %{id: id}, state) do
+  def handle_notification(:works, op, %{id: id}, state) do
     with_log_metadata module: __MODULE__, id: id do
+      Logger.info("Received #{String.upcase(to_string(op))} notification for ARK on work #{id}")
+
       case Works.get_work!(id) do
         nil -> :noop
         work -> update_ark_metadata(work)

app/lib/meadow/utils/arks.ex

@@ -52,14 +52,18 @@ defmodule Meadow.Arks do
   """
   def mint_ark(%Work{descriptive_metadata: %{ark: ark}} = work)
       when not is_nil(ark) do
+    Logger.warn("Not minting ARK for work #{work.id} because it already has one: #{ark}")
     {:noop, work}
   end
 
   def mint_ark(nil), do: {:noop, nil}
 
   def mint_ark(%Work{} = work) do
+    Logger.info("Minting ARK for work #{work.id}")
+
     case work |> initial_ark() |> Ark.mint() do
       {:ok, result} ->
+        Logger.info("Minted ARK #{result.ark} for work #{work.id}")
         Works.update_work(work, %{descriptive_metadata: %{ark: result.ark}})
 
       {:error, error_message} ->
@@ -106,6 +110,8 @@ defmodule Meadow.Arks do
   end
 
   defp update_existing_ark(work, _, ark) do
+    Logger.info("Updating ARK #{ark.ark} for work #{work.id}")
+
     case Ark.put(ark) do
       {:ok, result} ->
         Logger.info("Ark successfully updated. #{inspect(result)}")