Generate log in the ECS format, and trace detail about JWT authentica…

…tion errors

README.md

@@ -18,16 +18,17 @@ All commands provided here must be run in the `/neurow` directory
 
 - Install the latest version of Elixir by following instructions provided [here](https://elixir-lang.org/install.html),
 - Run `mix deps.get` to download the dependencies required by Neurow,
-- Run `mix run --no-halt` to start Neurow locally with the default development configuration. The public API in available on `http://localhost:4000` and the internal API on `http://localhost:3000`.
+- Run `mix run --no-halt` to start Neurow locally with the default development configuration. The public API is then available on `http://localhost:4000` and the internal API on `http://localhost:3000`.
 
-It is possible to override the default local configuration with environment variables. For example to run Neurow on custom ports: `PUBLIC_API_PORT=5000 INTERNAL_API_PORT=5000  mix run --no-halt `
+It is possible to override the default local configuration with environment variables. For example to run Neurow on custom ports: `PUBLIC_API_PORT=5000 INTERNAL_API_PORT=5000 mix run --no-halt `
 
 
 Available environment variables are:
 
 | Name | Default value | Role |
 | --- | --- | --- | 
 | `LOG_LEVEL` | info | Log level |
+| `LOG_FORMAT` | TEXT | Log format, possible values: `TEXT` - space separated attributes, `ECS` - JSON format compatible with the [Elastic Common Schema](https://www.elastic.co/guide/en/ecs/current/index.html) | 
 | `PUBLIC_API_PORT` | 4000 | TCP port of the public API |
 | `PUBLIC_API_JWT_MAX_LIFETIME` | 120 | Max lifetime in seconds allowed for JWT tokens issued on the public API |
 | `PUBLIC_API_CONTEXT_PATH` | "" | URL prefix for resources of the public API - Useful to mount Neurow on a existing website|
@@ -40,8 +41,7 @@ Available environment variables are:
 
 
 ### Generate JWT tokens for the local environment
-
-Both the public and internal APIs rely on JWT tokens for authentication. For now JWT tokens are signed tokens with shared secret keys. (The support of assymetric signatures will be supported later.)
+Both the public and internal APIs rely on JWT tokens for authentication. For now JWT tokens are signed tokens with shared secret keys. Assymetric signatures will be supported later.
 
 Developement issuers and their signature keys are hard coded in `config/runtimes.exs:51`. The available issuers are `test_issuer1` and `test_issuer2`. 
 
@@ -53,7 +53,6 @@ To generate a JWT token for the internal API, run:
 
 
 ### Run tests
-
 - `mix test` runs all tests (both unit and integration tests)
 - `mix test.unit` runs unit tests
 - `mix test.integration` run integration tests

neurow/config/runtime.exs

@@ -1,8 +1,21 @@
 import Config
 
-config :logger, :console,
-  format: "$time $metadata[$level] $message\n",
-  level: String.to_atom(System.get_env("LOG_LEVEL") || "info")
+case System.get_env("LOG_FORMAT") do
+  log_format when log_format in ["TEXT", nil] ->
+    config :logger, :console,
+      metadata: [:mfa],
+      format: "$time $metadata[$level] $message\n",
+      level: String.to_atom(System.get_env("LOG_LEVEL") || "info")
+
+  "ECS" ->
+    config :logger, :console,
+      metadata: :all,
+      level: String.to_atom(System.get_env("LOG_LEVEL") || "info"),
+      format: {Neurow.EcsLogFormatter, :format}
+
+  other_format ->
+    raise "Unsupported log format: '#{other_format}'"
+end
 
 # Public API configuration
 config :neurow,

neurow/lib/neurow/application.ex

@@ -1,6 +1,7 @@
 defmodule Neurow.Application do
   @moduledoc false
 
+  # Resolved at compile time
   @mix_env Mix.env()
 
   require Logger
@@ -37,8 +38,8 @@ defmodule Neurow.Application do
         history_min_duration: history_min_duration,
         cluster_topologies: cluster_topologies
       }) do
-    Logger.warning("Current host #{node()}, environment: #{@mix_env}")
-    Logger.warning("Starting internal API on port #{internal_api_port}")
+    Logger.info("Current host #{node()}, environment: #{@mix_env}")
+    Logger.info("Starting internal API on port #{internal_api_port}")
 
     base_public_api_http_config = [
       port: public_api_port,
@@ -48,7 +49,7 @@ defmodule Neurow.Application do
 
     {sse_http_scheme, public_api_http_config} =
       if ssl_keyfile != nil do
-        Logger.warning(
+        Logger.info(
           "Starting public API on port #{public_api_port}, with keyfile: #{ssl_keyfile}, certfile: #{ssl_certfile}"
         )
 
@@ -61,7 +62,7 @@ defmodule Neurow.Application do
 
         {:https, http_config}
       else
-        Logger.warning("Starting public API on port #{public_api_port} without SSL")
+        Logger.info("Starting public API on port #{public_api_port} without SSL")
         {:http, base_public_api_http_config}
       end
 

neurow/lib/neurow/ecs_log_formatter.ex

@@ -0,0 +1,46 @@
+defmodule Neurow.EcsLogFormatter do
+  # Resolved at compile time
+  @revision System.get_env("GIT_COMMIT_SHA1") || "unknown"
+
+  # ECS Reference: https://www.elastic.co/guide/en/ecs/current/index.html
+
+  def format(level, message, timestamp, metadata) do
+    {{year, month, day}, {hour, minute, second, millisecond}} = timestamp
+    {:ok, date} = Date.new(year, month, day)
+    {:ok, time} = Time.new(hour, minute, second, millisecond * 1000)
+    {:ok, datetime} = DateTime.new(date, time)
+
+    {module, function, arity} = metadata[:mfa]
+
+    %{
+      "@timestamp" => datetime |> DateTime.to_iso8601(),
+      "log.level" => level,
+      "log.name" => "#{module}.#{function}/#{arity}",
+      "log.source" => %{
+        "file" => %{
+          name: to_string(metadata[:file]),
+          line: metadata[:line]
+        }
+      },
+      "ecs.version" => "8.11.0",
+      "message" => message,
+      "category" => metadata[:category] || "app",
+      "service" => %{
+        name: "neurow",
+        version: @revision
+      }
+    }
+    |> with_optional_attribute(metadata[:trace_id], "trace.id")
+    |> with_optional_attribute(metadata[:error_code], "error.code")
+    |> :jiffy.encode()
+    |> new_line()
+  end
+
+  defp with_optional_attribute(payload, attribute, attribute_name) do
+    if attribute,
+      do: Map.put(payload, attribute_name, attribute),
+      else: payload
+  end
+
+  defp new_line(msg), do: "#{msg}\n"
+end

neurow/lib/neurow/jwt_auth_plug.ex

@@ -210,8 +210,17 @@ defmodule Neurow.JwtAuthPlug do
   end
 
   defp forbidden(conn, error_code, error_message, options) do
-    Logger.debug(
-      "JWT authentication error path: #{conn.request_path}, audience: #{options |> Options.audience()} error: #{error_code} - #{error_message}"
+    jwt_token =
+      case conn |> jwt_token_from_request() do
+        {:ok, jwt_token} -> jwt_token
+        _ -> nil
+      end
+
+    Logger.error(
+      "JWT authentication error: #{error_code} - #{error_message}, path: '#{conn.request_path}', audience: '#{options |> Options.audience()}', token: '#{jwt_token}'",
+      category: "security",
+      error_code: "jwt_authentication.#{error_code}",
+      trace_id: conn |> get_req_header("x-request-id") |> List.first()
     )
 
     conn =