Saturday, August 15, 2009

Are Groovy Stacktraces a Showstopper?

I've been part of an interesting debate on the merits of Groovy via Twitter this week. I'm reproducing it here because I think it's an interesting take on what potential users feel are make or break issues for a language, and to give others who may not have seen it the chance to weigh in without the 140 character limit. :)

(Sorry in advance. Reproducing a Twitter convo in a blog is kind of hideous)

[@philswenson] if you want to know why groovy sucks, click here: http://pastie.org/583115
[@joshareed] @philswenson It took me a second to diagnose your problem. Did you want Groovy to say: "Hey joker, actually import the classes you're using"
[@joshareed] @philswenson Apparently Ruby has some magical mind-reading interpreter/compiler that saves you from yourself?

[@philswenson] @joshareed why the extra 500 lines of crap? in java or jruby that stacktrace would have been 1/50 the size. that's my point
[@joshareed] @philswenson re: Java guess that's the trade off for Groovy dynamics. Ruby's (http://bit.ly/IagLJ) is not any better [Note: Nambu mangled the original link]

[@philswenson] @joshareed Ruby's stack dump = 67 lines. Groovy's = 222 lines. Not as different as I said, but still...
[@joshareed] @philswenson # of lines doesn't matter when you see the cause of the prob in the first 10 lines, does it? You don't have to keep reading...
[@joshareed] @philswenson and was the 67 vs 222 equivalent programs in each? I'd be interested in comparing the source of each

[@philswenson] @joshareed this was a case where the cause was obvious (it usually isn't). isn't groovy in large part about succinctness over java?
[@joshareed] @philswenson how much time do you spend looking at stacktraces that this is hang up for you? Write a 3 line .findAll{} to filter traces
[@joshareed] @philswenson and if you want to stick with stacktrace length as your argument then you won't be plain old Java traces with JRuby

From my perspective, this isn't a JRuby vs Groovy debate even though both languages were brought up in the conversation. Both are two different ways to skin a cat but they ultimately get you to the same place. Which you choose to use is more a matter of personal preference than the actual merits of the language.

What I'm more interested in is how important/serious is the stacktrace issue that Phil Swenson argues? I've been writing Groovy for a couple years now and can't remember (off the top of my head) a stacktrace from Groovy that was so confusing I couldn't figure out the problem. I'm sure there are some, especially when you start getting deep into the Groovy innards, but I'm guessing that's also the case with other languages on the JVM, like JRuby.

All dynamic languages built on the JVM introduce a certain level of indirection (by necessity), so are Groovy's stacktraces that much more hideous than JRuby's? What qualifies as hideous? I think length is a naive measure because the cause of the problem is likely to show up in the first dozen lines. Who cares if it goes on for another 200 lines? Length is also easily manipulated. You could write a simple findAll closure that sanitizes the stacktrace by removing all the lines that start with 'sun.reflect' or 'org.codehaus.groovy.runtime'. I have never once run into a problem that could be tracked to one of those lines in the stacktrace. So now does that make Groovy better than JRuby because the stacktrace is shorter?

I'm sure this is just a case of me being used to seeing Groovy stacktraces, so I'm used to feel of them and can quickly hone in on the cause of the problem. Likewise I'm sure Phil is used to [J]Ruby errors which probably look much different than Groovy's. I say probably because the two example put forth didn't look all that dissimilar IMO but were not from the same problem so it was an apples to oranges comparison.

Anyways, how important are stacktraces when making the decision to use a particular language? Are they important enough to declare one language's superiority over another? Are they worth focusing on to improve Groovy's ease-of-use?

22 comments:

Robert Fischer said...

I'm downright embarrassed by Groovy's stack traces, and they are pretty annoying to scroll back up through. The signal-to-noise ratio is really, really low.

The Groovy impl based on invoke_dynamic will wipe out a lot of these extra stack trace frames. But that's Groovy 2 (if not later): JDK7 has to come out and be popularized.

Hamlet D'Arcy said...

The Groovy Development Team seems to believe that cleaning stack traces should be the job of tools. For instance, GroovyConsole cleans the traces, IDEA provides some filtering, and Spock provides some very useful filtering. There are methods in the GDK to clean the traces. I'm paraphrasing the mailing list here and quoting no one in particular, but the sentiment is that the language should not decide for you which information is useful and which isn't; that is the job of your tools. Writing a Grails plugin the cleans stack traces should be pretty easy (IDK for sure), as well as any other tools.

But I agree that they are horrible. It's part of the learning curve that I'm over.

Berkay said...

They are horrible from operations/support perspective. It fills the logs with loads of garbage, makes it very difficult to find what's going on.

Anonymous said...

A little interesting to get the hang of yes, but I wouldn't call them an embarrassment or horrible. Stop reading once you see it start to be MOP stuff.

Ted Naleid said...

I can see why people have a problem with them, but they never really bugged me. Grep for your package name and you've pretty much got a 5-10 line stack trace that's your answer almost all of the time.

I agree with the groovy devs that tool support is the right place to deal with this.

I do think that more work could be done by the tool devs, or maybe it'd be nice to have some sort of command line flag (-Dsimple.stacktrace=true) that filters things down for you. Might not be all that hard to implement with AST transformations.

I like seeing all the detail as it gives me a better peek into what's going on under the covers.

Robert Fischer said...

@Hamlet

I'll buy that it's the job of the tools. I'll even grant that it's occasionally useful to see where things blew up in Groovy. But if the language designers are going to push it off onto the tools, they need to at least provide a useful API to do it (something like GrailsUtil.deepSanitize).

The ability to expand that list would be nifty: app servers, frameworks, etc., all add stack frames on that don't really need to be there.

@Berkay

I don't buy the ops argument. If you're looking at the raw logs from production, you're doing it wrong. Feed it through a quickie perl script (or grep -v) to filter that stuff out. You probably need to be doing that in ops logs anyway: there's all kinds of noise in your average ops log.

matt said...

Yes they are annoying, but I don't think they are a showstopper.

Jochen and the like are correct, eclipse and other tools should have a log filter that filters by package. Really, the problem goes to the root of how exceptions are reported by the JVM in the first place, and it has no way of package filtering the report.

I don't think the Groovy team can be expected to alter that :D However providing an addition to the GREclipse plugin and others would be most welcome.

Anonymous said...

I agree that it should be a command line switch or something along those lines. Then, I'd give it one revision before having it set became the default...

Scott Hickey said...

From experience developing and deploying applications into production, I can attest that Groovy stacktraces are not a showstopper.

phil swenson said...

Note: I shouldn't have said "groovy sucks." I should have said "this sucks about groovy."

Also note that that stacktrace I posted was using the groovy exception sanitizer utility and it still looked like that:
"}catch(Exception e){
throw StackTraceUtils.sanitize(e)
}"

I think that the groovy team doesn't want to fix it because there would be a large perf hit to resolve it. So what they should do is get a sanitizer that WORKS and add a method to Exception. So when the exception is to be presented to the user, just do a logger.excetion(groovyexception.sanitize()) or something similar.

phil swenson said...

yeah, horrid stack-traces are not a show-stopper. but it's one of many irritating issues about groovy that has pushed me to using JRuby for my current project.

Josh Reed said...

I'll preface this by saying that I'm pretty ignorant when it comes to JRuby. So if I'm off base, then please correct me.

It seems to me that the stack trace issue really stems from the fact that in Groovy you're always in 'Java integration' mode whereas in JRuby you are not. I can't imagine the JRuby guys have found some significantly better solution (with respect to the stack traces generated when calling Java libraries) that the Groovy team hasn't considered/borrowed.

With that concession, I guess I would expect JRuby stack traces to be more to the point because they aren't doing all of the reflection jazz behind the scenes to make sure everything places nice from the Java side. When you start crossing that Ruby/Java boundary, I would guess that the stack traces become increasingly more hideous (unless they are sanitizing by default)

Roshan Shrestha said...

You only have to look at many of the entries in Nabble to wish that either 1) Groovy produced a lean stack trace, or 2) the user would only copy the relevant portion of the stack trace.

