java.lang.UnsupportedOperationException while Lucee is trying to stop a thread

[Jan Jannek]

Hi everyone,

I am having problems with threads in Lucee.

The following exception occurs and is displayed - but on the Console only.

Exception in thread "Thread-72" java.lang.UnsupportedOperationException

at java.lang.Thread.stop(Thread.java:869)

at lucee.commons.io.StopThread.run(SystemUtil.java:1058)

(The "Thread-72" can contain any number, depending on the thread name. It's not always "72".)

There is no exception in the exception.log or any other log file.

SystemUtil.java uses the deprecated stop method of java.lang.Thread (according to the javadocs of java 7 and 8). I don't know if this has anything to do with it but could be.

Environment

• OS X 10.10
  
• Java 1.8 64 bit
  
• Lucee 4.5.1.008 Express on Jetty
  
• using the Java Concurreny Framework via cfconcurrent (https://github.com/marcesher/cfconcurrent)

I don't know exactly what causes Lucee to try to stop the thread. Are threads subject to the request timeout setting in the Lucee Admin?

Is the max concurrent threads setting in the Lucee Admin only related to cfthread or could this be problematic in my case as well?

Any help or hint is appreciated.

Best regards,

Jan

[Michael Offner]

This happens with java8 (openjdk) whe a request timeout happens, we already did a quick fix for this 

https://bitbucket.org/lucee/lucee/issue/277/request-timeout-fails-with-java8

And we plan to do a release that includes that fix next week.

Best run Lucee 4.5 on Java 7

Micha

--
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/eaf72cd9-7f98-43d1-92be-ed6e60890204%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Jan Jannek]

Hi Micha,

thank you very much for the quick response.

However one question remains:

Why does a request timeout happen at all in this case?

I am using a ScheduledThreadPoolExecutor (http://docs.oracle.com/javase/7/docs/api/java/util/concurrent/ScheduledThreadPoolExecutor.html) which runs recurring tasks in separate Java Threads (forever, as long as the application is alive). Each task run only takes a couple of seconds.

Is the whole scheduled execution subject to the request timeout? Would it be required to set the request timeout to 0 in the Lucee admin to make it work (that would be odd as it affects all requests).

I create and start the scheduled thread pool executor in onApplicationStart in the Application.cfc and store it in the application scope. Would it be possible to set the request timeout using cfsetting *within* onApplicationStart (which is kind of strange).

To reproduce the problem just try out the ScheduledExecutor example that ships with the cfconcurrent framework (https://github.com/marcesher/cfconcurrent). There the errors/requesttimeouts also occur.

Any further ideas or suggestions are appreciated.

Jan

[Michael Offner]

it is hard to say why it is happening, the only thing i can read from your exception is that Lucee was trying to stop a thread and was failing, after that fix we should have more details in the log to see what is exactly happening.

Micha

--

You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/3dfa8d52-9417-4dad-b1a5-8ab9389482e4%40googlegroups.com.

[Jan Jannek]

Using JDK 7 the following errors occur:

Console:

Exception in thread "pool-3-thread-1" java.lang.IllegalMonitorStateException

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1941)

at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1100)

at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:745)

Exception in thread "pool-1-thread-7" java.lang.IllegalMonitorStateException

at java.util.concurrent.locks.ReentrantLock$Sync.tryRelease(ReentrantLock.java:155)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1260)

at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:460)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:449)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:745)

and so on (multiple times, recurring every few seconds)

requesttimeout.log

"ERROR","Thread-18","04/15/2015","11:54:34","controler","stop thread (37) because run into a timeout (fail to retrieve path:java.lang.NullPointerException:null).;java.lang.Throwable;java.lang.Throwable

at sun.misc.Unsafe.park(Native Method)

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2090)

at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)

at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:745)

"

I hope this helps.

Jan

[Jan Jannek]

Some further experiments and how to reproduce the problem.

1. Startup Lucee
2. Click the link beneath "Submit a task" in the first cfconcurrent example (Executor Service)
3. wait a bit (I used a stopwatch and it was approx. the request timeout set in the lucee admin)
4. have a look at the console and the requesttimeout.log

(all other cfconcurrent examples behave equally)

I tried both JDK 7 and JDK 8. I also applied the BE patch release 4.5.1.011.

It looks to me as if the request timeout set in the lucee admin is applied on the thread, even if the initial request ends normally after a couple of seconds. Weird is that even the executed task in the separate thread is only a couple of milliseconds.

just for information:

I was unsure of whether this is a cfconcurrent or a lucee problem so I created an issue on the cfconcurrent github page. Here is the link for cross-reference: https://github.com/marcesher/cfconcurrent/issues/3

Right now I believe that it's a Lucee issue - or is this intended behavior?

[Jan Jannek]

One thing that I forgot to mention:

Almost the same experience using Railo Express 4.2.1.008, except that the errors do not show up on the Console, they only are written to the requesttimeout.log.

[Simon Goldschmidt]

Has this issue been addressed for CFFTP and CFTHREAD in Lucee 4.5.1.023?

If you FTP a server that is offline, the timeout doesn't work. This:

  <cfsetting requesttimeout="10">

  <cfftp connection="test" action="open" server="1.2.3.4" username="test" password="test" timeout="5">

experiences the 10sec page timeout rather than the 5sec FTP timeout.

If you do this within a CFTHREAD, you see errors in the requesttimeout.log like "Thread.stop(Throwable) is not supported by this JVM and failed with UnsupportedOperationException" and "could not stop the thread on the first approach" and it has other nasty impacts like killing the task that sends emails.

Simon

[Daan de Wit]

Problems like this are actually the reason why Thread.stop() has been deprecated years ago, and apparently causes errors now when used in OpenJDK 8. 

We are currently trying to run CFML-code from Java, that also causes this IllegalMonitorStateException, but it also seems to randomly hang Tomcat.

Why doesn't Lucee call Thread.interrupt() to stop the threads? I understand some external code (library / CFML) might catch the interrupted-exception, but when CFML code catches it, Lucee can detect that (using Thread.isInterrupted, or in the implementation of cfcatch, and act appropriately). So the only real problem here is Java code that is not under control of Lucee. That is, as far as I can see now, the only reason why calling Thread.stop() might be needed. So, the solution would be to call Thread.interrupt() (and handle interrupts correctly in the thread that is running the CFML code) before falling back to Thread.stop() as a last resort.