Lazy construction of parameters

[anders.johansen]

Hi,

I would like to convert code such at this:

if (entry == null) {
log.warning("No entry found in storeEntries for
arcfilename: "
+ arcfileName);
}

....to this:

LogWarning.ifNull(entry, "No entry found in storeEntries for
arcfilename: " + arcFileName);

In effect consolidating common logging situations to one line of code.

Unfortunately, this means that the cost of constructing the message
must be paid always, and not just when the test fails. This has been
raised as a potential concern by some of my collaborators. In
particular, some like to construct lengthy messages in case of fails,
involving DB lookups etc.

Is there any easy way to deal with this, that retains the simple syntax
for the programmer?

Sincerely,
Anders S. Johansen

 

[Chris Uppal]

Unfortunately, this means that the cost of constructing the message
must be paid always, and not just when the test fails. This has been
raised as a potential concern by some of my collaborators. In
particular, some like to construct lengthy messages in case of fails,
involving DB lookups etc.

Is there any easy way to deal with this, that retains the simple syntax
for the programmer?

The only way that I can think of involves having many overloaded definitions of
LogWarning.ifNull().

void ifNull(Object it, String msg);
void ifNull(Object it, String msg1, String msg2);
void ifNull(Object it, String msg1, String msg2, String msg3);
... etc ..

You might be tempted to use the new varadic argument list stuff in 1.5. That's
by no means a bad idea, but you should be aware that every call to a varadic
method call involves allocating an array to hold the apparent arguments. I
suppose you could use explicit arguments up to some smallish limit, and then
have a varadic version as a fall-back to handle the rare cases.

-- chris

 

[dduck]

Hi,

Good suggestions!

Still, they do not solve the problem of string construction in the
example. The cost I am trying to avoid is constructing:

String _tmp = "No entry found in storeEntries for arcfilename: " +
arcfileName;

If one uses if/then, this string is never constructed.

Compare that to the use of Java's "assert" method, which does not
impose that penalty.

boolean cond=true;
assert cond : "This string " + "is never constructed";

I attempted using this behaviour to implement lazy conversion to
string, but it turned out to be either impossible or beyond the reach
of my wild Java-fu Briefly I attempted to use Java assert to check
the condition, and then use the AssertionFailed exception thrown if
condition failed as signal for string construction. This works, but
apparently can't be encapsulated in a method, as the method call forces
the toString() conversion of the message parameter, possibly to avoid
(lack of) side effects for correctness.

A

 

[James Westby]

Hi,

Good suggestions!

Still, they do not solve the problem of string construction in the
example. The cost I am trying to avoid is constructing:

String _tmp = "No entry found in storeEntries for arcfilename: " +
arcfileName;

If one uses if/then, this string is never constructed.

Compare that to the use of Java's "assert" method, which does not
impose that penalty.

boolean cond=true;
assert cond : "This string " + "is never constructed";

I attempted using this behaviour to implement lazy conversion to
string, but it turned out to be either impossible or beyond the reach
of my wild Java-fu Briefly I attempted to use Java assert to check
the condition, and then use the AssertionFailed exception thrown if
condition failed as signal for string construction. This works, but
apparently can't be encapsulated in a method, as the method call forces
the toString() conversion of the message parameter, possibly to avoid
(lack of) side effects for correctness.

A

If you don't mind having two different ways of doing the same thing
within your source code then you could provide your convenience method
for the simple cases where the overhead is not great, and use the
original syntax for the expensive cases.


James

 

[Bart Cremers]

Do avoid string the construction I would change to logger to use
MessageFormat to help out.

public class LogWarning {
public static void ifNull(Object it, String message, Object arg) {
if (it == null) {
System.out.println(MessageFormat.format(message, arg));
}
}

public static void ifNull(Object it, String message, Object[]
objects) {
if (it == null) {
System.out.println(MessageFormat.format(message, objects));
}
}
}


....
LogWarning.ifNull(entry, "No entry found in storeEntries for
{0}", arcfilename);
....

Bart

 

[Chris Uppal]

Still, they do not solve the problem of string construction in the
example.

Try the appended code (never compiled, let alone tested). Use like:

LogWarning.ifNull(
entry,
"No entry found in storeEntries for arcfilename: ",
arcFileName);

Note that Strings are neither constructed (toString()) nor appended unless
necessary. Parameter arrays don't get constructed if there is an optimised
case available.

-- chris


=======================
public class
LogWarning
{
// *** Conditional Logging ***

// optimised form for 1 argument case
public static void
ifNull(Object it, Object msg)
{
if (it != null)
log(msg);
}


// optimised form for 2 argument case
public static void
ifNull(Object it, Object msg1, Object msg2)
{
if (it != null)
log(msg1, msg2);
}

// general case
public static void
ifNull(Object it, Object... msgs)
{
if (it != null)
log(msgs);
}


// *** Unconditional Logging ***

// optimised form for 1 argument case
public static void
log(Object msg)
{
log(msg.toString());
}


// optimised form for 2 argument case
public static void
log(Object msg1, Object msg2)
{
log(msg1.toString() + msg2.toString());
}

// general case
public static void
log(Object... msgs)
{
StringBuilder builder = new StringBuilder();
for (Object msg : msgs)
builder.append(msg);
log(builder.toString());
}

// base case
public static void
log(String text)
{
// ... whatever ...
}
}
=======================

 

[dduck]

Hi all,

Many good suggestions here! I will profile a bit, and see what
develops. This may solve an existing performance problem in our code.

None however solve (unless I am mistaken) the case that some of my
collaborators argue, namely extremely expensive messages created from -
say - DB lookups, such as (pseudocode):

LogWarning.ifNull(entry, "Entry was null, DB contained " +
DB.findClients("name == John Smith").count() + " clients named John
Smith");

The claim is that it is potentially dangerous to performance to
encourage this use, by making the convinience methods available.
Personally I would in such cases profile to diagnose, and then refactor
the critical cases to if/then, but a generic, zero-cost solution (in
case of passed test) would obviously be preferable. One could inversely
argue that when the convinience methods are not always zero-impact as
compared to the if/then construct, then they are not an absolute
improvement, and should hence not be used.

I know... I doubt it is possible too... Java assert can swing it, but
that is a keyword-level construct with explicit compiler support and
special sematics (no evaluation fo message unless test fails). That may
be very hard to duplicate in usercode.

Sincerely,
Anders

 

[Bart Cremers]

You could take this a lot further and use reflection to solve the
expensive message creation.

Object entry = new Object();
String arcfilename = "MyFilName";

LogWarning.ifNull(entry, "No entry found in storeEntries for
{0}", arcfilename);

long time = System.currentTimeMillis();
LogWarning.ifNull(entry, "Entry was null, DB contained {0}
clients named John Smith",
DB.findSomething("name == John Smith"));
long end = System.currentTimeMillis();
System.out.println("Took " + (end - time) + " millis");

time = System.currentTimeMillis();
LogWarning.ifNull(entry, "Entry was null, DB contained {0}
clients named John Smith", new ReflectionHelper(
DB.class, "findSomething", "name == John Smith"));
end = System.currentTimeMillis();
System.out.println("Took " + (end - time) + " millis");


class LogWarning {
public static void ifNull(Object it, String message, Object arg) {
if (it == null) {
System.out.println(MessageFormat.format(message, arg));
}
}

public static void ifNull(Object it, String message, Object[]
objects) {
if (it == null) {
System.out.println(MessageFormat.format(message, objects));
}
}
}

class DB {
public static int findSomething(String args) {
try {
Thread.sleep(5000);
} catch (InterruptedException e) {
}

return 500;
}
}

class ReflectionHelper {
private Object instance;
private Method method;
private Object[] args;

public ReflectionHelper(Object instance, String method, Object...
args) {
this(instance.getClass(), instance, method, args);
}

public ReflectionHelper(Class clazz, String method, Object... args)
{
this(clazz, null, method, args);
}

private ReflectionHelper(Class clazz, Object instance, String
method, Object[] args) {
this.instance = instance;
this.args = args;

Class[] paramTypes = new Class[args.length];
for (int i = 0; i < args.length; i++) {
paramTypes = args.getClass();
}

try {
this.method = clazz.getMethod(method, paramTypes);
} catch (NoSuchMethodException e) {
}
}

private Object execute() {
if (method != null) {
try {
return method.invoke(instance, args);
} catch (IllegalAccessException e) {
return "[ERROR EXECUTING] " + e.getMessage();
} catch (InvocationTargetException e) {
return "[ERROR EXECUTING] " + e.getMessage();
}
}
return "[ERROR EXECUTING]";
}

public String toString() {
return execute().toString();
}
}


Now, this is just some rough code and for sure not production quality,
but solves the issue.

Bart

 

[dduck]

Followup to Chris:

I implemented your solution (see below), and did a bit of measurement
(see below again). In case of condition not true (so no logging), the
optimized solution Chris proposed is approximately 20 times faster on
my testcode.

I changed the test to isTrue for convinience, and implemented this
method in addition to the ones proposed by Chris:

public static void
ifTrueString(boolean cond, String msg) {
if (cond) {
log(msg);
}
}


The log method was implemented thus:

// base case
private static String msg;
public static void
log(String text)
{
// System.out.println("Log: " + text);
msg = text;
}

The commented line was used for inital testing.

I then used this test class to measure time consumption:

package ImprovedLogging;

import java.util.Calendar;
import java.util.Random;

public class MyLoggerTester {

/**
* @param args
*/
private static final int nTimes=1000000;
private static String aString = "aString contents";
private static void logString(boolean cond) {
for (int i=0; i<nTimes; ++i) {
MyLogger.ifTrueString(cond, "Appended with aString " + aString);
}
}
private static void logOptimized(boolean cond) {
for (int i=0; i<nTimes; ++i) {
MyLogger.ifTrue(cond, "Appended with aString ", aString);
}
}
public static void main(String[] args) {
Random rnd = new Random(42424242);
boolean cond = rnd.nextDouble()>2; // Change to <2 to get true
condition
long start = Calendar.getInstance().getTimeInMillis();
logString(cond);
System.out.print("Elapsed ms ");
System.out.println(Calendar.getInstance().getTimeInMillis()-start);
start = Calendar.getInstance().getTimeInMillis();
logOptimized(cond);
System.out.print("Elapsed ms ");
System.out.println(Calendar.getInstance().getTimeInMillis()-start);
}
}

In my setup I get:
Elapsed ms 750
Elapsed ms 32

...for false condition (no logging) and:
Elapsed ms 1125
Elapsed ms 1109

....for true condition.

Comments?

Sincerely,
Anders

 

[dduck]

@Bart:

Neat solution. In effect, you are building a higher-order function, and
then defer invocation. Thought about doing something like that, but
didn't have the Java skills yet - I am still in transition from C++,
where I'd just use the preprocessor for this...

Sincerely,
Anders

 

[Torsten Kirschner]

Hi,

I would like to convert code such at this:

if (entry == null) {
log.warning("No entry found in storeEntries for
arcfilename: "
+ arcfileName);
}

...to this:

LogWarning.ifNull(entry, "No entry found in storeEntries for
arcfilename: " + arcFileName);

In effect consolidating common logging situations to one line of code.

Unfortunately, this means that the cost of constructing the message must
be paid always, and not just when the test fails. This has been raised
as a potential concern by some of my collaborators. In particular, some
like to construct lengthy messages in case of fails, involving DB
lookups etc.

Is there any easy way to deal with this, that retains the simple syntax
for the programmer?

Simpler than if() {} else {} which already solves your problem?

Your case seems to be rather special. Apparently, your test result does
not change the control flow of your program other than the need for
logging it.

Such cases are rarely the focal point of development in my experience.

I wouldn't invest too much time into creating an obscure logging
"framework" which side effect is testing.

You could look into the ternary operator. It appears to use short circuit
evaluation.

 

[Martin Gregorie]

I would like to convert code such at this: ....

In effect consolidating common logging situations to one line of code.

I think you may have overlooked the point that the variety of triggering
conditions is normally as great as the number of ways of building the
warning message.

I prefer to leave the condition outside for added flexibility. This
means I only need a single convenience class, ReportError, that has one
constructor and two methods:

public class ReportError
{
public ReportError(String progname) { }

public void trace(String trace_string) { }
public void error(String error_string) { }
}

trace() simply assembles and outputs the message to stderr while error()
outputs a message to stderr of the form "progname: error_string" before
calling System.exit(1).

I get maximum flexibility and readability from this class. error()
simply traps fatal conditions while trace() is used both for reporting
progress in a long running progress and for diagnostic tracing within an
"if (debug) { } " condition.

If I find the need to send messages to a system log I'll probably extend
ReportError with a logMessage() method.

 

[Ingo R. Homann]

Hi,

I would prefer something like this:

LogWarning.ifNull(entry, new Object(){public String toString(){return
"Entry was null, DB contained " +
DB.findClients("name == John Smith").count() + " clients named John
Smith"});

This is much easier and - in contrast to the reflection-solution - has
full compile-time safety (which would be the main advantage for me to
use this).

Of course, it would be easier, if there was a special syntax for that
("closures"?)

Ciao,
Ingo

 

[tom fredriksen]

You might be tempted to use the new varadic argument list stuff in 1.5.

Whats a varadic? i presume you mean variable argument list.

In any case it would be a normal way of solving it. The vararg parameter
is programmer shorthand for an array of X, in this case Strings. The
compiler takes care of the details.

So what you do is create a vararg parameter, and you pass all strings as
individual strings to the method. In the method, you check for null and
construct the final string if needed. This costs you almost nothing more
than the original statement except for perhaps the cost of copying the
string references to the parameter stack and invoking the jump.
That is small cost I am willing to pay for the simplified code.

/tom

 

[Chris Uppal]

Whats a varadic? i presume you mean variable argument list.
Yes.


This costs you almost nothing more
than the original statement except for perhaps the cost of copying the
string references to the parameter stack and invoking the jump.

Well, it has the cost (as I mentioned in my earlier post) that each call to a
varadic method involves allocating an array with N slots, and copying the N
parameters into the array, before calling the method (passing the array as the
parameter). Java's varadic methods are not implemented by witchery with the
parameter stack as is (often) the case for 'C' varargs implementations.

In many cases that extra expense is not worth worrying about, but you should be
aware that it is there.

-- chris

 

[Chris Uppal]

Of course, it would be easier, if there was a special syntax for that
("closures"?)

Yes, that's what I would call "closures" (in this context). And also yes, in a
language with syntactic support for them, using closures as the basis of
conditional logging produces a very clean, usable, flexible, and reasonably
efficient, design.

-- chris

 

[Stefan Ram]

Yes.
varadic

The adjective actually is »variadic«, however the JLS uses
»variable arity«.

 

[Piotr Kobzda]

I would like to convert code such at this:

if (entry == null) {
log.warning("No entry found in storeEntries for
arcfilename: "
+ arcfileName);
}

...to this:

LogWarning.ifNull(entry, "No entry found in storeEntries for
arcfilename: " + arcFileName);

In effect consolidating common logging situations to one line of code.

So what about line like this:

logger.logWarningIf(entry == null
&& logger.setMessage("No entry found in storeEntries for
arcfilename: " + arcfileName));


Thanks to use of Java '&&' operator second operand will be computed only
when the first one is true. As the result no message build is performed
unless really needed.


In this case Logger must buffer your message before commitment of the
printout, like in the following example:


public class Logger {

private String message;

public void logWarningIf(boolean needToLogIt) {
if (needToLogIt) {
System.out.println("warning: "+ message);
}
}

public boolean setMessage(String msg) {
message = msg;
return true;
}

}

P.S.

I've never used it, my preference is classic if (...) { log... }
scenario, and honesty saying I can't see any reason to switch to
something else.


Regards,
piotr

 

[Eric Sosman]

Hi,

I would like to convert code such at this:

if (entry == null) {
log.warning("No entry found in storeEntries for
arcfilename: "
+ arcfileName);
}

...to this:

LogWarning.ifNull(entry, "No entry found in storeEntries for
arcfilename: " + arcFileName);

In effect consolidating common logging situations to one line of code.

Unfortunately, this means that the cost of constructing the message
must be paid always, and not just when the test fails. This has been
raised as a potential concern by some of my collaborators. In
particular, some like to construct lengthy messages in case of fails,
involving DB lookups etc.

Is there any easy way to deal with this, that retains the simple syntax
for the programmer?

The pre-existing syntax looks pretty simple to me ...

One way to repackage so while avoiding the potentially
expensive message construction would be

LogWarning.ifNull(entry,
new Object() {
public String toString() {
return "No entry found ... "
+ arcfileName
+ expensiveStuff();
}
}
);

Note that arcfileName would need to be final in this
scenario. Note also that it always constructs an Object,
even if it then does nothing but throw it away -- one
supposes that the Object construction is cheaper than the
database queries and such that go into building the message
itself.

I really don't think this would be an improvement over
the original -- all this foofaraw just to relocate an `if'?
But there's no point arguing with Gus, as the old saying
has it. ;-)

 

[Chris Uppal]

The adjective actually is »variadic«, [...]

It is ? <checks...> Ah yes, that is more common by /far/. Thank you for the
correction.

-- chris