geo said...

They're one of the reasons a console debugger, like pdb, would be very useful in Groovy.

Artur said...

What I don't like is the mindset "It is groovy, so whatever it outputs has to be great". What about agreeing that it would be great to see 'native' groovy stacktraces, but is is currently not possible or very hard to achieve that? And maybe looking for a usable solution, rather than requiring everybody to write filter scripts or wade through hundreds of lines of noise.

I wonder if it would be possible to have some optional hack in groovy, which would cause exceptions to be recreated with reflection-injected StackTraceElement[] stackTrace field, which would contain groovy level info. It would have to be optional, because some people (especially groovy developers) would still prefer to see original stack traces.

Josh Reed said...

@Artur

I don't think there's anyone here that's said that the stack traces are great. Most of the responses come down to: 'they suck' or 'meh, don't care'

What do you mean by 'native' stack traces? Cleaned up so there is less noise? If that's the case, I think Ted offered up the best compromise--a command line flag to choose between full traces and simplified ones.

I did a quick google after Phil mentioned it and found: http://groovy.codehaus.org/api/org/codehaus/groovy/runtime/StackTraceUtils.html

I haven't had a chance to see how much it cleans up the stack traces. From Phil's comment, it sounds like it might need some additional configuration to really get rid of the cruft.

Anonymous said...

