From c4b7a98f7f81c63b46753f4ba28410456f71ca40 Mon Sep 17 00:00:00 2001
From: "Michael B. Klein" <mbklein@gmail.com>
Date: Wed, 24 Apr 2024 20:42:10 +0000
Subject: [PATCH] Add more logging to ARK listener

---
 app/lib/meadow/ark_listener.ex | 18 +++++++++++++-----
 app/lib/meadow/utils/arks.ex   |  6 ++++++
 2 files changed, 19 insertions(+), 5 deletions(-)

diff --git a/app/lib/meadow/ark_listener.ex b/app/lib/meadow/ark_listener.ex
index 7ea4422ce..e2ee7f2bc 100644
--- a/app/lib/meadow/ark_listener.ex
+++ b/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)
diff --git a/app/lib/meadow/utils/arks.ex b/app/lib/meadow/utils/arks.ex
index 808c32baa..74cf9677a 100644
--- a/app/lib/meadow/utils/arks.ex
+++ b/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)}")