From f9d5377e64d2c6bfb16c7298be448fddc3e0477a Mon Sep 17 00:00:00 2001 From: nikitosing <32202610+nikitosing@users.noreply.github.com> Date: Thu, 9 Nov 2023 11:09:38 +0300 Subject: [PATCH] Add endpoint url to the block_scout_web logging (#8609) * Replace :console logger backend with LoggerJSON; Add endpoint url to the block_scout_web logging * Move logger_json dependency * Turn json logs only for prod environment * Disable debug ecto logs for test environment * Return HTTP method to logs --- CHANGELOG.md | 1 + .../lib/block_scout_web/plug/logger.ex | 47 +++++++------------ apps/block_scout_web/mix.exs | 3 +- apps/ethereum_jsonrpc/mix.exs | 3 +- apps/explorer/config/test.exs | 12 +++-- apps/explorer/mix.exs | 3 +- apps/indexer/mix.exs | 3 +- config/config.exs | 10 +++- config/dev.exs | 2 + config/prod.exs | 4 +- config/test.exs | 2 + mix.lock | 1 + 12 files changed, 51 insertions(+), 40 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2bfd041e27..bac2acc947 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,7 @@ - [#8795](https://github.com/blockscout/blockscout/pull/8795) - Disable catchup indexer by env - [#8750](https://github.com/blockscout/blockscout/pull/8750) - Support new eth-bytecode-db request metadata fields +- [#8609](https://github.com/blockscout/blockscout/pull/8609) - Change logs format to JSON; Add endpoint url to the block_scout_web logging ### Fixes diff --git a/apps/block_scout_web/lib/block_scout_web/plug/logger.ex b/apps/block_scout_web/lib/block_scout_web/plug/logger.ex index 883dd95ef3..b61c9cafe4 100644 --- a/apps/block_scout_web/lib/block_scout_web/plug/logger.ex +++ b/apps/block_scout_web/lib/block_scout_web/plug/logger.ex @@ -19,53 +19,40 @@ defmodule BlockScoutWeb.Plug.Logger do @impl true def call(conn, opts) do level = Keyword.get(opts, :log, :info) - application = Keyword.get(opts, :application, :block_scout_web) - - log(application, conn, level, opts) start = System.monotonic_time() Conn.register_before_send(conn, fn conn -> + stop = System.monotonic_time() + diff = System.convert_time_unit(stop - start, :native, :microsecond) + status = Integer.to_string(conn.status) + Logger.log( level, fn -> - stop = System.monotonic_time() - diff = System.convert_time_unit(stop - start, :native, :microsecond) - status = Integer.to_string(conn.status) - - [connection_type(conn), ?\s, status, " in ", formatted_diff(diff)] + [connection_type(conn), ?\s, status, " in ", formatted_diff(diff), " on ", conn.method, ?\s, endpoint(conn)] end, - opts + Keyword.merge( + [duration: diff, status: status, unit: "microsecond", endpoint: endpoint(conn), method: conn.method], + opts + ) ) conn end) end - defp log(:api, conn, level, opts) do - endpoint = - if conn.query_string do - "#{conn.request_path}?#{conn.query_string}" - else - conn.request_path - end - - Logger.log(level, endpoint, opts) - end - - defp log(_application, conn, level, opts) do - Logger.log( - level, - fn -> - [conn.method, ?\s, conn.request_path] - end, - opts - ) - end - defp formatted_diff(diff) when diff > 1000, do: [diff |> div(1000) |> Integer.to_string(), "ms"] defp formatted_diff(diff), do: [Integer.to_string(diff), "µs"] defp connection_type(%{state: :set_chunked}), do: "Chunked" defp connection_type(_), do: "Sent" + + defp endpoint(conn) do + if conn.query_string do + "#{conn.request_path}?#{conn.query_string}" + else + conn.request_path + end + end end diff --git a/apps/block_scout_web/mix.exs b/apps/block_scout_web/mix.exs index e0283df5a7..17b4a79de4 100644 --- a/apps/block_scout_web/mix.exs +++ b/apps/block_scout_web/mix.exs @@ -132,7 +132,8 @@ defmodule BlockScoutWeb.Mixfile do {:ex_json_schema, "~> 0.10.1"}, {:ueberauth, "~> 0.7"}, {:ueberauth_auth0, "~> 2.0"}, - {:bureaucrat, "~> 0.2.9", only: :test} + {:bureaucrat, "~> 0.2.9", only: :test}, + {:logger_json, "~> 5.1"} ] end diff --git a/apps/ethereum_jsonrpc/mix.exs b/apps/ethereum_jsonrpc/mix.exs index 9159a8c985..d4496a620d 100644 --- a/apps/ethereum_jsonrpc/mix.exs +++ b/apps/ethereum_jsonrpc/mix.exs @@ -85,7 +85,8 @@ defmodule EthereumJsonrpc.MixProject do {:decimal, "~> 2.0"}, {:decorator, "~> 1.4"}, {:hackney, "~> 1.18"}, - {:poolboy, "~> 1.5.2"} + {:poolboy, "~> 1.5.2"}, + {:logger_json, "~> 5.1"} ] end end diff --git a/apps/explorer/config/test.exs b/apps/explorer/config/test.exs index 8a08ee60ac..955f9df842 100644 --- a/apps/explorer/config/test.exs +++ b/apps/explorer/config/test.exs @@ -12,7 +12,8 @@ config :explorer, Explorer.Repo, ownership_timeout: :timer.minutes(7), timeout: :timer.seconds(60), queue_target: 1000, - migration_lock: nil + migration_lock: nil, + log: false # Configure API database config :explorer, Explorer.Repo.Replica1, @@ -26,7 +27,8 @@ config :explorer, Explorer.Repo.Replica1, enable_caching_implementation_data_of_proxy: true, avg_block_time_as_ttl_cached_implementation_data_of_proxy: false, fallback_ttl_cached_implementation_data_of_proxy: :timer.seconds(20), - implementation_data_fetching_timeout: :timer.seconds(20) + implementation_data_fetching_timeout: :timer.seconds(20), + log: false # Configure API database config :explorer, Explorer.Repo.Account, @@ -36,7 +38,8 @@ config :explorer, Explorer.Repo.Account, # Default of `5_000` was too low for `BlockFetcher` test ownership_timeout: :timer.minutes(1), timeout: :timer.seconds(60), - queue_target: 1000 + queue_target: 1000, + log: false for repo <- [Explorer.Repo.PolygonEdge, Explorer.Repo.PolygonZkevm, Explorer.Repo.RSK, Explorer.Repo.Suave] do config :explorer, repo, @@ -46,7 +49,8 @@ for repo <- [Explorer.Repo.PolygonEdge, Explorer.Repo.PolygonZkevm, Explorer.Rep # Default of `5_000` was too low for `BlockFetcher` test ownership_timeout: :timer.minutes(1), timeout: :timer.seconds(60), - queue_target: 1000 + queue_target: 1000, + log: false end config :logger, :explorer, diff --git a/apps/explorer/mix.exs b/apps/explorer/mix.exs index 1a43393fa6..e976d63ce4 100644 --- a/apps/explorer/mix.exs +++ b/apps/explorer/mix.exs @@ -117,7 +117,8 @@ defmodule Explorer.Mixfile do {:cbor, "~> 1.0"}, {:cloak_ecto, "~> 1.2.0"}, {:redix, "~> 1.1"}, - {:hammer_backend_redis, "~> 6.1"} + {:hammer_backend_redis, "~> 6.1"}, + {:logger_json, "~> 5.1"} ] end diff --git a/apps/indexer/mix.exs b/apps/indexer/mix.exs index f388f63531..6444e65961 100644 --- a/apps/indexer/mix.exs +++ b/apps/indexer/mix.exs @@ -55,7 +55,8 @@ defmodule Indexer.MixProject do # Tracing {:spandex, "~> 3.0"}, # `:spandex` integration with Datadog - {:spandex_datadog, "~> 1.0"} + {:spandex_datadog, "~> 1.0"}, + {:logger_json, "~> 5.1"} ] end diff --git a/config/config.exs b/config/config.exs index 554d3ae557..f09d21a3f0 100644 --- a/config/config.exs +++ b/config/config.exs @@ -38,9 +38,17 @@ config :logger, {LoggerFileBackend, :api}, {LoggerFileBackend, :block_import_timings}, {LoggerFileBackend, :account}, - {LoggerFileBackend, :api_v2} + {LoggerFileBackend, :api_v2}, + LoggerJSON ] +config :logger_json, :backend, + metadata: + ~w(application fetcher request_id first_block_number last_block_number missing_block_range_count missing_block_count + block_number step count error_count shrunk import_id transaction_id duration status unit endpoint method)a, + json_encoder: Jason, + formatter: LoggerJSON.Formatters.BasicLogger + 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", diff --git a/config/dev.exs b/config/dev.exs index 323212e107..27154824a9 100644 --- a/config/dev.exs +++ b/config/dev.exs @@ -3,6 +3,8 @@ import Config # DO NOT make it `:debug` or all Ecto logs will be shown for indexer config :logger, :console, level: :info +config :logger_json, :backend, level: :none + config :logger, :ecto, level: :debug, path: Path.absname("logs/dev/ecto.log") diff --git a/config/prod.exs b/config/prod.exs index 1d9be54e3f..2e8c9db24d 100644 --- a/config/prod.exs +++ b/config/prod.exs @@ -2,7 +2,9 @@ import Config # Do not print debug messages in production -config :logger, :console, level: :info +config :logger, :console, level: :none + +config :logger_json, :backend, level: :info config :logger, :ecto, level: :info, diff --git a/config/test.exs b/config/test.exs index 92ddca6a93..c979cd8348 100644 --- a/config/test.exs +++ b/config/test.exs @@ -4,6 +4,8 @@ import Config config :logger, :console, level: :warn +config :logger_json, :backend, level: :none + config :logger, :ecto, level: :warn, path: Path.absname("logs/test/ecto.log") diff --git a/mix.lock b/mix.lock index 03e579b8ae..605ac6bec0 100644 --- a/mix.lock +++ b/mix.lock @@ -75,6 +75,7 @@ "jsx": {:hex, :jsx, "2.8.3", "a05252d381885240744d955fbe3cf810504eb2567164824e19303ea59eef62cf", [:mix, :rebar3], [], "hexpm", "fc3499fed7a726995aa659143a248534adc754ebd16ccd437cd93b649a95091f"}, "junit_formatter": {:hex, :junit_formatter, "3.3.1", "c729befb848f1b9571f317d2fefa648e9d4869befc4b2980daca7c1edc468e40", [:mix], [], "hexpm", "761fc5be4b4c15d8ba91a6dafde0b2c2ae6db9da7b8832a55b5a1deb524da72b"}, "logger_file_backend": {:hex, :logger_file_backend, "0.0.13", "df07b14970e9ac1f57362985d76e6f24e3e1ab05c248055b7d223976881977c2", [:mix], [], "hexpm", "71a453a7e6e899ae4549fb147b1c6621f4233f8f48f58ca10a64ec67b6c50018"}, + "logger_json": {:hex, :logger_json, "5.1.2", "7dde5f6dff814aba033f045a3af9408f5459bac72357dc533276b47045371ecf", [:mix], [{:ecto, "~> 2.1 or ~> 3.0", [hex: :ecto, repo: "hexpm", optional: true]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}, {:phoenix, ">= 1.5.0", [hex: :phoenix, repo: "hexpm", optional: true]}, {:plug, "~> 1.0", [hex: :plug, repo: "hexpm", optional: true]}, {:telemetry, "~> 0.4.0 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: true]}], "hexpm", "ed42047e5c57a60d0fa1450aef36bc016d0f9a5e6c0807ebb0c03d8895fb6ebc"}, "makeup": {:hex, :makeup, "1.1.0", "6b67c8bc2882a6b6a445859952a602afc1a41c2e08379ca057c0f525366fc3ca", [:mix], [{:nimble_parsec, "~> 1.2.2 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "0a45ed501f4a8897f580eabf99a2e5234ea3e75a4373c8a52824f6e873be57a6"}, "makeup_elixir": {:hex, :makeup_elixir, "0.16.1", "cc9e3ca312f1cfeccc572b37a09980287e243648108384b97ff2b76e505c3555", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.2.3 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "e127a341ad1b209bd80f7bd1620a15693a9908ed780c3b763bccf7d200c767c6"}, "makeup_erlang": {:hex, :makeup_erlang, "0.1.2", "ad87296a092a46e03b7e9b0be7631ddcf64c790fa68a9ef5323b6cbb36affc72", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "f3f5a1ca93ce6e092d92b6d9c049bcda58a3b617a8d888f8e7231c85630e8108"},