Java Forum / General / March 2006
Lazy construction of parameters
anders.johansen@gmail.com - 14 Mar 2006 10:16 GMT 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 - 14 Mar 2006 12:05 GMT > Unfortunately, this means that the cost of constructing the message > must be paid always, and not just when the test fails. This has been [quoted text clipped - 4 lines] > 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 - 14 Mar 2006 13:15 GMT 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 :D 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 - 14 Mar 2006 13:22 GMT > Hi, > [quoted text clipped - 24 lines] > > 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 - 14 Mar 2006 13:33 GMT 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 - 14 Mar 2006 13:42 GMT > 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 - 14 Mar 2006 14:15 GMT 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 - 14 Mar 2006 14:35 GMT 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[i] = args[i].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 - 14 Mar 2006 14:43 GMT 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
Chris Uppal - 15 Mar 2006 11:14 GMT > Elapsed ms 750 > Elapsed ms 32 > > ..for false condition (no logging) and: [...]
> Comments? This sort of benchmarking should really take account of the behaviour of the JIT, but still, taking the above as best case figures, it's questionable whether a saving of less than a second for a million logging calls is really worthwhile.
Of course, the saving is unbounded if you consider more complex code to supply the parameters to the call, but I don't think that expressing arbitrary computation really fits into this framework (or into any other framework expressible conveniently in Java).
-- chris
dduck - 14 Mar 2006 14:50 GMT @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
Jean-Marie Gaillourdet - 15 Mar 2006 10:52 GMT Hi,
dduck schrieb:
> @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... I had a similar problem to yours in our theorem prover with an unparser. I preferred to extend my unparser with lazy unparse methods and combine it with message format logging methods.
class MyLogger extends Logger { public void infof(String messageFormat, Object... args) { return String.format(messageFormat, args) } }
class MyUnparser { String unparse(Formula f) { ... }
Object unparseLazy(Formula f) { return new Object { public String toString() { return unparse(f); } } } }
So applications have the following form:
... logger.infof("Bla bla %s\n", unparser.unparserLazy(f)); ...
instead of
logger.info("Bla bla %s" + unparser.unparser(f) + "\n");
Note: The condition is hidden in info and depends on the global logging configuration in my case.
Regards, Jean-Marie
Ingo R. Homann - 14 Mar 2006 15:30 GMT 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
Chris Uppal - 14 Mar 2006 15:59 GMT > 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
tom fredriksen - 14 Mar 2006 15:30 GMT >> Unfortunately, this means that the cost of constructing the message >> must be paid always, and not just when the test fails. This has been [quoted text clipped - 6 lines] > > 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 - 14 Mar 2006 15:54 GMT > > 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. 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
Stefan Ram - 14 Mar 2006 16:17 GMT >> Whats a varadic? i presume you mean variable argument list. >Yes. >varadic The adjective actually is »variadic«, however the JLS uses »variable arity«.
Chris Uppal - 14 Mar 2006 16:56 GMT > The adjective actually is »variadic«, [...] It is ? <checks...> Ah yes, that is more common by /far/. Thank you for the correction.
-- chris
Torsten Kirschner - 14 Mar 2006 14:59 GMT On Tue, 14 Mar 2006 01:16:05 -0800, anders.johanse wrote:
> Hi, > [quoted text clipped - 21 lines] > 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 - 14 Mar 2006 15:06 GMT > 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.
 Signature martin@ | Martin Gregorie gregorie. | Essex, UK org |
Piotr Kobzda - 14 Mar 2006 16:53 GMT > I would like to convert code such at this: > [quoted text clipped - 10 lines] > > 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
Wibble - 15 Mar 2006 02:42 GMT >> I would like to convert code such at this: >> [quoted text clipped - 49 lines] > Regards, > piotr And of course don't make that Logger a singleton since its not thread safe.
Piotr Kobzda - 15 Mar 2006 09:02 GMT > And of course don't make that Logger a singleton since its not > thread safe. I didn't presume it. Logging is done using Logger instance and there is no limitation in creation as many Logger instances as needed.
Anyway, if someone wish to use a singleton instance, the simple solution to make it thread safe is to use ThreadLocal for message buffer like this:
ThreadLocal<String> message = new ThreadLocal<String>();
Regards, piotr
Eric Sosman - 14 Mar 2006 16:55 GMT anders.johansen@gmail.com wrote On 03/14/06 04:16,:
> Hi, > [quoted text clipped - 21 lines] > 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. ;-)
 Signature Eric.Sosman@sun.com
Wibble - 15 Mar 2006 02:45 GMT > anders.johansen@gmail.com wrote On 03/14/06 04:16,: > [quoted text clipped - 50 lines] > But there's no point arguing with Gus, as the old saying > has it. ;-) Thats alot of hair to avoid saying 'if (blah) print'. Also, if blah is a final boolean, java can just compile out the whole print form.
Perhaps this is best left a problem not solved.
dduck - 15 Mar 2006 08:53 GMT Well, I don't know...
As a relative newcomer to Java-in-the-wild (as opposed to Java-in-the-academia or C++-up-the-wazoo), I don't find the (apparently) common Java ideom of:
Logger logger = Logger.getLogger(<some magic here>); <...> if (condition) { logger.warning(<message>); }
...particular transparent. It's a lot of typing that locks functionality locally with no obvious way to interject run-time filtering of logging (besides hacking something into the logger chain). Why not make a helper method as a shorthand?
I know... I am in the "relentless refactoring for brevity" camp here, and there are other valid points of view. Still, this happens a lot in our 40 K line code base, so every saving of 3 lines + improvement of clarity can probably be multiplied with a factor of at least 100 when evaluating the effect. Of course it should be balanced by an appreciation of the effort involved in refactoring the old ideom and the potential impact on performance and/or stability.
This discussion parallels the one currently taking place in our collaborative work, and so I value comments, experiences and insights - please feel free to contribute.
Anders
Chris Uppal - 15 Mar 2006 11:41 GMT > ...particular transparent. It's a lot of typing that locks > functionality locally with no obvious way to interject run-time > filtering of logging Agreed.
Ultimately, though, I think you are going to hit the problem that Java just is not expressive enough to do this properly. In which case it might be better to settle for a pattern where /every/ log statement is expressed as a conditional:
if (Logger.shouldLog(... something...)) Logger.log(...something else....)
That at least gives you somewhere to introject system-wide filtering without having to find and change every line of logging in the entire code-base.
Yes, it's less that ideal . It's poor structuring. It's verbose. It violates the "don't ask, tell" slogan of OO programming. And, maybe it's less efficient than it might be. But that's what you get when the language is underpowered....
-- chris
Jens Auer - 15 Mar 2006 12:01 GMT > ...particular transparent. It's a lot of typing that locks > functionality locally with no obvious way to interject run-time [quoted text clipped - 8 lines] > appreciation of the effort involved in refactoring the old ideom and > the potential impact on performance and/or stability. Logging is the standard example of aspect-oriented programming, which handles cross-cutting concerns like this and puts them into their own entity. You might want to have a quick look at AspectJ, a Java implementation of aspect-oriented programming.
Free MagazinesGet these publications absolutely FREE for up to 12 months. There are no hidden fees and no obligation. Simply choose a title, complete the application form and submit it. Read more ...
|
|
|