RE: [Cdk-devel] logger.debug performance + cake

[Anatoli K. <ana...@in...>]

Hello Miguel,

I like you proposed solution. Having=20

LoggingTool.debug(String message, Object o)
LoggingTool.debug(String message, Object o1, Object o2)

et cetera, et cetera will resolve lots of issues.=20

And as you mentioned, in cases when even getting the object is =
expensive, we
could always place logger.isDebugEnabled() conditional block as per =
log4j
recommendations.

To be compatible with log4j and facilitate this override, LoggingTool =
should
have=20

boolean isDebugEnabled();
boolean isInfoEnabled();

plus supporting methods and appropriate infrastructure.

By the way, I manually removed logging offending statements from my =
local
sources and run and indeed CDK runs significantly faster.

Cheers,
 Toly

-----Original Message-----
From: cdk...@li...
[mailto:cdk...@li...] On Behalf Of Miguel =
Howard
Sent: 06 February 2004 10:28
To: cdk...@li...
Subject: [Cdk-devel] logger.debug performance + cake

Egon wrote:
> (Solution III)
> 	If really most time is spend on ChemObject.toString() methods,
> we
> could also add a method LoggingTool.debug(ChemObject) which will do
> the  .toString() internally, only if debugging is enabled. That would
> mean that the source code of most classes would actually simplify,
> instead of becoming more complex. But, the performance gain might be
> less, because now and then,
>   	Classes can still make complex debug messages without doing
> .toString()...


Anatoli wrote:

> LoggingTool.debug(msg, ChemObject); will definitely work, but I agree
> that it will be impossible to cater for all cases and it performance
> gain will be less. Arguably, it is a bit too much fuss to maintain.

I think there is a variant of Egon's proposed solution this which will
allow you to "have you cake and eat it too" ...

The *grand majority* of the performance problem is the process of
turning these things into strings unnecessarily and garbage-collecting
them. The overhead of the function call is insignificant.

Egon proposed passing a message and a ChemObject. You can get a much
more general solution by just passing Objects.

Every object knows how to turn itself into a string. Therefore, there is
no reason to convert things into strings before calling your
logger.debug method.

Change the parameter types for your debug methods to be Objects, rather
than Strings (or ChemObjects). Then, those objects won't get converted
into Strings unless debugging is turned on.

  public void debug(String logMessage) {
    if (! loggingTurnedOn)
      return;
    ...
  }

becomes

  public void debug(Object logObject) {
    if (! loggingTurnedOn)
      return;
    String logMessage =3D "" + logObject;
    // or if you prefer,
    // String logMessage =3D logObject.toString();
    ...
  }


>From the outside, change the calls:
  logger.debug(atom.toString());
becomes
  logger.debug(atom);


Anatoli wrote:
> but I agree that it will be impossible to cater for all cases


You can handle cases with multiple parameters by having several
different debug methods in the logger which Handle this by having
several parameters:
  logger.debug(atom1, " bonds with ", atom2);

This would be defined as:

public void debug(Object logObj1, Object logObj2, Object logObj3) {
  if (loggingTurnedOn)
    debug("" + logObj1 + logObj2 + logObj3);
}



You can easily starting implementing this today without breaking any
existing code. Just change the parameter type to the debug message ...
all existing code which is constructing strings will continue to work.
Then you can start going through and removing all the .toString() calls
and splitting up the string concats into multiple parameters.


Egon wrote:
> But, the performance gain might be less, because now and then,
> Classes can still make complex debug messages without doing
> .toString()...

If there is a *lot* of calculation going on just for debug logging
purposes then it is appropriate to put in a conditional block. In this
case it is *benefit* to have it there, because it tells the person
reading the code that all this calculation is for debugging and/or data
structure verification.



Anatoli wrote:
> I could see merit in the patch system you propose. It is definitely
> much cleaner and intuitive. At the same time I could see 2 problems:
>
> 1) The code is actively manipulated during build. It could corrupt the
> code at build stage which will be invisible to the author and make
> debugging very hard. The professional programmer in me is inherently
> paranoid about any automatic source manipulations unless dead
> necessary, :-).

Manipulating the source code before it gets compiled is a major problem
for emacs and integrated development environments. For me, it is one of
the primary reasons why I don't like working on CDK. I cannot compile
and debug from within emacs.

> 2) More importantly, I actually like to have logger.debug() statements
> available to me in distribution even if they are disabled in log4j
> configuration. Opportunity to precisely control amount of output is
> one of the great advantages of using log4j.

I agree.

> I am actually very happy with the amount of debugging CDK provides me.
> I want it to be available all the time; I do not want to have two
> distribution versions of CDK (with and without debugging).

For this type of 'product' I think it is very important to easily be
able to turn logging on and off.



Miguel





-------------------------------------------------------
The SF.Net email is sponsored by EclipseCon 2004
Premiere Conference on Open Tools Development and Integration
See the breadth of Eclipse activity. February 3-5 in Anaheim, CA.
http://www.eclipsecon.org/osdn
_______________________________________________
Cdk-devel mailing list
Cdk...@li...
https://lists.sourceforge.net/lists/listinfo/cdk-devel