You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@commons.apache.org by "Dmitri Blinov (JIRA)" <ji...@apache.org> on 2016/07/12 13:32:20 UTC

[jira] [Updated] (JEXL-206) testCallableCancel() test hangs sporadically

     [ https://issues.apache.org/jira/browse/JEXL-206?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Dmitri Blinov updated JEXL-206:
-------------------------------
    Description: 
I'm struggling with strange behaviour of the building process, it seems that time after time the process hangs somewhere in the middle of the tests stage. First I thought it was somehow related to memory problems so I changed fork mode of the test plugin by adding                     <forkMode>pertest</forkMode> to maven-surefire-plugin configuration. But that helped for a couple of times to cleanly build jexl and run all tests successfully. The other times it simply hanged on test stage. I have managed to detect that it is the testCallableCancel() test that hangs. One of its worker threads has a stack trace as follows:

{code}
org.apache.commons.jexl3.internal.Interpreter.visit(Interpreter.java:893)
org.apache.commons.jexl3.parser.ASTWhileStatement.jjtAccept(ASTWhileStatement.java:18)
org.apache.commons.jexl3.internal.Interpreter.visit(Interpreter.java:1119)
org.apache.commons.jexl3.parser.ASTJexlScript.jjtAccept(ASTJexlScript.java:55)
org.apache.commons.jexl3.internal.Interpreter.interpret(Interpreter.java:210)
org.apache.commons.jexl3.internal.Script$Callable.interpret(Script.java:364)
org.apache.commons.jexl3.internal.Script$Callable.call(Script.java:372)
   - locked org.apache.commons.jexl3.internal.Script$Callable@18399f62
java.util.concurrent.FutureTask.run(FutureTask.java:262)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:745)
{code}

I have adjusted the test code with prinln() to dig further what is going on:

{code}
    @Test
    public void testCallableCancel() throws Exception {

        System.out.println("testCallableCancel(): started");

        JexlScript e = JEXL.createScript("while(true);");
        final Script.Callable c = (Script.Callable) e.callable(null);
        Object t = 42;
        Callable<Object> kc = new Callable<Object>() {
            @Override
            public Object call() throws Exception {
                System.out.println("testCallableCancel(): cancel() is called");
                return c.cancel();
            }

        };

        Callable<Object> xkc = new Callable<Object>() {
            @Override
            public Object call() throws Exception {
                System.out.println("testCallableCancel(): run() is called");
                return c.call();
            }

        };

        ExecutorService executor = Executors.newFixedThreadPool(2);
        Future<?> future = executor.submit(xkc);
        Future<?> kfc = executor.submit(kc);
        try {
            Assert.assertTrue((Boolean) kfc.get());

            System.out.println("testCallableCancel(): canceled()");

            t = future.get();
            Assert.fail("should have been cancelled");
        } catch (ExecutionException xexec) {
            // ok, ignore
            Assert.assertTrue(xexec.getCause() instanceof JexlException.Cancel);
        } finally {
            executor.shutdown();
        }
        Assert.assertTrue(c.isCancelled());

        System.out.println("testCallableCancel(): finished");
    }
{code}

If the test hangs it prints the following:
{panel}
testCallableCancel(): started
testCallableCancel(): run() is called
testCallableCancel(): cancel() is called
testCallableCancel(): canceled()
{panel}

If the test runs as normal and does not hang it prints the following:
{panel}
testCallableCancel(): started
testCallableCancel(): run() is called
testCallableCancel(): cancel() is called
testCallableCancel(): canceled()
testCallableCancel(): finished
{panel}

  was:
I'm struggling with strange behaviour of the building process, it seems that time after time the process hangs somewhere in the middle of the tests stage. First I thought it was somehow related to memory problems so I changed fork mode of the test plugin by adding                     <forkMode>pertest</forkMode> to maven-surefire-plugin configuration. But that helped for a couple of times to cleanly build jexl and run all tests successfully. The other times it simply hanged on test stage. I have managed to detect that it is the testCancelLoopWait() test that hangs. It writes to the console the message 
{panel}
WARNING: org.apache.commons.jexl3.ScriptCallableTest.testCancelLoopWait@1:20 execution cancelled
{panel}

 and hangs with its stack trace as follows:

{code}
org.apache.commons.jexl3.internal.Interpreter.visit(Interpreter.java:893)
org.apache.commons.jexl3.parser.ASTWhileStatement.jjtAccept(ASTWhileStatement.java:18)
org.apache.commons.jexl3.internal.Interpreter.visit(Interpreter.java:1119)
org.apache.commons.jexl3.parser.ASTJexlScript.jjtAccept(ASTJexlScript.java:55)
org.apache.commons.jexl3.internal.Interpreter.interpret(Interpreter.java:210)
org.apache.commons.jexl3.internal.Script$Callable.interpret(Script.java:364)
org.apache.commons.jexl3.internal.Script$Callable.call(Script.java:372)
   - locked org.apache.commons.jexl3.internal.Script$Callable@18399f62
