Issue Details (XML | Word | Printable)

Key: GROOVY-1744
Type: Bug Bug
Status: Closed Closed
Resolution: Won't Fix
Priority: Critical Critical
Assignee: Jochen Theodorou
Reporter: Mikko Halttunen
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
groovy

Extreme performance problem when calling closures using 'shorthand' notation

Created: 23/Feb/07 07:54 AM   Updated: 11/Oct/07 08:25 PM   Resolved: 11/Oct/07 08:25 PM
Return to search
Component/s: None
Affects Version/s: 1.0
Fix Version/s: 1.1-rc-1

Time Tracking:
Not Specified

Environment:
Linux: blackdown-j2sdk1.4.2_03 and sun's jdk1.5.0_09
Windows XP Pro: jdk1.5.0_10


 Description  « Hide

When I define a closure and store it to a variable, according to groovy's documentation I can use two ways of calling that closure: closure.call(args) or closure(args). There is a great performance difference between these calls though. The difference consists of:

2 calls to new MissingPropertyException
2 calls to new MissingMethodException
2 calls to InvokeHelper.format(Object arguments, boolean verbose)
12 calls to arg.replaceAll (InvokeHelper:line 600)

One problem is the arg.replaceAll in InvokeHelper.format. Formatting the exceptions that are catched inside groovy is totally useless and causes extremely big performance loss. Removing calls to InvokerHelper improves performance a lot. Below an example of the two cases and how they work in different versions of groovy:

test.groovy:
------------------------------------
closure = { number ->
test = number + 1;
}

start = java.lang.System.currentTimeMillis()
for (i in 0..100000) {
closure(1)
}
end = java.lang.System.currentTimeMillis()
test1 = end - start

start = java.lang.System.currentTimeMillis()
for (i in 0..100000) {
closure.call(1)
}
end = java.lang.System.currentTimeMillis()
test2 = end - start

println "test1: $test1"
println "test2: $test2"
--------------------------------------

tested with: blackdown-j2sdk1.4.2_03 and sun's jdk1.5.0_09

groovy-1.0-jsr-04/bin/groovy test.groovy
test1: 573
test2: 541

groovy-1.0-jsr-06/bin/groovy test.groovy
test1: 30370
test2: 654

groovy-1.0/bin/groovy test.groovy
test1: 8455
test2: 615

groovy-1.0-modified/bin/groovy test.groovy
test1: 7653
test2: 620

groovy-1.0-modified is the same as 1.0, but MissingMethodException's call to InvokerHelper's methods were removed.



Jochen Theodorou added a comment - 11/Oct/07 08:25 PM

this is not really an error, the problem is more related to the inlining the VM does., because the short hand form uses a different path for the method call it takes more iterations until it is inlined. How many of these iteration are needed depends on the VM. Anyway, I was able to reproduce your results and the difference got away after giving each test a warmup phase consisting of calling the test code for the test (there are two tests, one for closure(1) and one for closure.call(1)) before getting the time.


Jochen Theodorou made changes - 11/Oct/07 08:25 PM
Field Original Value New Value
Status Open [ 1 ] Closed [ 6 ]
Assignee Jochen Theodorou [ blackdrag ]
Fix Version/s 1.1-rc-1 [ 13165 ]
Resolution Won't Fix [ 2 ]