defmodule Membrane.Logger do
@moduledoc """
Wrapper around the Elixir logger. Adds Membrane prefixes and handles verbose logging.
## Prefixes
By default, this wrapper prepends each log with a prefix containing the context
of the log, such as element name. This can be turned off via configuration:
use Mix.Config
config :membrane_core, :logger, prefix: false
Regardless of the config, the prefix is passed to `Logger` metadata under `:mb_prefix` key.
Prefixes are passed via process dictionary, so they have process-wide scope,
but it can be extended with `get_prefix/0` and `set_prefix/1`.
## Verbose logging
For verbose debug logs that should be silenced by default, use `debug_verbose/2`
macro. Verbose logs are purged in the compile time, unless turned on via configuration:
use Mix.Config
config :membrane_core, :logger, verbose: true
Verbose debugs should be used for logs that are USUALLY USEFUL for debugging,
but printed so often that they make the output illegible. For example, it may
be a good idea to debug_verbose from within `c:Membrane.WithInputPads.handle_buffer/4`
or `c:Membrane.Element.WithOutputPads.handle_demand/5` callbacks.
"""
@config Application.compile_env(:membrane_core, :logger, [])
@get_prefix_ast (quote do
Process.get(:membrane_logger_prefix, "")
end)
defp runtime_prepend_prefix_ast(message) do
quote bind_quoted: [message: message, prefix: @get_prefix_ast] do
if is_function(message, 0) do
fn ->
case message.() do
{content, metadata} -> {[prefix, content], metadata}
content -> [prefix, content]
end
end
else
[prefix, message]
end
end
end
defmacrop runtime_prepend_prefix(message), do: runtime_prepend_prefix_ast(message)
@doc """
Macro for verbose debug logs, that are silenced by default.
For details, see the ['verbose logging'](#module-verbose-logging) section of the moduledoc.
"""
defmacro debug_verbose(message, metadata \\ []) do
if Keyword.get(@config, :verbose, false) do
quote do
require Logger
Logger.debug(
unquote(prepend_prefix_ast(message)),
unquote([mb_verbose: true] ++ metadata)
)
end
else
# A hack to suppress the 'unused variable' warnings
quote do
_fn = fn ->
_unused = unquote(message)
_unused = unquote(metadata)
end
:ok
end
end
end
Enum.map([:debug, :info, :warn, :warning, :error], fn method ->
@doc """
Wrapper around `Logger.#{method}/2` that adds Membrane prefix.
For details, see the ['prefixes'](#module-prefixes) section of the moduledoc.
"""
defmacro unquote(method)(message, metadata \\ []) do
method = unquote(method)
quote do
require Logger
Logger.unquote(method)(unquote(prepend_prefix_ast(message)), unquote(metadata))
end
end
end)
@doc """
Wrapper around `Logger.log/3` that adds Membrane prefix.
For details, see the ['prefixes'](#module-prefixes) section of the moduledoc.
"""
defmacro log(level, message, metadata \\ []) do
quote do
require Logger
Logger.log(unquote(level), unquote(prepend_prefix_ast(message)), unquote(metadata))
end
end
@doc """
Wrapper around `Logger.bare_log/3` that adds Membrane prefix.
For details, see the 'prefixes' section of the moduledoc.
"""
@spec bare_log(Logger.level(), Logger.message(), Logger.metadata()) :: :ok
def bare_log(level, message, metadata \\ []) do
Logger.bare_log(level, runtime_prepend_prefix(message), metadata)
end
@doc """
Returns the logger prefix.
Returns an empty string if no prefix is set.
"""
@spec get_prefix() :: String.t()
def get_prefix() do
Process.get(:membrane_logger_prefix, "")
end
@doc """
Sets the logger prefix. Avoid using in Membrane-managed processes.
This function is intended to enable setting prefix obtained in a Membrane-managed
process via `get_prefix/1`. If some custom data needs to be prepended to logs,
please use `Logger.metadata/1`.
Prefixes in Membrane-managed processes are set automatically and using this
function there would overwrite them, which is usually unintended.
"""
@spec set_prefix(prefix :: String.t()) :: :ok
def set_prefix(prefix) do
Logger.metadata(mb_prefix: prefix)
if Membrane.Logger.get_config(:prefix, true) do
Process.put(:membrane_logger_prefix, "#{prefix} ")
end
:ok
end
@doc """
Returns the Membrane logger config.
"""
@spec get_config() :: Keyword.t()
def get_config() do
Application.get_env(:membrane_core, :logger, [])
end
@doc """
Returns value at given key in the Membrane logger config.
"""
@spec get_config(key, value) :: value when key: atom, value: any
def get_config(key, default \\ nil) do
Application.get_env(:membrane_core, :logger, [])
|> Keyword.get(key, default)
end
defp prepend_prefix_ast(message) when is_binary(message) or is_list(message) do
[@get_prefix_ast, message]
end
defp prepend_prefix_ast({op, _meta, _args} = message) when op in [:<<>>, :<>] do
[@get_prefix_ast, message]
end
defp prepend_prefix_ast(message) do
runtime_prepend_prefix_ast(message)
end
end