[erlang-questions] Logging methods in Erlang (FUNCTION macro)

Michael Truog mjtruog@REDACTED
Fri Sep 5 23:25:58 CEST 2014


When you care about the efficiency of logging within Erlang source code (i.e., only using Erlang source code for a logging solution) there are two main solutions:

1) Dynamically compile a module based on the logging level that is currently set and reload it.  Lower log levels are naturally ignored because their function doesn't do anything within the updated module.  This was done in older versions of ejabberd (https://github.com/processone/ejabberd/blob/2.1.x/src/ejabberd_loglevel.erl), but ejabberd has since switched to using lager.  CloudI uses this approach (https://github.com/CloudI/CloudI/blob/develop/src/lib/cloudi_core/src/cloudi_core_i_logger.erl).

2) Use a parse transform to rewrite all the source code that wants to do logging so that it can determine whether it needs to log by checking global state, probably in ets.  This approach is taken in lager with the parse transform at https://github.com/basho/lager/blob/master/src/lager_transform.erl .

I strongly believe you should not be required to dynamically change all your source code to facilitate logging, since that can be a source of problems for stability and transparency.  It is good to have the assurance that running module X is actually X's source code, since you can then make clear assertions about the behaviour of execution within module X.  Adding random source code (i.e., source code you don't control in a common dependency) to everything via a parse transform weakens your ability to understand the system with debugging, profiling, and basic human understanding, in addition to providing an opportunity for all source code to contain a difficult to discover error previously unknown within the transform.  The additional problem with the parse transform is the usage of global data to get the log level. Performance-wise it is better to have the log level setting the source code in a way that the change is a constant (i.e., a version of a module loaded) instead of 
dynamic data in ets which is volatile.

The main data missing from the logging approach #1 that is present in #2 is the function name.  Since Erlang is a functional programming language, functions are the most important element, not modules.  We already have a MODULE macro that helps to facilitate code reloading (while also being useful for logging), though we currently don't have a FUNCTION macro to provide the function name with no overhead.

I understand it is possible to get the function name from the stack trace with an exception like so:
current_function() ->
     catch throw(x), [_, {_, F, _, _} | _] = erlang:get_stacktrace(),
     F.

A method of getting the function name from the stack trace with less overhead is:
erlang:element(2, erlang:element(2, erlang:process_info(self(), current_function)))).

However, it is much better if we can avoid any overhead when getting the current function name.  That means it would be best to have a FUNCTION preprocessor macro available within Erlang source code.  Is there any clear reason why this should not be done?

Thanks,
Michael




More information about the erlang-questions mailing list