groovy

Bug in groovy.util.GroovyScriptEngine isSourceNewer() results in gratuitous recompilations and lost of static state in groovlets

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 1.7.5
  • Fix Version/s: 1.7.6, 1.8-beta-3
  • Component/s: Groovlet / GSP
  • Labels:
    None
  • Environment:
    Bug is independent of OS and JVM. I'm running Ubuntu 10.10 with OpenJDK 1.6.0_18.
  • Number of attachments :
    4

Description

isSourceNewer() method in groovy.util.GroovyScriptEngine does evaluate script sources for recompilation (it will return true) in cases where 'nextPossibleRecompilationTime >= lastMod'. This is wrong and results in gratuitous recompilations of scripts.

An ugly side effect of this bug is, that groovlet state (static objects kept in a static class) is being lost between incoming requests, due to gratuitous recompilation and subsequent restart of groovlets.

The attached patch fixes the issue.

  1. patchfile.txt
    28/Oct/10 7:33 AM
    0.5 kB
    Timur Mehrvarz
  2. patchfile2.txt
    28/Oct/10 3:54 PM
    0.6 kB
    Timur Mehrvarz
  3. patchfile3.txt
    28/Oct/10 6:50 PM
    0.6 kB
    Timur Mehrvarz
  4. patchfile-all3.txt
    28/Oct/10 6:50 PM
    0.9 kB
    Timur Mehrvarz

Activity

Hide
Guillaume Laforge added a comment -

Running the two related GroovyScriptEngine (GSE for short) tests make one fail.
You can try running them with

ant -DtestCase=groovy.util.GroovyScriptEngineTest test
ant -DtestCase=groovy.util.GroovyScriptEngineReloadingTest test

That's GroovyScriptEngineTest which is failing here with your patch.
Any idea why the test is failing?

[junit] Testcase: testReloadingInterval(groovy.util.GroovyScriptEngineTest):	FAILED
    [junit] assert gse.run(scriptName, binding) == 12
    [junit]        |   |   |           |        |
    [junit]        |   1   |           |        false
    [junit]        |       |           groovy.lang.Binding@23b17d49
    [junit]        |       gse4241425475617288650.groovy
    [junit]        groovy.util.GroovyScriptEngine@599855ed
    [junit] junit.framework.AssertionFailedError: assert gse.run(scriptName, binding) == 12
    [junit]        |   |   |           |        |
    [junit]        |   1   |           |        false
    [junit]        |       |           groovy.lang.Binding@23b17d49
    [junit]        |       gse4241425475617288650.groovy
    [junit]        groovy.util.GroovyScriptEngine@599855ed
    [junit] 	at org.codehaus.groovy.runtime.InvokerHelper.assertFailed(InvokerHelper.java:386)
    [junit] 	at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.assertFailed(ScriptBytecodeAdapter.java:658)
    [junit] 	at groovy.util.GroovyScriptEngineTest.testReloadingInterval(GroovyScriptEngineTest.groovy:245)
    [junit]

Perhaps in some cases the logic was reloading the class too often... but in this case, the reloading should have happened, but has not with the patch applied.

Show
Guillaume Laforge added a comment - Running the two related GroovyScriptEngine (GSE for short) tests make one fail. You can try running them with
ant -DtestCase=groovy.util.GroovyScriptEngineTest test
ant -DtestCase=groovy.util.GroovyScriptEngineReloadingTest test
That's GroovyScriptEngineTest which is failing here with your patch. Any idea why the test is failing?
[junit] Testcase: testReloadingInterval(groovy.util.GroovyScriptEngineTest):	FAILED
    [junit] assert gse.run(scriptName, binding) == 12
    [junit]        |   |   |           |        |
    [junit]        |   1   |           |        false
    [junit]        |       |           groovy.lang.Binding@23b17d49
    [junit]        |       gse4241425475617288650.groovy
    [junit]        groovy.util.GroovyScriptEngine@599855ed
    [junit] junit.framework.AssertionFailedError: assert gse.run(scriptName, binding) == 12
    [junit]        |   |   |           |        |
    [junit]        |   1   |           |        false
    [junit]        |       |           groovy.lang.Binding@23b17d49
    [junit]        |       gse4241425475617288650.groovy
    [junit]        groovy.util.GroovyScriptEngine@599855ed
    [junit] 	at org.codehaus.groovy.runtime.InvokerHelper.assertFailed(InvokerHelper.java:386)
    [junit] 	at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.assertFailed(ScriptBytecodeAdapter.java:658)
    [junit] 	at groovy.util.GroovyScriptEngineTest.testReloadingInterval(GroovyScriptEngineTest.groovy:245)
    [junit]
Perhaps in some cases the logic was reloading the class too often... but in this case, the reloading should have happened, but has not with the patch applied.
Hide
Timur Mehrvarz added a comment -

Well well well.. this is a completely different bug. The issue here is that URLConnection.getLastModified() truncates up to 999 ms from the time value when the file was originally modified. This is how it works:

Date.parse(getHeaderField("last-modified"));

In other words: getLastModified() works based on seconds, not ms.

What the test case is falling over: Because of the issue with getLastModified(), the value of lastMod may appear up to 999 ms OLDER than it really is. And so, it may look as if nextPossibleRecompilationTime is not yet due. While in reallity it is!

To fix this, I propose to adjust the value of lastMod in the following way:

lastMod = ((lastMod /1000)+1)*1000-1;

I'm attaching a 2nd patch relative to my other patch.

Show
Timur Mehrvarz added a comment - Well well well.. this is a completely different bug. The issue here is that URLConnection.getLastModified() truncates up to 999 ms from the time value when the file was originally modified. This is how it works: Date.parse(getHeaderField("last-modified")); In other words: getLastModified() works based on seconds, not ms. What the test case is falling over: Because of the issue with getLastModified(), the value of lastMod may appear up to 999 ms OLDER than it really is. And so, it may look as if nextPossibleRecompilationTime is not yet due. While in reallity it is! To fix this, I propose to adjust the value of lastMod in the following way: lastMod = ((lastMod /1000)+1)*1000-1; I'm attaching a 2nd patch relative to my other patch.
Hide
Timur Mehrvarz added a comment -

You will notice that there is still an issue with the code. This is really a separate problem, that is preventing patchfile1 + patchfile2 from working in some cases.

This remaining 3rd issue is that we want to accept re-compilation of a script only

if(depEntry.lastModified < lastMod)

(that is: if the cached version is older than the script in the filesystem)

and not

if(nextPossibleRecompilationTime < lastMod)

I am attaching patchfile3.txt to solve this. I'm also attaching a combined patchfile-all3.txt.
Thank you.

Show
Timur Mehrvarz added a comment - You will notice that there is still an issue with the code. This is really a separate problem, that is preventing patchfile1 + patchfile2 from working in some cases. This remaining 3rd issue is that we want to accept re-compilation of a script only if(depEntry.lastModified < lastMod) (that is: if the cached version is older than the script in the filesystem) and not if(nextPossibleRecompilationTime < lastMod) I am attaching patchfile3.txt to solve this. I'm also attaching a combined patchfile-all3.txt. Thank you.
Hide
Guillaume Laforge added a comment -

Well spotted for the last modified stuff! I've spent a moment on the logic of this method, but never really thought about how the last modification was really computed, which makes the granularity up to a second. Interesting.
The "all" patch works fine for me, thanks a lot.

Show
Guillaume Laforge added a comment - Well spotted for the last modified stuff! I've spent a moment on the logic of this method, but never really thought about how the last modification was really computed, which makes the granularity up to a second. Interesting. The "all" patch works fine for me, thanks a lot.

People

Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved: