Feuerlabs / exometer_core

Core components of exometer
Mozilla Public License 2.0
193 stars 121 forks source link

Lager dependency unfriendly #57

Open eproxus opened 8 years ago

eproxus commented 8 years ago

In my opinion, including Lager is outside the scope of Exometer. We're trying to include Exometer in an existing Elixir application which uses the Elixir's Logger. Getting Lager included just because of Exometer adds a lot of overhead and makes configuring logging much more complex (we either have to disable Lager or make it somehow send messages to the Elixir logging framework).

I see three possible solutions:

  1. Exclude logging completely from Exometer
  2. Use error_logger (which is picked up by Lager and Elixir's Logger anyway)
  3. Make logging/events inside Exometer be handled by a user defined callback module
tolbrino commented 8 years ago

I ran into the same situation with an Elixir project. Obviously this is an issue for any Erlang/Elixir library.

Since exometer doesn't use much of lager anyway and historally has only done so since it was integrated in Riak early on, I'd be fine with generalizing logging. @uwiger what do you think?

uwiger commented 8 years ago

@tolbrino I'm fine with it, but I'd also like to hear from Basho. After all, Exometer is their product and this is a fairly significant change.

tolbrino commented 8 years ago

@uwiger Good point.

jonmeredith commented 8 years ago

@eproxus Ulf pinged me and we had a quick conversation. I thought your error_logger idea sounded best, until Ulf pointed out the lack of debug logging support in SASL....

I suppose there's a 4th option of trying to make it a compile time choice and switch between lager calls or the Elixir Logger.

I still haven't played with Elixir much - how are other libraries handling this?

tolbrino commented 8 years ago

@jonmeredith Exometer is more involved than a normal library, an application really. Lots of Elixir libraries simply default to the Elixir logger. Since exometer already includes the log.hrl extending that to support switching the logging library would be easy.

Alternatively, exometer doesn't use lager debug a lot anyway. In my use cases I always found that I wanted to debug at the interfaces to exometer from my applications, which is fine since an umbrella application can always choose to use lager. This way one can also easily trace inside of exometer if needed.

Also we've got the lager reporter which could be used to pipe whatever data is needed into lager on a debug level easily.

eproxus commented 8 years ago

In my opinion, a library that is not application specific, should never force me into a certain logging paradigm.

If you really need the introspection into Exometer (that the error_logger cannot provide), I would then suggest the 3rd option, possible even together with a bundled Lager event callback module (where the dependency on Lager would be removed still). Then people who want to use Lager can just configure that callback module to be used.

uwiger commented 8 years ago

In the locks application, instead of using a logger for debugging, I simply use an ?event() macro (example), which ends up calling an empty function. When I want to activate debugging, I use TTB to trace on the event functions (see locks_ttb). The place where I use this the most is in the more complicated test suite (example)

The following screenshot shows what the pretty-printed trace log from a multi-node trace looks like in emacs:

screenshot 2016-01-08 12 27 00
uwiger commented 8 years ago

One of the nice things about lager:debug() is that it won't process the input arguments unless logging is enabled at that level. This means that one can massage the debug output without incurring runtime overhead with debugging disabled.

It's not an issue in exometer in the sense that it doesn't currently massage debug output arguments. However, it does pretty-print, and using the ?event-style debugging as above tends to produce slightly messier output.

FWIW, in the latest push to locks, I introduced a ?costly_event macro, which only calls the event function if that function is being traced. I think this increases the usefulness of the technique somewhat.

eproxus commented 8 years ago

Well, if a couple of calls to an empty callback module (which would be the case for option 3) is too much overhead, I would instead suggest a debug macro in Exometer that will compile in all the Lager logging code. That way, we can remove the dependency on Lager, and people who use this macro would have to make sure Lager is present when running and compiling.

uwiger commented 8 years ago

To be clear, 'disabled' lager debug macros are not zero overhead either.

Specifically, the generated check for a lager:debug() is

case {whereis(lager_event), whereis(lager_event), lager_config:get({lager_event,loglevel}, {0,[]})} of
    {undefined,undefined,_} -> fun() -> {error,lager_not_running} end();
    {undefined,_,_} ->               fun() -> {error,{sink_not_configured,lager_event}} end();
    {__Pidexometer_report1160, _, {__Levelexometer_report1160, __Tracesexometer_report1160}}
        when __Levelexometer_report1160 band 128 /= 0 orelse  __Tracesexometer_report1160 /= [] ->
        lager:do_log(debug, [{application,exometer_core} | ...], ...);
    _ ->
        ok
end,

where lager_config:get/2 performs an ets:lookup/2.

eproxus commented 8 years ago

Oh, then a callback module with a no-op function should be much faster? So win-win?

jonmeredith commented 8 years ago

The problem with a callback module is you would lose the line number reporting that you get from the parse transform - all error reports would come from exometer_log:info:1234 rather than the original call site.

Converting all the lager code to compile time macros seems like the best option (and checking it doesn't have any similar problems - I'm fairly certain the preprocessor gets to run before the parse transform).

eproxus commented 8 years ago

Good point with the line numbers.

The only problem I see is that when Lager is not a dependency of the project, you might have problems including the Lager header file when that compile time macro is enabled.

jonmeredith commented 8 years ago

Hmmm, maybe make rebar.config.script add a preprocessor define around which code files it can see? Check for lager in the path and define LOG_LAGER, check for the Elixir logger and define something else?

On Mon, Jan 11, 2016 at 7:52 AM Adam Lindberg notifications@github.com wrote:

Good point with the line numbers.

The only problem I see is that when Lager is not a dependency of the project, you might have problems including the Lager header file when that compile time macro is enabled.

— Reply to this email directly or view it on GitHub https://github.com/Feuerlabs/exometer_core/issues/57#issuecomment-170577263 .

tolbrino commented 8 years ago

Could you guys take a look at https://github.com/tolbrino/hut and let me know what you think? I tested it locally with exometer_core and it works fine.

eproxus commented 8 years ago

For me, Hut looks good. How would an optional dependency be specified in a project using it (e.g. Exometer and Lager)?

tolbrino commented 8 years ago

Exometer would include Hut as its dependency. Your umbrella project would include Exometer and Lager as its dependency. Then, depending on your build tool, you'd ensure that Exometer gets compiled with the macro HUT_LAGER.

eproxus commented 8 years ago

Sounds reasonable to me. I think that no-op or SASL logging should be the default though. Having ton's of io:format's everywhere would not be nice.

tolbrino commented 8 years ago

I thought of switching to SASL for the default too.

jonmeredith commented 8 years ago

Hey Tino - @mrallen1 took a look at hut and thinks that it will work fine integrating with Riak, so feel free to go ahead and convert if you would like.

I'd also vote for SASL as it's part of the standard runtime and should always be present - that seems like a much better compromise between nothing at all and a spew of io:formats.

tolbrino commented 8 years ago

@jonmeredith Thanks for the feedback. I'll do the conversion then and adapt the default.

eproxus commented 8 years ago

@tolbrino Looking forward to trying it out. :-) Thanks for putting in the effort.

