Move count out of prose and into metadata

Record the number of things being fetched in metadata instead of in
text so that the count can be graphed.

apps/block_scout_web/config/config.exs

@@ -48,7 +48,7 @@ config :ex_cldr,
 config :logger, :block_scout_web,
   # keep synced with `config/config.exs`
   format: "$dateT$time $metadata[$level] $message\n",
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a,
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a,
   metadata_filter: [application: :block_scout_web]
 
 config :spandex_phoenix, tracer: BlockScoutWeb.Tracer

apps/ethereum_jsonrpc/config/config.exs

@@ -17,7 +17,7 @@ config :ethereum_jsonrpc, EthereumJSONRPC.Tracer,
 config :logger, :ethereum_jsonrpc,
   # keep synced with `config/config.exs`
   format: "$dateT$time $metadata[$level] $message\n",
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a,
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a,
   metadata_filter: [application: :ethereum_jsonrpc]
 
 # Import environment specific config. This must remain at the bottom

apps/explorer/config/config.exs

@@ -50,7 +50,7 @@ config :explorer,
 config :logger, :explorer,
   # keep synced with `config/config.exs`
   format: "$dateT$time $metadata[$level] $message\n",
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a,
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a,
   metadata_filter: [application: :explorer]
 
 config :spandex_ecto, SpandexEcto.EctoLogger,

apps/indexer/config/config.exs

@@ -19,7 +19,7 @@ config :indexer, Indexer.Tracer,
 config :logger, :indexer,
   # keep synced with `config/config.exs`
   format: "$dateT$time $metadata[$level] $message\n",
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a,
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a,
   metadata_filter: [application: :indexer]
 
 # Import environment specific config. This must remain at the bottom

apps/indexer/lib/indexer/block/catchup/bound_interval_supervisor.ex

@@ -184,7 +184,8 @@ defmodule Indexer.Block.Catchup.BoundIntervalSupervisor do
   end
 
   def handle_info(
-        {ref, %{first_block_number: first_block_number, missing_block_count: missing_block_count, shrunk: false}},
+        {ref,
+         %{first_block_number: first_block_number, missing_block_count: missing_block_count, shrunk: false}},
         %__MODULE__{
           bound_interval: bound_interval,
           task: %Task{ref: ref}
@@ -228,7 +229,8 @@ defmodule Indexer.Block.Catchup.BoundIntervalSupervisor do
   end
 
   def handle_info(
-        {ref, %{first_block_number: first_block_number, missing_block_count: missing_block_count, shrunk: true}},
+        {ref,
+         %{first_block_number: first_block_number, missing_block_count: missing_block_count, shrunk: true}},
         %__MODULE__{
           task: %Task{ref: ref}
         } = state

apps/indexer/lib/indexer/block/fetcher/receipts.ex

@@ -13,7 +13,7 @@ defmodule Indexer.Block.Fetcher.Receipts do
         %Block.Fetcher{json_rpc_named_arguments: json_rpc_named_arguments} = state,
         transaction_params
       ) do
-    Logger.debug(fn -> "fetching #{length(transaction_params)} transaction receipts" end)
+    Logger.debug("fetching transaction receipts", count: Enum.count(transaction_params))
     stream_opts = [max_concurrency: state.receipts_concurrency, timeout: :infinity]
 
     transaction_params

apps/indexer/lib/indexer/block/uncle/fetcher.ex

@@ -74,7 +74,10 @@ defmodule Indexer.Block.Uncle.Fetcher do
     # the same block could be included as an uncle on multiple blocks, but we only want to fetch it once
     unique_hashes = Enum.uniq(hashes)
 
-    Logger.debug(fn -> "fetching #{length(unique_hashes)}" end)
+    unique_hash_count = Enum.count(unique_hashes)
+    Logger.metadata(count: unique_hash_count)
+
+    Logger.debug("fetching")
 
     case EthereumJSONRPC.fetch_blocks_by_hash(unique_hashes, json_rpc_named_arguments) do
       {:ok, blocks} ->
@@ -82,7 +85,7 @@ defmodule Indexer.Block.Uncle.Fetcher do
 
       {:error, reason} ->
         Logger.error(fn ->
-          ["failed to fetch ", unique_hashes |> length |> to_string(), ": ", inspect(reason)]
+          ["failed to fetch: ", inspect(reason)]
         end)
 
         {:retry, unique_hashes}
@@ -110,14 +113,12 @@ defmodule Indexer.Block.Uncle.Fetcher do
            transactions: %{params: transactions_params, on_conflict: :nothing}
          }) do
       {:ok, _} ->
