Improve logs

Author: louiscb

lib/remote_persistent_term/fetcher/s3.ex

@@ -68,7 +68,10 @@ defmodule RemotePersistentTerm.Fetcher.S3 do
     with {:ok, versions} <- list_object_versions(state),
          {:ok, %{etag: etag, version_id: version}} <- find_latest(versions) do
       Logger.info(
-        "found latest version of s3://#{state.bucket}/#{state.key}: #{etag} with version: #{version}"
+        bucket: state.bucket,
+        key: state.key,
+        version: version,
+        message: "Found latest version of object"
       )
 
       {:ok, etag}
@@ -80,17 +83,32 @@ defmodule RemotePersistentTerm.Fetcher.S3 do
         {:error, "could not find s3://#{state.bucket}/#{state.key}"}
 
       {:error, reason} ->
-        Logger.error("#{__MODULE__} - s3://#{state.bucket}/#{state.key} - unknown error: #{inspect(reason)}")
+        Logger.error(%{
+          bucket: state.bucket,
+          key: state.key,
+          reason: inspect(reason),
+          message: "Failed to get current version of object - unknown reason"
+        })
+
         {:error, "Unknown error"}
     end
   end
 
   @impl true
   def download(state) do
-    Logger.info("downloading s3://#{state.bucket}/#{state.key}...")
+    Logger.info(
+      bucket: state.bucket,
+      key: state.key,
+      message: "Downloading object from S3"
+    )
 
     with {:ok, %{body: body}} <- get_object(state) do
-      Logger.debug("downloaded s3://#{state.bucket}/#{state.key}!")
+      Logger.debug(
+        bucket: state.bucket,
+        key: state.key,
+        message: "Downloaded object from S3"
+      )
+
       {:ok, body}
     else
       {:error, reason} ->
@@ -134,29 +152,53 @@ defmodule RemotePersistentTerm.Fetcher.S3 do
   defp aws_client_request(op, %{region: region, failover_regions: nil}),
     do: client().request(op, region: region)
 
-  defp aws_client_request(op, %{region: region, bucket: bucket, key: key, failover_regions: failover_regions})
+  defp aws_client_request(
+         op,
+         %{
+           region: region,
+           bucket: bucket,
+           key: key,
+           failover_regions: failover_regions
+         } = state
+       )
        when is_list(failover_regions) do
     with {:error, reason} <- client().request(op, region: region) do
-      Logger.error(
-        "s3://#{bucket}/#{key} - Failed to fetch from primary region #{region}: #{inspect(reason)}, will try failover regions"
-      )
-
-      try_failover_regions(op, failover_regions, bucket, key)
+      Logger.error(%{
+        bucket: bucket,
+        key: key,
+        region: region,
+        reason: inspect(reason),
+        message: "Failed to fetch from primary region, attempting failover regions"
+      })
+
+      try_failover_regions(op, failover_regions, state)
     end
   end
 
-  defp try_failover_regions(_op, [], _bucket, _key), do: {:error, "All regions failed"}
+  defp try_failover_regions(_op, [], _state), do: {:error, "All regions failed"}
 
-  defp try_failover_regions(op, [region | remaining_regions], bucket, key) do
-    Logger.info("s3://#{bucket}/#{key} - Trying failover region: #{region}")
+  defp try_failover_regions(op, [region | remaining_regions], state) do
+    Logger.info(%{
+      bucket: state.bucket,
+      key: state.key,
+      region: region,
+      message: "Trying failover region"
+    })
 
     case client().request(op, region: region) do
       {:ok, result} ->
         {:ok, result}
 
       {:error, reason} ->
-        Logger.error("s3://#{bucket}/#{key} - Failed to fetch from failover region #{region}: #{inspect(reason)}")
-        try_failover_regions(op, remaining_regions, bucket, key)
+        Logger.error(%{
+          bucket: state.bucket,
+          key: state.key,
+          region: region,
+          reason: inspect(reason),
+          message: "Failed to fetch from failover region"
+        })
+
+        try_failover_regions(op, remaining_regions, state)
     end
   end
 

test/remote_persistent_term/fetcher/s3_test.exs

@@ -16,10 +16,16 @@ defmodule RemotePersistentTerm.Fetcher.S3Test do
       {:error, :unknown_error}
     end)
 
