Getting ejabberd to use Elixir logger in release build

Questions / Help
, ,
1

I’ve inherited an Elixir app, that embeds ejabberd, as is described here: https://docs.ejabberd.im/developer/extending-ejabberd/elixir/#embedding-ejabberd-in-an-elixir-application
Unfortunately I don’t have any experience with Elixir / OTP and the tooling around them.
The version I use is:

$ elixir -v
Erlang/OTP 20 [erts-9.3.3.11] [source] [64-bit] [smp:4:4] [ds:4:4:10] [async-threads:10] [hipe] [kernel-poll:false]

Elixir 1.6.6 (compiled with OTP 20)

One of the first things I would like to do, is to change the log format to a custom one. For the Elixir part of the app, this works fine where I do something along the lines of

config :logger,
  level: :info,
  handle_otp_reports: true,
  handle_sasl_reports: true,
  backends: [:console],
  console: [format: {Utils.LogFormatter, :format}]

in config/config.exs.

I also noticed that ejabberd explicitly checks for the Elixir logger, and uses that when it’s present: https://github.com/processone/ejabberd/blob/90b22da88041284dc6247f1b5f850da30d1e435d/src/ejabberd_logger.erl#L111-L117

My mix.exs looks something like this:

...

  def application do
    [
      mod: {MyApp, []},
      extra_applications: [:logger, :ejabberd]
    ]
  end

  defp deps do
    [
      {:ejabberd, "~> 18.4"},
      ...
    ]
  end

...

I changed extra_applications, with the intention of making sure that logger starts before ejabberd (am I doing this right?).

Now when I run my service with iex --no-halt -S mix, ejabberd picks up the Elixir logger just fine, and I see this:

Application logger started at :nonode@nohost
...
Ignoring ejabberd logger options, using Elixir Logger.
...
ejabberd 18.4.0 is started in the node nonode@nohost
Application ejabberd started at :nonode@nohost

But when I create a release build with mix release and start that, ejabberd does not pick up the logger:

Application logger started at :nonode@nohost
...
Application ejabberd started on node 'my_app@127.0.0.1'
Application ejabberd started at :"my_app@127.0.0.1"

Somewhere in between the start of logger and ejabberd I also get

Application logger started at :"my_app@127.0.0.1"

I suspect that ejabberd doesn’t know about the “first” logger, because it’s running on a “different node”. Does that sound plausible? Why would it behave like this in a release build, but not with iex? Why does it first start a few apps with nonode@nohost and then switch to my_app@127.0.01? Can I somehow make sure logger gets started before ejabberd, but on the same node?

Thanks!

2

ejabberd uses lager as a logging facility so it will not work. You need to redirect all lager messages to Elixir’s Logger. Fortunately for You, there is already done library for that.

PS

TBH I cannot wait until both lager and Logger migrate to logger and all that mess will be fixed.

1 Like
3

Mhh yeah, that was my first thought as well. Did you take a look at the link to the ejabberd code I posted?
ejabberd definitely uses logger when it can. It does work for non-release builds. I was hoping to find out why that mechanism doesn’t work for a release though.

4

It seems that ejabberd do not define logger application in it’s dependencies which mean that the launch order can be different between versions which causes the problems that in production it uses lager while locally it uses Logger.

5

I added lager_logger to my dependencies and added the following to config/config.exs:

# Redirect ejabberd logs (using lager) to Elixir's logger
config :lager,
  handlers: [lager_logger: :info]

This works fine when I run my app through mix. Unfortunately the release build still makes problems - it looks like lager doesn’t use that configuration setting. Do I have to do something else or add that config setting to a different file?

6

Is it possible that the following code in ejabber’s logger:


overrides my configuration in config.exs? But then again setting the handler to lager_logger works fine when I run the app with mix :thinking:

7

Thanks, this post helped me out! Although, I ended up using a different library which operates in reverse: logger_lager_backend sends Logger events to lager.

I’m also looking forward to some consolidation here! :beer:

8

Working on it.

3 Likes