-        retry(errors, original_entries)
+        retry(errors)
 
       {:error, step, failed_value, _changes_so_far} ->
         Logger.error(fn ->
           [
-            "failed to import ",
+            "failed to import  in step ",
-            original_entries |> length() |> to_string(),
-            " in step ",
             inspect(step),
             ": ",
             inspect(failed_value)
@@ -185,17 +186,15 @@ defmodule Indexer.Block.Uncle.Fetcher do
     end)
   end
 
-  defp retry([], _), do: :ok
+  defp retry([]), do: :ok
 
-  defp retry(errors, original_entries) when is_list(errors) do
+  defp retry(errors) when is_list(errors) do
     retried_entries = errors_to_entries(errors)
 
     Logger.error(fn ->
       [
         "failed to fetch ",
         retried_entries |> length() |> to_string(),
-        "/",
-        original_entries |> length() |> to_string(),
         ": ",
         errors_to_iodata(errors)
       ]

apps/indexer/lib/indexer/coin_balance/fetcher.ex

@@ -74,7 +74,10 @@ defmodule Indexer.CoinBalance.Fetcher do
     # `{address, block}`, so take unique params only
     unique_entries = Enum.uniq(entries)
 
-    Logger.debug(fn -> ["fetching ", unique_entries |> length() |> to_string()] end)
+    unique_entry_count = Enum.count(unique_entries)
+    Logger.metadata(count: unique_entry_count)
+
+    Logger.debug(fn -> "fetching" end)
 
     unique_entries
     |> Enum.map(&entry_to_params/1)
@@ -85,7 +88,7 @@ defmodule Indexer.CoinBalance.Fetcher do
 
       {:error, reason} ->
         Logger.error(fn ->
-          ["failed to fetch ", unique_entries |> length() |> to_string(), ": ", inspect(reason)]
+          ["failed to fetch: ", inspect(reason)]
         end)
 
         {:retry, unique_entries}
@@ -115,7 +118,7 @@ defmodule Indexer.CoinBalance.Fetcher do
 
   defp run_fetched_balances(%FetchedBalances{params_list: []}, original_entries), do: {:retry, original_entries}
 
-  defp run_fetched_balances(%FetchedBalances{params_list: params_list, errors: errors}, original_entries) do
+  defp run_fetched_balances(%FetchedBalances{params_list: params_list, errors: errors}, _) do
     value_fetched_at = DateTime.utc_now()
 
     importable_balances_params = Enum.map(params_list, &Map.put(&1, :value_fetched_at, value_fetched_at))
@@ -128,20 +131,18 @@ defmodule Indexer.CoinBalance.Fetcher do
         address_coin_balances: %{params: importable_balances_params}
       })
 
-    retry(errors, original_entries)
+    retry(errors)
   end
 
-  defp retry([], _), do: :ok
+  defp retry([]), do: :ok
 
-  defp retry(errors, original_entries) when is_list(errors) do
+  defp retry(errors) when is_list(errors) do
     retried_entries = fetched_balances_errors_to_entries(errors)
 
     Logger.error(fn ->
       [
         "failed to fetch ",
         retried_entries |> length() |> to_string(),
-        "/",
-        original_entries |> length() |> to_string(),
         ": ",
         fetched_balance_errors_to_iodata(errors)
       ]

apps/indexer/lib/indexer/internal_transaction/fetcher.ex

@@ -103,7 +103,10 @@ defmodule Indexer.InternalTransaction.Fetcher do
   def run(entries, json_rpc_named_arguments) do
     unique_entries = unique_entries(entries)
 
-    Logger.debug(fn -> "fetching internal transactions for #{length(unique_entries)} transactions" end)
+    unique_entries_count = Enum.count(unique_entries)
+    Logger.metadata(count: unique_entries_count)
+
+    Logger.debug("fetching internal transactions for transactions")
 
     unique_entries
     |> Enum.map(&params/1)
@@ -130,9 +133,7 @@ defmodule Indexer.InternalTransaction.Fetcher do
           {:error, step, reason, _changes_so_far} ->
             Logger.error(fn ->
               [
-                "failed to import internal transactions for ",
+                "failed to import internal transactions for transactions at ",
-                to_string(length(entries)),
-                " transactions at ",
                 to_string(step),
                 ": ",
                 inspect(reason)
@@ -144,9 +145,7 @@ defmodule Indexer.InternalTransaction.Fetcher do
         end
 
       {:error, reason} ->
-        Logger.error(fn ->
+        Logger.error(fn -> ["failed to fetch internal transactions for transactions: ", inspect(reason)] end)
-          "failed to fetch internal transactions for #{length(entries)} transactions: #{inspect(reason)}"
-        end)
 
         # re-queue the de-duped entries
         {:retry, unique_entries}

apps/indexer/lib/indexer/token_balance/fetcher.ex

@@ -93,10 +93,11 @@ defmodule Indexer.TokenBalance.Fetcher do
   end
 
   def fetch_from_blockchain(params_list) do
-    {:ok, token_balances} =
+    retryable_params_list = Enum.filter(params_list, &(&1.retries_count <= @max_retries))
-      params_list
+
-      |> Enum.filter(&(&1.retries_count <= @max_retries))
+    Logger.metadata(count: Enum.count(retryable_params_list))
-      |> TokenBalances.fetch_token_balances_from_blockchain()
+
+    {:ok, token_balances} = TokenBalances.fetch_token_balances_from_blockchain(retryable_params_list)
 
     token_balances
   end

apps/indexer/lib/indexer/token_balances.ex

@@ -34,7 +34,7 @@ defmodule Indexer.TokenBalances do
 
   @decorate span(tracer: Tracer)
   def fetch_token_balances_from_blockchain(token_balances, opts \\ []) do
-    Logger.debug(fn -> "fetching #{Enum.count(token_balances)} token balances" end)
+    Logger.debug("fetching token balances", count: Enum.count(token_balances))
 
     task_timeout = Keyword.get(opts, :timeout, @task_timeout)
 

config/config.exs

@@ -32,19 +32,19 @@ config :logger,
 config :logger, :console,
   # Use same format for all loggers, even though the level should only ever be `:error` for `:error` backend
   format: "$dateT$time $metadata[$level] $message\n",
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a
 
 config :logger, :ecto,
   # Use same format for all loggers, even though the level should only ever be `:error` for `:error` backend
   format: "$dateT$time $metadata[$level] $message\n",
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a,
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a,
   metadata_filter: [application: :ecto]
 
 config :logger, :error,
   # Use same format for all loggers, even though the level should only ever be `:error` for `:error` backend
   format: "$dateT$time $metadata[$level] $message\n",
   level: :error,
-  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number)a
+  metadata: ~w(application fetcher request_id first_block_number last_block_number block_number count)a
 
 # Import environment specific config. This must remain at the bottom
 # of this file so it overrides the configuration defined above.