diff --git a/README.md b/README.md index d0b2b5524..2aa13d823 100644 --- a/README.md +++ b/README.md @@ -266,6 +266,9 @@ The following environment variables can be used to configure Livebook on boot: users (attached to evaluation and request logs). By default includes only request_id. + * `LIVEBOOK_LOG_FORMAT` - sets the log output format, either "text" (default) + for human-readable logs or "json" for structured JSON. + * `LIVEBOOK_NODE` - sets the node name for running Livebook in a cluster. Note that Livebook always runs using long names distribution, so the node host name must use a fully qualified domain name (FQDN) or an IP diff --git a/config/config.exs b/config/config.exs index 0cf85db5c..e746e2b1a 100644 --- a/config/config.exs +++ b/config/config.exs @@ -10,7 +10,7 @@ config :livebook, LivebookWeb.Endpoint, render_errors: [formats: [html: LivebookWeb.ErrorHTML], layout: false] # Configures Elixir's Logger -config :logger, :console, +config :logger, :default_formatter, format: "$date $time $metadata[$level] $message\n", metadata: [:request_id] diff --git a/config/dev.exs b/config/dev.exs index 59348b447..e9b053f71 100644 --- a/config/dev.exs +++ b/config/dev.exs @@ -62,7 +62,7 @@ config :livebook, LivebookWeb.Endpoint, ] # Do not include timestamps in development logs -config :logger, :console, +config :logger, :default_formatter, format: "$metadata[$level] $message\n", metadata: [] diff --git a/config/test.exs b/config/test.exs index 316b41d3e..cc5a3791f 100644 --- a/config/test.exs +++ b/config/test.exs @@ -6,8 +6,25 @@ config :livebook, LivebookWeb.Endpoint, http: [port: 4002], server: false -# Print only warnings and errors during test -config :logger, level: :warning +# Print only warnings and errors during test. +# +# We configure the default handler instead of Logger on purpose, +# as we want all calls to be processed, especially when using +# the JSON formatter. +config :logger, :default_handler, level: :warning + +# Also configure the JSON formatter for test. +# We make sure we write all currently available metadata. +path = "tmp/test.log.json" +File.rm(path) + +config :livebook, :logger, [ + {:handler, :json_log, :logger_std_h, + %{ + config: %{file: ~c"#{path}"}, + formatter: {LoggerJSON.Formatters.Basic, %{metadata: [:users, :request_id]}} + }} +] # Disable authentication in tests config :livebook, diff --git a/lib/livebook.ex b/lib/livebook.ex index 5fa14bdb3..72283affb 100644 --- a/lib/livebook.ex +++ b/lib/livebook.ex @@ -101,8 +101,19 @@ defmodule Livebook do config :logger, level: level end - if metadata = Livebook.Config.log_metadata!("LIVEBOOK_LOG_METADATA") do - config :logger, :console, metadata: metadata + log_metadata = Livebook.Config.log_metadata!("LIVEBOOK_LOG_METADATA") + log_format = Livebook.Config.log_format!("LIVEBOOK_LOG_FORMAT") || :text + + case {log_format, log_metadata} do + {:json, log_metadata} -> + config :logger, :default_handler, + formatter: {LoggerJSON.Formatters.Basic, %{metadata: log_metadata || [:request_id]}} + + {:text, log_metadata} when not is_nil(log_metadata) -> + config :logger, :default_formatter, metadata: log_metadata + + _ -> + :ok end if port = Livebook.Config.port!("LIVEBOOK_PORT") do diff --git a/lib/livebook/application.ex b/lib/livebook/application.ex index 67830841a..bb9a9fa15 100644 --- a/lib/livebook/application.ex +++ b/lib/livebook/application.ex @@ -4,6 +4,7 @@ defmodule Livebook.Application do require Logger def start(_type, _args) do + Logger.add_handlers(:livebook) Livebook.ZTA.init() create_teams_hub = parse_teams_hub() setup_optional_dependencies() diff --git a/lib/livebook/config.ex b/lib/livebook/config.ex index c79fc25ee..3314d3ff2 100644 --- a/lib/livebook/config.ex +++ b/lib/livebook/config.ex @@ -479,6 +479,23 @@ defmodule Livebook.Config do end end + @doc """ + Parses and validates log format from env. + """ + def log_format!(env) do + formats = ~w(text json) + + if format = System.get_env(env) do + if format in formats do + String.to_atom(format) + else + abort!( + "expected #{env} to be one of #{Enum.join(formats, ", ")}, got: #{inspect(format)}" + ) + end + end + end + @doc """ Parses and validates the port from env. """ diff --git a/mix.exs b/mix.exs index 3324fe4b3..1ac3d2462 100644 --- a/mix.exs +++ b/mix.exs @@ -125,6 +125,7 @@ defmodule Livebook.MixProject do {:phoenix_live_reload, "~> 1.2", only: :dev}, {:lazy_html, "~> 0.1.0", only: :test}, {:bypass, "~> 2.1", only: :test}, + {:logger_json, "~> 6.1"}, # So that we can test Python evaluation in the same node {:pythonx, "~> 0.4.2", only: :test}, # ZTA deps diff --git a/mix.lock b/mix.lock index 3b1f08c59..080f6c35d 100644 --- a/mix.lock +++ b/mix.lock @@ -25,6 +25,7 @@ "jsx": {:hex, :jsx, "3.1.0", "d12516baa0bb23a59bb35dccaf02a1bd08243fcbb9efe24f2d9d056ccff71268", [:rebar3], [], "hexpm", "0c5cc8fdc11b53cc25cf65ac6705ad39e54ecc56d1c22e4adb8f5a53fb9427f3"}, "kubereq": {:hex, :kubereq, "0.3.2", "e425dd94bd74b6510dc45a9557d9378d3fd6ca0ea3ebe0dad2a9c85a08c2e20a", [:mix], [{:fresh, "~> 0.4.4", [hex: :fresh, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}, {:mint, "~> 1.0", [hex: :mint, repo: "hexpm", optional: false]}, {:mint_web_socket, "~> 1.0", [hex: :mint_web_socket, repo: "hexpm", optional: false]}, {:pluggable, "~> 1.0", [hex: :pluggable, repo: "hexpm", optional: false]}, {:req, "~> 0.5.0", [hex: :req, repo: "hexpm", optional: false]}, {:yaml_elixir, "~> 2.0", [hex: :yaml_elixir, repo: "hexpm", optional: false]}], "hexpm", "d13293ac66bbfe7ac238881ac0404662af5a01f96f9325dd556594fd858f2a3e"}, "lazy_html": {:hex, :lazy_html, "0.1.0", "619c4c124a7375ecbf66263de90270d221ffc7479afde436717a4e5cceaac954", [:make, :mix], [{:cc_precompiler, "~> 0.1", [hex: :cc_precompiler, repo: "hexpm", optional: false]}, {:elixir_make, "~> 0.9.0", [hex: :elixir_make, repo: "hexpm", optional: false]}, {:fine, "~> 0.1.0", [hex: :fine, repo: "hexpm", optional: false]}], "hexpm", "a212f417b0e546055b7d5d72d302fce747b63ac9dfe0cf491c1f9af6d198e256"}, + "logger_json": {:hex, :logger_json, "6.2.1", "a1db30e1164e6057f2328a1e4d6b632b9583c015574fdf6c38cf73721128edcb", [:mix], [{:decimal, ">= 0.0.0", [hex: :decimal, repo: "hexpm", optional: true]}, {:ecto, "~> 3.11", [hex: :ecto, repo: "hexpm", optional: true]}, {:jason, "~> 1.4", [hex: :jason, repo: "hexpm", optional: false]}, {:plug, "~> 1.15", [hex: :plug, repo: "hexpm", optional: true]}, {:telemetry, "~> 1.0", [hex: :telemetry, repo: "hexpm", optional: true]}], "hexpm", "34acd0bfd419d5fcf08c4108a8a4b59b695fcc60409dc1dd1a868b70c42e1d1f"}, "makeup": {:hex, :makeup, "1.2.1", "e90ac1c65589ef354378def3ba19d401e739ee7ee06fb47f94c687016e3713d1", [:mix], [{:nimble_parsec, "~> 1.4", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "d36484867b0bae0fea568d10131197a4c2e47056a6fbe84922bf6ba71c8d17ce"}, "makeup_elixir": {:hex, :makeup_elixir, "1.0.1", "e928a4f984e795e41e3abd27bfc09f51db16ab8ba1aebdba2b3a575437efafc2", [: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", "7284900d412a3e5cfd97fdaed4f5ed389b8f2b4cb49efc0eb3bd10e2febf9507"}, "makeup_erlang": {:hex, :makeup_erlang, "1.0.2", "03e1804074b3aa64d5fad7aa64601ed0fb395337b982d9bcf04029d68d51b6a7", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "af33ff7ef368d5893e4a267933e7744e46ce3cf1f61e2dccf53a111ed3aa3727"}, diff --git a/test/livebook/config_test.exs b/test/livebook/config_test.exs index a55b13a76..689498be4 100644 --- a/test/livebook/config_test.exs +++ b/test/livebook/config_test.exs @@ -43,6 +43,34 @@ defmodule Livebook.ConfigTest do end end + describe "log_metadata!/1" do + test "parses valida metadata configs" do + with_env([TEST_LOG_METADATA: "users,request_id"], fn -> + assert Config.log_metadata!("TEST_LOG_METADATA") == [:users, :request_id] + end) + end + + test "returns nil when environment variable is not set" do + assert Config.log_metadata!("TEST_LOG_METADATA") == nil + end + end + + describe "log_format!/1" do + test "parses valid formats" do + with_env([TEST_LOG_FORMAT: "text"], fn -> + assert Config.log_format!("TEST_LOG_FORMAT") == :text + end) + + with_env([TEST_LOG_FORMAT: "json"], fn -> + assert Config.log_format!("TEST_LOG_FORMAT") == :json + end) + end + + test "returns nil when environment variable is not set" do + assert Config.log_format!("TEST_LOG_FORMAT") == nil + end + end + defp with_env(env_vars, fun) do existing = Enum.map(env_vars, fn {env, _value} ->