First. Welcome to the JVM.

Now if you want succinct stacktraces in any java environment, set up your freaking lo4gj appenders right.

All you need is add your root package. I'm guessing: 'test.framework'

Hamlet D'Arcy said...

@Anonymous yeah, no sh*t. yours is the best comment here. totally agree.

Charles Oliver Nutter said...

JRuby's stack traces are short because they're Ruby traces, not JVM traces. Groovy has no "Groovy traces".

Groovy's traces are also long because Groovy has a *lot* more work happening between calls than JRuby does for most things. For Ruby-to-Ruby calls, JRuby will only have 2-4 intermediate frames in the trace, where Groovy will have 10-20 intermediate frames. JRuby does not use reflection for any core classes, which shortens things further. And when calling out to Java, the trace only grows by the size of reflection logic.

We've done a lot to make sure stack traces are tight and clean in JRuby. I think "tight and clean" should be the default, not forcing users to use the right tool or configure a logging framework. That's asinine.

Scott Hickey said...

re Charles Nutter's trolling comment "asinine":

The Groovy stacktraces might not be perfect but no one is "forcing users to use the right tool or configure a logging framework" to be productive.

My project team for three years consisted of VB/Cobol turned Java newbies and Excel/Foxpro programmers. Somehow, they managed to be incredibly successful using Groovy and had managed to find the first line in the stack trace that pointed to a Groovy file with little trouble.

If they could handle it, I would thing professional Java programmers can manage without any tools or cleanup.

Would some options for more/less verbosity been useful? Sure. But it needs to be put into perspective. Once your using Groovy on a project, its just not that big of a deal or to the point of the blog: Its just not a showstopper.

Charles Oliver Nutter said...

Scott: Default behavior should be the behavior most people want. In this case, I think most people want only the relevant information in the stack trace. So the default should be to only show the relevant information in the stack trace.

I never said anything about productivity. Just about expecting people to make configuration changes to shorten/clean stack traces down to what most people actually want. If most people want them to be cleaner/shorter, make them cleaner/shorter by default.

tomCorbin said...

The example code about the sanitizer used StackTraceUtils.sanitize. I use "deepSanitize" does that make a difference?

I've found that deepSanitize generally gives me fairly good stack traces, except for postgres stuff in there.

Of course, it's a pain to use that, but I do'nt find it too terribly bad.