java.util.concurrent.FutureTask.run(FutureTask.java:262)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:745)
{code}

The problem started manifesting itself right after I had added ScriptInterruptableTest.java (see JEXL-204) but as I understand this test script is completely unrelated to ScriptCallableTest.java so I think it's  merely a conicidence. I could not write anything in ScriptInterruptableTest and screw up ScriptCallableTest, right?

PS. I have managed to catch this exactly behavior after removing ScriptInterruptableTest.java completely and making clean build, so I'm 100% sure there is something wrong with the original code, may be race condition or something. 

If the test runs as normal and does not hang it prints the following:
{panel}
WARNING: org.apache.commons.jexl3.ScriptCallableTest.testCancelLoopWait@1:20 execution cancelled
...12, 2016 3:31:50 PM org.apache.commons.jexl3.JexlEngine invocationFailed
{panel}

        Summary: testCallableCancel() test hangs sporadically  (was: testCancelLoopWait() test hangs sporadically?)

Sorry for previous misinformation about testCancelLoopWait(), it turned out that was not testCancelLoopWait() that hanged but the one that was run after it.

> testCallableCancel() test hangs sporadically
> --------------------------------------------
>
>                 Key: JEXL-206
>                 URL: https://issues.apache.org/jira/browse/JEXL-206
>             Project: Commons JEXL
>          Issue Type: Bug
>    Affects Versions: 3.0
>            Reporter: Dmitri Blinov
>
> I'm struggling with strange behaviour of the building process, it seems that time after time the process hangs somewhere in the middle of the tests stage. First I thought it was somehow related to memory problems so I changed fork mode of the test plugin by adding                     <forkMode>pertest</forkMode> to maven-surefire-plugin configuration. But that helped for a couple of times to cleanly build jexl and run all tests successfully. The other times it simply hanged on test stage. I have managed to detect that it is the testCallableCancel() test that hangs. One of its worker threads has a stack trace as follows:
> {code}
> org.apache.commons.jexl3.internal.Interpreter.visit(Interpreter.java:893)
> org.apache.commons.jexl3.parser.ASTWhileStatement.jjtAccept(ASTWhileStatement.java:18)
> org.apache.commons.jexl3.internal.Interpreter.visit(Interpreter.java:1119)
> org.apache.commons.jexl3.parser.ASTJexlScript.jjtAccept(ASTJexlScript.java:55)
> org.apache.commons.jexl3.internal.Interpreter.interpret(Interpreter.java:210)
> org.apache.commons.jexl3.internal.Script$Callable.interpret(Script.java:364)
> org.apache.commons.jexl3.internal.Script$Callable.call(Script.java:372)
>    - locked org.apache.commons.jexl3.internal.Script$Callable@18399f62
> java.util.concurrent.FutureTask.run(FutureTask.java:262)
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> java.lang.Thread.run(Thread.java:745)
> {code}
> I have adjusted the test code with prinln() to dig further what is going on:
> {code}
>     @Test
>     public void testCallableCancel() throws Exception {
>         System.out.println("testCallableCancel(): started");
>         JexlScript e = JEXL.createScript("while(true);");
>         final Script.Callable c = (Script.Callable) e.callable(null);
>         Object t = 42;
>         Callable<Object> kc = new Callable<Object>() {
>             @Override
>             public Object call() throws Exception {
>                 System.out.println("testCallableCancel(): cancel() is called");
>                 return c.cancel();
>             }
>         };
>         Callable<Object> xkc = new Callable<Object>() {
>             @Override
>             public Object call() throws Exception {
>                 System.out.println("testCallableCancel(): run() is called");
>                 return c.call();
>             }
>         };
>         ExecutorService executor = Executors.newFixedThreadPool(2);
>         Future<?> future = executor.submit(xkc);
>         Future<?> kfc = executor.submit(kc);
>         try {
>             Assert.assertTrue((Boolean) kfc.get());
>             System.out.println("testCallableCancel(): canceled()");
>             t = future.get();
>             Assert.fail("should have been cancelled");
>         } catch (ExecutionException xexec) {
>             // ok, ignore
>             Assert.assertTrue(xexec.getCause() instanceof JexlException.Cancel);
>         } finally {
>             executor.shutdown();
>         }
>         Assert.assertTrue(c.isCancelled());
>         System.out.println("testCallableCancel(): finished");
>     }
> {code}
> If the test hangs it prints the following:
> {panel}
> testCallableCancel(): started
> testCallableCancel(): run() is called
> testCallableCancel(): cancel() is called
> testCallableCancel(): canceled()
> {panel}
> If the test runs as normal and does not hang it prints the following:
> {panel}
> testCallableCancel(): started
> testCallableCancel(): run() is called
> testCallableCancel(): cancel() is called
> testCallableCancel(): canceled()
> testCallableCancel(): finished
> {panel}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)