users@glassfish.java.net

[gf-users] Re: (3.1.2.2) Interrupting idle thread on a non-idle thread

From: Noah White <emailnbw_at_gmail.com>
Date: Thu, 8 May 2014 23:02:57 -0400

The threads are considered IDLE and that's why you are running into this. The IDLE timeout (despite its name) has no concern if there is actually activity being done by the thread. It only looks at the amount if time it's been assigned from the pool.

IMO it's at best poor verbiage to call it and IDLE timeout value. They should either change the verbiage or implement functionality so that times out on the lack of actual thread activity.

A while back I filed an issue in the GF jira about this - feel free to throw a vote on it.

-Noah

Sent from my iPhone

> On May 8, 2014, at 8:17 PM, Pawel Veselov <pawel.veselov_at_gmail.com> wrote:
>
> Hi.
>
> I'm being hit with the flood of "Interrupting idle thread" messages in my GF logs, for threads that aren't idle, but are just taking long (hours) time to execute.
>
> It's normal for these particular requests to take that long time. The thread pool idle clean-up timeout is 900sec, and I assume the interruption starts after that time. It's reflected in the responses, when trying with curl, for example, it would wait for all the time that the thread will take to execute the job, but the job is completed, the response fails; that. Because the HTTP request body is partially written by that time (before the job's started), curl just says "curl: (18) transfer closed with outstanding read data remaining". This only happens when response time exceeds 15 minutes (900sec). So, that pending interrupt actually cancels the request, once GF classes can get their hands on the thread.
>
> Shouldn't this thread be considered "in use", and shouldn't be interrupted?
>
> Message: [#|2014-05-09T00:08:46.703+0000|WARNING|glassfish3.1.2|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=11;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-8080(13).|#]
>
> Stack trace:
> "http-thread-pool-8080(13)" daemon prio=10 tid=0x4652b000 nid=0x2766 in Object.wait() [0x3fdfe000]
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:129)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
> <...skipped...>
> at com.gsm.reporter.service.ReportServiceImpl.rebuildReports(ReportServiceImpl.java:273)
> at org.apache.jsp.do_jsp._jspService(do_jsp.java from :211)
> at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:111)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
> at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:411)
> at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:473)
> at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:377)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
> at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
> at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
> at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161)
> at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:331)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
> at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317)
> at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
> at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:860)
> at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:757)
> at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1056)
> at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:229)
> at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
> at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
> at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
> at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
> at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
> at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
> at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
> at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
> at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
>
>