-    assert capture_log(fn ->
-             assert {:error, "Unknown error"} = S3.current_version(%S3{bucket: "bucket", key: "key"})
-           end) =~
-             "Elixir.RemotePersistentTerm.Fetcher.S3 - s3://bucket/key - unknown error: :unknown_error"
+    log =
+      capture_log(fn ->
+        assert {:error, "Unknown error"} =
+                 S3.current_version(%S3{bucket: "bucket", key: "key"})
+      end)
+
+    assert log =~ "bucket: \"bucket\""
+    assert log =~ "key: \"key\""
+    assert log =~ "reason: \":unknown_error\""
+    assert log =~ "Failed to get current version of object - unknown reason"
   end
 
   describe "init/1" do
@@ -67,9 +73,13 @@ defmodule RemotePersistentTerm.Fetcher.S3Test do
           assert {:ok, "current-etag"} = result
         end)
 
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from primary region #{@region}"
-      assert log =~ "will try failover regions"
-      assert log =~ "s3://#{@bucket}/#{@key} - Trying failover region: failover-region-1"
+      assert log =~ "bucket: \"#{@bucket}\""
+      assert log =~ "key: \"#{@key}\""
+      assert log =~ "region: \"#{@region}\""
+      assert log =~ "Failed to fetch from primary region, attempting failover regions"
+      assert log =~ "region: \"failover-region-1\""
+      assert log =~ "Trying failover region"
+      assert log =~ "Found latest version of object with version: #{@version}"
     end
 
     test "download/1 tries first failover region when primary region fails" do
@@ -97,9 +107,14 @@ defmodule RemotePersistentTerm.Fetcher.S3Test do
           assert {:ok, "content from failover region"} = result
         end)
 
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from primary region #{@region}"
-      assert log =~ "will try failover regions"
-      assert log =~ "s3://#{@bucket}/#{@key} - Trying failover region: failover-region-1"
+      assert log =~ "bucket: \"#{@bucket}\""
+      assert log =~ "key: \"#{@key}\""
+      assert log =~ "Downloading object from S3"
+      assert log =~ "region: \"#{@region}\""
+      assert log =~ "Failed to fetch from primary region, attempting failover regions"
+      assert log =~ "region: \"failover-region-1\""
+      assert log =~ "Trying failover region"
+      assert log =~ "Downloaded object from S3"
     end
 
     test "returns error when primary and all failover regions fail" do
@@ -131,12 +146,17 @@ defmodule RemotePersistentTerm.Fetcher.S3Test do
           assert message =~ "All regions failed"
         end)
 
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from primary region #{@region}"
-      assert log =~ "will try failover regions"
-      assert log =~ "s3://#{@bucket}/#{@key} - Trying failover region: failover-region-1"
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from failover region failover-region-1"
-      assert log =~ "s3://#{@bucket}/#{@key} - Trying failover region: failover-region-2"
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from failover region failover-region-2"
+      assert log =~ "bucket: \"#{@bucket}\""
+      assert log =~ "key: \"#{@key}\""
+      assert log =~ "Downloading object from S3"
+      assert log =~ "region: \"#{@region}\""
+      assert log =~ "Failed to fetch from primary region, attempting failover regions"
+      assert log =~ "region: \"failover-region-1\""
+      assert log =~ "Trying failover region"
+      assert log =~ "reason: \"\\\"First failover region connection error\\\"\""
+      assert log =~ "Failed to fetch from failover region"
+      assert log =~ "region: \"failover-region-2\""
+      assert log =~ "reason: \"\\\"Second failover region connection error\\\"\""
     end
 
     test "tries second failover region when first failover region fails" do
@@ -167,10 +187,17 @@ defmodule RemotePersistentTerm.Fetcher.S3Test do
           assert {:ok, "content from second failover region"} = result
         end)
 
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from primary region #{@region}"
-      assert log =~ "s3://#{@bucket}/#{@key} - Trying failover region: failover-region-1"
-      assert log =~ "s3://#{@bucket}/#{@key} - Failed to fetch from failover region failover-region-1"
-      assert log =~ "s3://#{@bucket}/#{@key} - Trying failover region: failover-region-2"
+      assert log =~ "bucket: \"#{@bucket}\""
+      assert log =~ "key: \"#{@key}\""
+      assert log =~ "Downloading object from S3"
+      assert log =~ "region: \"#{@region}\""
+      assert log =~ "Failed to fetch from primary region, attempting failover regions"
+      assert log =~ "region: \"failover-region-1\""
+      assert log =~ "Trying failover region"
+      assert log =~ "reason: \"\\\"First failover region connection error\\\"\""
+      assert log =~ "Failed to fetch from failover region"
+      assert log =~ "region: \"failover-region-2\""
+      assert log =~ "Downloaded object from S3"
     end
   end
 end