tolbrino commented 8 years ago

@eproxus The PR replacing lager has been merged. I feel like we can close this discussion.

surik commented 8 years ago

I really don't understand how I can use exometer_core with hut in Elixir application. For example I have an application which uses exometer_core from master:

defmodule App.Mixfile do
  use Mix.Project

  def project do
    [app: :app,
     version: "1.0.0",
     deps: deps(Mix.env)]
  end

  def application do
    [applications: [:exometer_core],
     mod: {App, []}]
  end

  defp deps(_) do
    [{:exometer_core, github: "Fuerlabs/exometer_core"}]
  end
end

How I can build it with using Logger? I have seen on example in hut but it looks redundantly to create Makefiles instead using mix or rebar.

tolbrino commented 8 years ago

What exactly is your intention? Obviously you can use Elixir.Logger in your app as you please. If you are talking about using it in exometer_core, that is not supported by hut as of now. Feel free to post a PR. However, Elixir.Logger already intercepts SASL logging, so even the standard config for hut should be ok. Btw, there is a type in Feuerlabs in your deps.

surik commented 8 years ago

@tolbrino ok, I see that Elixir.Logger is not supported right now.

My question is not about Logger. My question is how I can change default logging system for exometer_core in my Elixir application? Lets imagine I want to use lager. How I can say to mix to compile exometer_core with -DHUT_LAGER option? In your example I see you use Makefile. Is it preferable way?

tolbrino commented 8 years ago

When using rebar you can set these preprocessor macros using the erl_opts property, see https://github.com/rebar/rebar/blob/master/rebar.config.sample

surik commented 8 years ago

@tolbrino I'm not sure but looks erl_opts will be used only for current application and not for dependencies. That means exometer_core will use default logging system.

tolbrino commented 8 years ago

Ok, now I get your point. I'll look into and dig up an example.

surik commented 8 years ago

Hi @tolbrino, any results?

mootpointer commented 8 years ago

Wouldn't a seperate hut_lager package which integrates hut with lager make more sense than using preprocessor macros?

surik commented 8 years ago

@mootpointer how separated hut_lager can help me build exometer_core with lager?

Maybe better to use sasl directly without additional dependency which is difficult to use?