- Feature Articles
- CodeSOD
- Error'd
- Forums
-
Other Articles
- Random Article
- Other Series
- Alex's Soapbox
- Announcements
- Best of…
- Best of Email
- Best of the Sidebar
- Bring Your Own Code
- Coded Smorgasbord
- Mandatory Fun Day
- Off Topic
- Representative Line
- News Roundup
- Editor's Soapbox
- Software on the Rocks
- Souvenir Potpourri
- Sponsor Post
- Tales from the Interview
- The Daily WTF: Live
- Virtudyne
Admin
if (logger.isFristEnabled()) { logger.debug("setSetFristPattern(String)-start"); logger.debug("Frist!"); logger.debug("setSetFristPattern(String)-end"); }
Admin
function writeString (string) { logString(string); return string; }
function logString(string) { log = log + writeString(string); }
Admin
Infinite-loop warning! Performance may be affected.
Admin
The really sad thing is that all of that logging was even more useless than it already appears. Throw an exception and you bypass the exit messages, meaning that you have an utter nightmare trying to match exit messages with entry messages.
Admin
That has got to be generated code. Nobody would be consistent enough to do something that stupid to every method.
Admin
Instant classic!
Admin
Actually, sadly enough, there are people who are consistent enough to do something that stupid every method. I've seen that, and worse, with my own eyes.
Admin
For folks not familiar with Java logging, like the developer, an interesting feature of logger.debug() is that the implementation first checks to see if isDebugEnabled() returns true. The explicit check for logger.isDebugEnabled() should only be used when you are doing something like:
That pattern avoids the call to reallyComplexMethod() if you don't need it. I've seen a coworker use this kind of pattern in non-generated code. It's obnoxious to read and debug.Admin
Hahaha.
No.
I have hacked on some code that had a several thousand line class that not only contained it's own database abstraction layer and logging functionality, but had "entry" messages for every single method.
And I know for a fact that it wasn't generated code. The person who wrote it wasn't that smart.
Hacking it to use the system logging class, cleaning up the duplicated methods, cutting all the unnecessary messages (like "****** markTrustTransactionPaid() ---- ENTRY ****") and generally spring cleaning the class cut a couple of thousand lines out of it, but it's still more than 2000 lines of code.
And it still makes me shudder.
Admin
His name is not Walter, it is XXXXX and it works with me!
Admin
I've done work for "a large financial transaction company" who insisted on a very similar logging style in their systems.
Every single public method of every class had "Assembly.Class.Method() Entry" and "Exit" logged, along with parameters and return values - in production code.
We tried to protest. We tried to educate. But they were very insistent.
So next time it takes 5 minutes for the ATM to give you cash, you'll know why!
Admin
I have, in fact, been forced to write code similar to this. It was one of the coding standards requirements for this project I once worked on.
I was able to successfully argue that while it sometimes made sense to log entry and exit from functions, it did not make sense to do so on every function, getters and setters included. Once the standards people understood that this wasn't C code, and thus not every function had such a useful purpose, they relented.
Admin
Would this be considered a speed up log?
Admin
Alright, for those accessor methods this is a bit of overkill. On the other hand the way it is implemented here should really not make a noticable performance difference.
What really can cause trouble is when those parameters are not simple Strings but complex objects with complex toString() methods and when the methods are called really often. (like TreeCellRenderer#getTreeCellRendererComponent)
Conclusion: minor WTF, if at all.
Admin
Seems like a fine pattern to follow. Maybe a bit of overkill. Maybe not, depending on requirements. I would turn off debug log messages for production.
Admin
You haven't met many Java developers...
Admin
Admin
This guy built his own profiler. Without all the advantages of an actual profiler, like being able to turn it off.
Admin
It's the disk I/O of all this logging that hits you, not the processing. At some point writing out of logging will start to clog up your I/O channels an hence puts every method invocation in an I/O wait.
Admin
I've got to say this is far better than what the company I currently work for has for logging - which is absolutely none at all (including error logging).
Admin
Definitly not. Of course when debugging is on there must be a performance decrease.
I should have made clear that there should not be a significant performance difference between a method following this pattern and a method not following this pattern. Got it now?
Admin
Logging get/set functions is a bit extreme, but this pattern is hardly a TDWTF. I've personally done this to help solve problems with multi-server IVR software that would allow, for example, conference calling. The 'errors' that would occur wouldn't be simple exceptions, they would be 'people showing up in the wrong conference', so extensive logging of what is going on was about the only way to solve the problem.
Further, if your error is going to cause multiple people to be affected, (or in the case of Anon-y-mouse, multiple people to lose lots of money), it strikes me as a bit irresposible to avoid logging as extensively as possible.
Finally, historical tracability can, at times, require this kind of logging. In production code. No matter how much this might slow down your clever algorhithm.
captcha: minim
The amount you seem to care about solving obscure bugs.
Admin
And yet when logging was turned off they noted a 40% performance increase?
Admin
Why didn't he log halfway?
It's like asking my how far I'm on my way to my parents house and I'm only able to say I've started or ended my journey.
There should be a loop in there in a seperate thread keeping track of the progress of the returned string bit for bit.
ABIGO - When you try to say amigo with a cold.
Admin
This really isn't that bad - it's not the isDebugEnabled() check that'd kill the performance, it's the IO bottleneck in writing all that rubbish to disk, and debug should be off in production anyway.
Really, I'd rather someone over-log, which I rarely see, than under-log, which I see everyday.
Admin
Right, so he overdid it a little? This is the big WTF? A bigger WTF is to have production systems with very little or no logging. You can easily disable logging in production. The WTF is maybe the fact that he didn't have "severity levels" in logging... but again, it's far from being a "classic wtf" as some suggested.
And about the other user comment, that it doesn't help in case of exception.... well, in fact, it does; an exception is not something that typically goes unnoticed in a log. And when you match the "entry" with "exit", you also have a clear picture of how many levels up the exception traveled.
Admin
My bad - communication failure. See here
WTF:
Admin
Number One: despite what the OP implies, this has nothing whatever to do with "architecture." The guy hasn't even built his own logging infrastructure, for chrissake. (And I'm not saying he should...) I normally get hives when I hear the words "Java" and "architecture," but not in this case.
Number Two: All the "industry-standard" logging packages I have seen, in whatever language, are barely fit for purpose. I realise that this is a grandiose claim, but I'm standing by it. They all seem to have inherited the same four brain-deal "levels" from NetView, which was yer standard over-engineered HP product. If they involve an RDBMS at any level, then sayonara, buddie.
Number Three, and this is really quite important, they all apply the same deranged paradigm to the task. The code in the OP is a perfect, if extreme, example. Entry and Exit, hah!
Logging is Comments, except as audit trail after the event rather than verbiage before the compiler. Log messages should almost never be associated with the details of language implementation. Log messages should describe the application domain, not the programming domain.
Sorry for the huge amounts of emphasis, but this stuff is beginning to bug me. I've cowritten a 4000 TPS system, and it was chock full of logging. In useful places. And, filtered for "debug," left fully functional in production.
If even one person takes away the lesson from today that "logging is evil," I will hunt them down and insert knobbly things in each and every orifice.
Admin
Oh help.
This is the application I'm working on right now.
looks suspiciously around at team members
Admin
But it is. Didn't you see that 40% performance hit? =P
Admin
Honestly, it could be worse. Two decades ago, I had a very similar task in C code that was traced to the following macros:
Yes, every function did look like this:
It was written by a contractor.
Though actually I shouldn't say "could be worse" because it was this and crap like it that let me look like the hero by speeding up the app by a couple orders of magnitiude
Admin
You don't "architect" something, you "design" it.
And, yes, I know I'm a grammar nazi.
Admin
Don't worry, all the entries and exits will be carefully logged.
Admin
Yes. Replace reallyComplexMethod() with doVeryImportantBusinessLogicStuff() and have fun "debugging" the application: "but it works on my dev machine..." and "with debug logging it works"
Admin
This is generated by a logging plugin for Eclipse called Log4E. A great plugin with many handy features; of which, can toggle the placement of such "automatic log statements" and can apply them on a project/package level... as well as remove them. A simple two clicker
Admin
Admin
I personally prefer overly verbose logging over speechless systems that don't give you any clue when somethings goes wrong, where it goes wrong.
The only WTF I can see is that verbose logging seems always to be enabled. Log levels are one method for filtering too many log messages (if the compiler was smart, it inlined the log calls anyway), the other method is to use C style #defines/maybe also Java consts to tell the compiler not to include these log messages at all.
I find the 40% increase performance increase hard to believe, because log messages are usually bufferd (not flushed) before they are written to disk in one chunk. Hence the performance toll is not so big or the application was not as slow as the article suggests.
Admin
Admin
What, with all that progress and advances in computers, you're telling me they can't log a string to a file?
Captcha: damnum
Admin
There's not really that much wrong with the logging. Heck, I even wrote a little library that does the entry and exit logging for certain operations (not methods, that's not really that useful) automatically, storing it in a collection from java.util.concurrent and using the thread ID as the key.
Not because I thought it was such a jolly idea, but because the support people very specifically asked for it. They wanted this amount of logging.
Then, when I delivered it, they thought there was perhaps a little too much logging going on, but hey, that's what they asked for.
Admin
Admin
Ah, you're right, this is much better:
And as a bonus, if the Java compiler is anything like the .NET compiler with which I have some familiarity, this will prevent the compiler from performing any optimizations within the try block (which in this instance would be the entire contents of every method).
Admin
Admin
Just allow me to pat my Erlang trace primitives and smile smugly at the Java dweebs, OK?
Admin
That would be good had our equivalent of Walter used it. It wasn't quite as bad as having these on every accessor, but they were on 90% of the methods. Sometimes, the problems with exceptions as was indicated by ptj33 was solved by needless try/finally blocks. Oh and you should have heard the howling when I and the other sane developers began to remove them.
Admin
To keep the matching simple either the code which logs catching the exception has to say how many levels were skipped (doable, but there's no evidence that it was done here), or you need a complex try-catch-finally setup (more complex than bsiegel's, although that's on the right lines: you really want to know whether you exited normally or abnormally).
Besides all that, if you really insist on logging entry and exit to every method in Java then the sensible thing to do is to learn enough Aspect-J to do it all in an aspect without cluttering your main code and creating maintenance consistency nightmares.
AIUI the Java JIT does a lot more than the .NET one. I'm pretty sure it isn't put off by try blocks.PS In constructing and submitted this post I was sent twice to the error page, which mentions that "Not sure what it was, but it was logged." Maybe part of the reason this site is slow to load is that the server's disk is fragmented by 5TB of error logging.
Admin
You never tried this, did you? If the logging is not buffered (or flushed at every record) you have a application that is standing still, not just 40% slowdown.
I would go further, the fact that it slowed the application ONLY 40% shows the application did other I/O intensive work, otherwise it would have been much worse.
Which does not mean logging is bad, just that you should be aware of the performance hit copious logging can bring about. M4
Admin
To be fair, I suppose that "to dictionary" would be a special case. At least, with "to architect," you can be pretty sure that the presumed architect in question has signed off on the plans (never mind all the other things that architects might or might not do ... let's not lose a truly useful verb-o-noun purely on the basis of oversimplification).
I propose that "to dictionary" is far more appropriate when referring to
Bottom line: verbs can traditionally be turned in to nouns with very little loss of information -- in fact, this is precisely the purpose of a gerundive.To turn a noun in to a verb, however, is almost certain to lose information. What, precisely, did Le Corbusier "architect"? And how?
I'm also fascinated by Akimsa's concept of "spam." I wonder whether the word "spam" will get through? Apparently, the First Amendment ain't doing too well in the brave new world of the Internet...
Admin
The basic idea makes sense, and depending on how you configured the logging, this style could have had no I/O bottleneck at all; you can send it to an in-memory buffer and then flush hundreds of events at a time to syslog, and have that deal with it.
The real WTF is that Log4E was set up to generate logging on getter / setters, and the system was configured with the logging level turned up to DEBUG in production.
Admin
Maybe auto tunnels need to make sure that every person that enters, leaves. Logging is good, logging is bad, yadda yadda. Excessive logging tells me that the code is not trusted. The people that do this will go on chapter and verse on how great their language of choice is.