Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add formatter for Elastic Common Schema (ECS) #116

Merged
merged 7 commits into from
May 21, 2024
Merged
Show file tree
Hide file tree
Changes from 6 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
60 changes: 59 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -11,12 +11,14 @@ A collection of formatters and utilities for JSON-based logging for various clou

## Supported formatters

- [`LoggerJSON.Formatters.Basic`](https://hexdocs.pm/logger_json/LoggerJSON.Formatters.Basic.html) - a basic JSON formatter that logs messages in a structured format, can be used with any JSON-based logging system, like ElasticSearch, Logstash, etc.
- [`LoggerJSON.Formatters.Basic`](https://hexdocs.pm/logger_json/LoggerJSON.Formatters.Basic.html) - a basic JSON formatter that logs messages in a structured, but generic format, can be used with any JSON-based logging system.

- [`LoggerJSON.Formatters.GoogleCloud`](https://hexdocs.pm/logger_json/LoggerJSON.Formatters.GoogleCloud.html) - a formatter that logs messages in a structured format that can be consumed by Google Cloud Logger and Google Cloud Error Reporter.

- [`LoggerJSON.Formatters.Datadog`](https://hexdocs.pm/logger_json/LoggerJSON.Formatters.Datadog.html) - a formatter that logs messages in a structured format that can be consumed by Datadog.

- [`LoggerJSON.Formatters.Elastic`](https://hexdocs.pm/logger_json/LoggerJSON.Formatters.Elastic.html) - a formatter that logs messages in a structured format that conforms to the [Elastic Common Schema (ECS)](https://www.elastic.co/guide/en/ecs/8.11/ecs-reference.html), so it can be consumed by ElasticSearch, LogStash, FileBeat and Kibana.

## Installation

Add `logger_json` to your list of dependencies in `mix.exs`:
Expand Down Expand Up @@ -245,6 +247,62 @@ as much as possible.
}
```

## Elastic

Follows the [Elastic Common Schema (ECS)](https://www.elastic.co/guide/en/ecs/8.11/ecs-reference.html) format.

```json
{
"@timestamp": "2024-05-21T15:17:35.374Z",
"ecs.version": "8.11.0",
"log.level": "info",
"log.logger": "Elixir.LoggerJSON.Formatters.ElasticTest",
"log.origin": {
"file.line": 18,
"file.name": "/app/logger_json/test/logger_json/formatters/elastic_test.exs",
"function": "test logs message of every level/1"
},
"message": "Hello"
}
```

When an error is thrown, the message field is populated with the error message and the `error.` fields will be set:

> Note: when throwing a custom exception type that defines the fields `id` and/or `code`, then the `error.id` and/or `error.code` fields will be set respectively.

```json
{
"@timestamp": "2024-05-21T15:20:11.623Z",
"ecs.version": "8.11.0",
"error.message": "runtime error",
"error.stack_trace": "** (RuntimeError) runtime error\n test/logger_json/formatters/elastic_test.exs:191: anonymous fn/0 in LoggerJSON.Formatters.ElasticTest.\"test logs exceptions\"/1\n",
"error.type": "Elixir.RuntimeError",
"log.level": "error",
"message": "runtime error"
}
```

Any custom metadata fields will be added to the root of the message, so that your application can fill any other ECS fields that you require:

> Note that this also allows you to produce messages that do not strictly adhere to the ECS specification.

```json
// with Logger.metadata(:"device.model.name": "My Awesome Device")
{
"@timestamp": "2024-05-21T15:17:35.374Z",
"ecs.version": "8.11.0",
"log.level": "info",
"log.logger": "Elixir.LoggerJSON.Formatters.ElasticTest",
"log.origin": {
"file.line": 18,
"file.name": "/app/logger_json/test/logger_json/formatters/elastic_test.exs",
"function": "test logs message of every level/1"
},
"message": "Hello",
"device.model.name": "My Awesome Device"
}
```

## Copyright and License

Copyright (c) 2016 Andrew Dryga
Expand Down
4 changes: 4 additions & 0 deletions lib/logger_json.ex
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,10 @@ defmodule LoggerJSON do
* `LoggerJSON.Formatters.Datadog` - a formatter that logs messages in a structured format that can be consumed
by Datadog.

* `LoggerJSON.Formatters.Elastic` - a formatter that logs messages in a structured format that conforms to the
[Elastic Common Schema (ECS)](https://www.elastic.co/guide/en/ecs/8.11/ecs-reference.html),
so it can be consumed by ElasticSearch, LogStash, FileBeat and Kibana.

## Installation

Add `logger_json` to your list of dependencies in `mix.exs`:
Expand Down
253 changes: 253 additions & 0 deletions lib/logger_json/formatters/elastic.ex
Original file line number Diff line number Diff line change
@@ -0,0 +1,253 @@
defmodule LoggerJSON.Formatters.Elastic do
@moduledoc """
Custom Erlang's [`:logger` formatter](https://www.erlang.org/doc/apps/kernel/logger_chapter.html#formatters) which
writes logs in a JSON-structured format that conforms to the Elastic Common Schema (ECS), so it can be consumed by
ElasticSearch, LogStash, FileBeat and Kibana.

## Formatter Configuration

For list of options see "Shared options" in `LoggerJSON`.

## Metadata

For list of other well-known metadata keys see "Metadata" in `LoggerJSON`.

Any custom metadata that you set with `Logger.metadata/1` will be included top-level in the log entry.

## Examples

Example of an info log (`Logger.info("Hello")` without any metadata):

%{
"@timestamp" => "2024-05-17T16:20:00.000Z",
"ecs.version" => "8.11.0",
"log.level" => "info",
"log.logger" => "Elixir.LoggerJSON.Formatters.ElasticTest",
"log.origin" => %{
"file.name" => ~c"/app/logger_json/test/formatters/elastic_test.exs",
"file.line" => 18,
"function" => "test logs an LogEntry of every level/1"
},
"message" => "Hello"
}

Example of logging by keywords or by map (Logger.info(%{message: "Hello", foo: :bar, fiz: %{buz: "buz"}})).
The keywords or map items are added to the top-level of the log entry:

%{
"@timestamp" => "2024-05-17T16:20:00.000Z",
"ecs.version" => "8.11.0",
"fiz" => %{"buz" => "buz"},
"foo" => "bar",
"log.level" => "debug",
"log.logger" => "Elixir.LoggerJSON.Formatters.ElasticTest",
"log.origin" => %{
"file.line" => 68,
"file.name" => ~c"/app/logger_json/test/formatters/elastic_test.exs",
"function" => "test logs an LogEntry with a map payload containing message/1"},
"message" => "Hello"
}

Example of logging due to raising an exception (`raise RuntimeError`):

%{
"@timestamp" => "2024-05-17T16:20:00.000Z",
"ecs.version" => "8.11.0",
"error.message" => "runtime error",
"error.stack_trace" => "** (RuntimeError) runtime error\\n Elixir.LoggerJSON.Formatters.ElasticTest.erl:159: anonymous fn/4 in LoggerJSON.Formatters.ElasticTest.\\"test logs exceptions\\"/1\\n",
"error.type" => "Elixir.RuntimeError",
"log.level" => "error",
"message" => "runtime error"
}

Note that if you raise an exception that contains an `id` or a `code` property, they will be included in the log entry as `error.id` and `error.code` respectively.

Example:

defmodule TestException do
defexception [:message, :id, :code]
end

...

raise TestException, id: :oops_id, code: 42, message: "oops!"

results in:

%{
"@timestamp" => "2024-05-17T16:20:00.000Z",
"ecs.version" => "8.11.0",
"error.code" => 42,
"error.id" => "oops_id",
"error.message" => "oops!",
"error.stack_trace" => "** (LoggerJSON.Formatters.ElasticTest.TestException) oops!\n test/formatters/elastic_test.exs:190: anonymous fn/0 in LoggerJSON.Formatters.ElasticTest.\"test logs exceptions with id and code\"/1\n",
"error.type" => "Elixir.LoggerJSON.Formatters.ElasticTest.TestException",
"log.level" => "error",
"message" => "oops!"
}
"""
import Jason.Helpers, only: [json_map: 1]
import LoggerJSON.Formatter.{MapBuilder, DateTime, Message, Metadata, Plug, RedactorEncoder}

@behaviour LoggerJSON.Formatter

@ecs_version "8.11.0"

@processed_metadata_keys ~w[file line mfa domain error_logger
otel_span_id span_id
otel_trace_id trace_id
conn]a

@impl LoggerJSON.Formatter
def format(%{level: level, meta: meta, msg: msg}, opts) do
metadata_keys_or_selector = Keyword.get(opts, :metadata, [])
metadata_selector = update_metadata_selector(metadata_keys_or_selector, @processed_metadata_keys)
redactors = Keyword.get(opts, :redactors, [])

message =
format_message(msg, meta, %{
binary: &format_binary_message/1,
structured: &format_structured_message/1,
crash: &format_crash_reason(&1, &2, meta)
})

line =
%{
"@timestamp": utc_time(meta),
"log.level": Atom.to_string(level),
"ecs.version": @ecs_version
}
|> maybe_merge(encode(message, redactors))
|> maybe_merge(encode(take_metadata(meta, metadata_selector), redactors))
|> maybe_merge(format_logger_fields(meta))
|> maybe_merge(format_http_request(meta))
|> maybe_put(:"span.id", format_span_id(meta))
|> maybe_put(:"trace.id", format_trace_id(meta))
|> Jason.encode_to_iodata!()

[line, "\n"]
end

@doc false
def format_binary_message(binary) do
%{message: IO.chardata_to_string(binary)}
end

@doc false
def format_structured_message(map) when is_map(map) do
map
end

def format_structured_message(keyword) do
Enum.into(keyword, %{})
end

@doc false
def format_crash_reason(message, {{:EXIT, pid}, reason}, _meta) do
stacktrace = Exception.format_banner({:EXIT, pid}, reason, [])
error_message = "process #{inspect(pid)} exit: #{inspect(reason)}"
format_error_fields(message, error_message, stacktrace, "EXIT")
end

def format_crash_reason(message, {:exit, reason}, _meta) do
stacktrace = Exception.format_banner(:exit, reason, [])
error_message = "exit: #{inspect(reason)}"
format_error_fields(message, error_message, stacktrace, "exit")
end

def format_crash_reason(message, {:throw, reason}, _meta) do
stacktrace = Exception.format_banner(:throw, reason, [])
error_message = "throw: #{inspect(reason)}"
format_error_fields(message, error_message, stacktrace, "throw")
end

def format_crash_reason(_message, {%type{} = exception, stacktrace}, _meta) do
message = Exception.message(exception)

formatted_stacktrace =
[
Exception.format_banner(:error, exception, stacktrace),
Exception.format_stacktrace(stacktrace)
]
|> Enum.join("\n")

format_error_fields(message, message, formatted_stacktrace, type)
|> maybe_put(:"error.id", get_exception_id(exception))
|> maybe_put(:"error.code", get_exception_code(exception))
end

def format_crash_reason(message, {error, reason}, _meta) do
stacktrace = "** (#{error}) #{inspect(reason)}"
error_message = "#{error}: #{inspect(reason)}"
format_error_fields(message, error_message, stacktrace, error)
end

defp get_exception_id(%{id: id}), do: id
defp get_exception_id(_), do: nil

defp get_exception_code(%{code: code}), do: code
defp get_exception_code(_), do: nil

@doc """
Formats the error fields as specified in https://www.elastic.co/guide/en/ecs/8.11/ecs-error.html
"""
def format_error_fields(message, error_message, stacktrace, type) do
%{
message: message,
"error.message": error_message,
"error.stack_trace": stacktrace,
"error.type": type
}
end

@doc """
Formats the log.logger and log.origin fields as specified in https://www.elastic.co/guide/en/ecs/8.11/ecs-log.html
"""
def format_logger_fields(%{file: file, line: line, mfa: {module, function, arity}}) do
%{
"log.logger": module,
"log.origin": %{
"file.name": to_string(file),
"file.line": line,
function: "#{function}/#{arity}"
}
}
end

def format_logger_fields(_meta), do: nil

if Code.ensure_loaded?(Plug.Conn) do
# See the formats for the following fields in ECS:
# - client.ip: https://www.elastic.co/guide/en/ecs/8.11/ecs-client.html
# - http.*: https://www.elastic.co/guide/en/ecs/8.11/ecs-http.html
# - url.path: https://www.elastic.co/guide/en/ecs/8.11/ecs-url.html
# - user_agent.original: https://www.elastic.co/guide/en/ecs/8.11/ecs-user_agent.html
defp format_http_request(%{conn: %Plug.Conn{} = conn}) do
json_map(
"client.ip": remote_ip(conn),
"http.version": Plug.Conn.get_http_protocol(conn),
"http.request.method": conn.method,
"http.request.referrer": get_header(conn, "referer"),
"http.response.status_code": conn.status,
"url.path": conn.request_path,
"user_agent.original": get_header(conn, "user-agent")
)
end
end

defp format_http_request(_meta), do: nil

defp format_span_id(%{otel_span_id: otel_span_id}), do: safe_chardata_to_string(otel_span_id)
defp format_span_id(%{span_id: span_id}), do: span_id
defp format_span_id(_meta), do: nil

defp format_trace_id(%{otel_trace_id: otel_trace_id}), do: safe_chardata_to_string(otel_trace_id)
defp format_trace_id(%{trace_id: trace_id}), do: trace_id
defp format_trace_id(_meta), do: nil

def safe_chardata_to_string(chardata) when is_list(chardata) or is_binary(chardata) do
IO.chardata_to_string(chardata)
end

def safe_chardata_to_string(other), do: other
end
Loading
Loading