Fredrik Thulin wrote:
> In general, I think that LOG_DEBUG and similar macros that evaluate code 
> are unappealing because it makes it harder to understand the code, but I 
> am also of the opinion that aesthetics in code are not always to be 
> considered paramount.

Generally I agree that macros are unappealing, however convoluting code 
with many calls related to debugging is an aesthetics problem on its own 
no matter what the syntactic construct is used to call the debug 
function.  It seems to me that this is what tracing was designed for - 
have an ability to do debug tracing without poputing the code with 
extraneous calls.

Also, I wouldn't imagine that anyone would run a production system with 
debug logging turned on.

> Earlier profiling has indicated that debug logging in YXA accounts for 
> about 10% of the work performed in a proxy (probably actually even more 
> percents, see below). Before Erlang got SMP support, it also introduced 
> a lot of unhealthy blocking (on every platform but Solaris I believe). 
> I'm not sure if SMP enabled Erlang still has a big mutex around all I/O, 
> so this may still be the case.

10% of performance improvement is also what we saw.  We've been playing 
with this lately after the SMP emulator race condition bug was fixed in 
trying to explain why the SMP mode gives only a 1.5 performance increase 
on a 4-CPU host.

> What types of log messages actually written out to disk was made 
> configurable recently, and even though probably not unmeasurable the 
> performance win of using a macro like that instead of a macro that makes 
> the actual log function just return immediately are probably negligible.

What the macros help with is to be able to see quickly without guessing 
whether logging calls have any performace impact or not.  Even if 
there's negligible performance loss, it is a convenience helper in 
profiling if not anything else.

> Did you really mean "without recompilation"? If ?LAZY were defined to [] 
> instead of evaluating the call to lists:flatten (in a fun()), then how 
> could that be changed without recompilation? Were you thinking that 
> ?LAZY would be something like
> 
> -define(LAZY(A),
>     case yxa_config:get_env(debug_log_enabled) of
>         true  -> fun() -> A() end;
>         false -> []
>     end).

Yes indeed, or else doing the yxa_config:get_env/1 call inside the 
logger:log/3.

> Seriously, what I would like to do is to release YXA 1.0 before making 
> this change (I'm just waiting for a new edoc), and then do some 
> measurements on the performance gained by ?LAZY just to make sure it is 
> worthwhile, and then do it. If YXA 1.0 can be correct, then 1.5 or 
> something could be both fast and correct =). Is this acceptable?

Sure!

> /Fredrik
> 
> PS. The really _really_ good solution would be one that made it possible 
> to evaluate if a transaction should get debug logging or not at runtime, 
> so that one could enable debug logging for a specific peer when needed. 
> I don't know if that is ever going to be possible with lazy creation of 
> log data though. I've tried creating such functionality before by 
> letting the logger process look at the group leader for whatever process 
> generates a log message, and then see if the group leader has been 
> flagged for debug logging or not, but never got it working...

We've been using dynamic code generation to accomplish similar things. 
As an example, the configuration data (similar to 'debug_log_enabled' 
above) is stored in a dynamically generated code with semantics:

get_key(Key::atom()) -> Value::term().

put_vals([{Key::atom(), Value::term()}]) -> ok.

The auto-generated code is compiled dynamically and looks like this:

...
get_key(debug_log_enabled) -> true;
get_key(some_option_a)     -> true;
get_key(some_option_b)     -> [a, b, c];
...

This method has a cost of a single function call for a value lookup and 
gives a better performance than ets lookups.  The same principle can be 
used for selective transaction logging, as well as substituting 'local' 
function calls at startup *once* instead of doing that via ets lookups 
for every call in local.erl.

If interested we can send you some sample code that does dynamic code 
generation.

Regards,

Serge
_______________________________________________
Yxa-devel mailing list
Yxa-devel@lists.su.se
https://lists.su.se/mailman/listinfo/yxa-devel

Reply via email to