DatasourceConnectionPool Exception

527 views
Skip to first unread message

Scott Smith

unread,
Sep 11, 2015, 4:42:10 PM9/11/15
to lucee
We are getting ready to put our first Lucee server into production today, but I decided to do a rudimentary load test of a page in my development environment beforehand (holding down F5 for about a 30 seconds to a minute to initiate a solid stretch of requests).

I noticed I was able to consistently kill my app doing this. It throws an exception that specifies java.lang.ThreadDeath and then repeatedly shows the same exception: java.lang.StackTraceElement[]{lucee.runtime.db.DatasourceConnectionPool.getDatasourceConnection(DatasourceConnectionPool.java:60) 

The exception only takes down a single host and it's context. All other hosts continue to run just fine, but the one I take down will not recover without a restart of the service.

I had someone take the same code and test it on our previous install using Railo (some where in the 4.2 version) and while I was able to kill the instance there too, it was a different in the way that it took down every host on the instance and had a different exception altogether.  

If anyone has any ideas as to whether or not we have an issue with our configuration, I'd appreciate it as I am somewhat uncomfortable adding this server to our production pool before I better understand what the issue is here.  I thought it might be related to the database configuration itself, but then I thought how could the other hosts/contexts continue to run fine when they rely on the same datasource?  

Here is an example of our database connection:

<data-source name="website" database="website" host="&primary-database-host;" username="&primary-database-username;"
password="&primary-database-password;"
allow="511" blob="true" class="net.sourceforge.jtds.jdbc.Driver"
clob="true" connectionLimit="-1" connectionTimeout="1" custom="" dbdriver="MSSQL2"
dsn="jdbc:jtds:sqlserver://{host}:{port}/{database}"
metaCacheTimeout="60000" port="1433" storage="false" validate="false"/>

And here is the stack trace:

2015-09-11 14:53:35 Commons Daemon procrun stderr initialized
java.lang.ThreadDeath
at java.lang.Thread.stop(Thread.java:850)
at lucee.commons.io.StopThread.run(SystemUtil.java:1068)
java.lang.ThreadDeath
at java.lang.Thread.stop(Thread.java:850)
at lucee.commons.io.StopThread.run(SystemUtil.java:1068)
java.lang.StackTraceElement[]{lucee.runtime.db.DatasourceConnectionPool.getDatasourceConnection(DatasourceConnectionPool.java:60)
,lucee.runtime.db.DatasourceManagerImpl.getConnection(DatasourceManagerImpl.java:77)
,lucee.runtime.tag.Query.executeDatasoure(Query.java:726)
,lucee.runtime.tag.Query.doEndTag(Query.java:559)
,query.query_cfc$cf.udfCall(C:\workspace\snap\framework\ORM\Query\Query.cfc:113)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:216)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:642)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:524)
,lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1777)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:773)
,lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1599)
,query_cfm$cf.call(C:\workspace\snap\framework\ORM\Query.cfm:53)
,lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:950)
,lucee.runtime.tag.CFTag.doInclude(CFTag.java:323)
,lucee.runtime.tag.CFTag.cfmlEndTag(CFTag.java:260)
,lucee.runtime.tag.CFTag.doAfterBody(CFTag.java:205)
,orm_cfc$cf.udfCall3(C:\workspace\snap\framework\ORM\ORM.cfc:576)
,orm_cfc$cf.udfCall(C:\workspace\snap\framework\ORM\ORM.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,orm_cfc$cf.udfCall4(C:\workspace\snap\framework\ORM\ORM.cfc:824)
,orm_cfc$cf.udfCall(C:\workspace\snap\framework\ORM\ORM.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:641)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:524)
,lucee.runtime.ComponentImpl.call(ComponentImpl.java:1760)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,model.authorization_cfc$cf.udfCall(C:\workspace\snap\corporate\model\Authorization.cfc:8)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:216)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:642)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:524)
,lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1777)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:773)
,lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1599)
,core.objectloader_cfc$cf.udfCall2(C:\workspace\snap\framework\core\ObjectLoader.cfc:215)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall2(C:\workspace\snap\framework\core\ObjectLoader.cfc:137)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall1(C:\workspace\snap\framework\core\ObjectLoader.cfc:130)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall2(C:\workspace\snap\framework\core\ObjectLoader.cfc:249)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall2(C:\workspace\snap\framework\core\ObjectLoader.cfc:239)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall2(C:\workspace\snap\framework\core\ObjectLoader.cfc:211)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall2(C:\workspace\snap\framework\core\ObjectLoader.cfc:137)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.type.scope.UndefinedImpl.call(UndefinedImpl.java:766)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,core.objectloader_cfc$cf.udfCall1(C:\workspace\snap\framework\core\ObjectLoader.cfc:130)
,core.objectloader_cfc$cf.udfCall(C:\workspace\snap\framework\core\ObjectLoader.cfc)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:216)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:642)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:524)
,lucee.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1777)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithNamedValues(VariableUtilImpl.java:773)
,lucee.runtime.PageContextImpl.getFunctionWithNamedValues(PageContextImpl.java:1599)
,core.fwengine_cfc$cf.udfCall(C:\workspace\snap\framework\core\fwEngine.cfc:23)
,lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:111)
,lucee.runtime.type.UDFImpl._call(UDFImpl.java:328)
,lucee.runtime.type.UDFImpl.call(UDFImpl.java:229)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:641)
,lucee.runtime.ComponentImpl._call(ComponentImpl.java:524)
,lucee.runtime.ComponentImpl.call(ComponentImpl.java:1760)
,lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:742)
,lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1589)
,base.index_cfm$cf.call(C:\workspace\snap\framework\base\index.cfm:8)
,lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:950)
,lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:854)
,index_cfm$cf.call(C:\workspace\snap\corporate\index.cfm:1)
,lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:950)
,lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:902)
,lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:223)
,lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:35)
,lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2257)
,lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2224)
,lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:456)
,lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:47)
,javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
,org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
,org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
,org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
,org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
,org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
,org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:748)
,org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:486)
,org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:411)
,org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:338)
,org.tuckey.web.filters.urlrewrite.NormalRewrittenUrl.doRewrite(NormalRewrittenUrl.java:213)
,org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:171)
,org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145)
,org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92)
,org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:381)
,org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
,org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
,org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
,org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
,org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
,org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
,org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
,org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
,ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:191)
,org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
,org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
,org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:620)
,org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2516)
,org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2505)
,java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
,java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
,org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
,java.lang.Thread.run(Thread.java:745)
}


Geoff Parkhurst

unread,
Sep 14, 2015, 4:56:40 AM9/14/15
to lu...@googlegroups.com
With your change to Lucee, did you upgrade to Java 8 ?

I can't add a lot, other than a 'me too' - since moving to Java 8,
we've had lots of problems with java.lang.threaddeath, especially in
the area of database connectivity. I've noticed quite a few commits in
github / lucee concerning database pools, changes to the way threads
are killed / timed out etc so am hoping some of this will filter down
to the stable branch soon.

We're also testing a recent (4.2 it is now) Microsoft SQL driver - no
problems so far.
> --
> See Lucee at CFCamp Oct 22 & 23 2015 @ Munich Airport, Germany - Get your
> ticket NOW - http://www.cfcamp.org/
> ---
> 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/CADhKUgGaS8wnZHwm2uCSsQoMXRxR-LwMiwbymQRnGJDOV3%2BjBQ%40mail.gmail.com.
> For more options, visit https://groups.google.com/d/optout.

Scott Smith

unread,
Sep 14, 2015, 8:03:23 AM9/14/15
to lu...@googlegroups.com
Yes we did indeed update to Java8. The last thing I did Friday before leaving was try swapping back to Java7 and see how that went. It appeared I was still able to take down my local instance, but I ended up just letting it spin and taking off for the weekend. I will jump into the logs this morning when I get in and confirm whether or not the outcome was different with Java7. Also, did you say you are using a different driver than what is packaged with Lucee? Is the 4.2 driver being used in combination with Java8 or Java7?



On September 14, 2015 at 3:56:38 AM CDT, Geoff Parkhurst <geoff.p...@gmail.com> wrote:
With your change to Lucee, did you upgrade to Java 8 ?

I can't add a lot, other than a 'me too' - since moving to Java 8,
we've had lots of problems with java.lang.threaddeath, especially in
the area of database connectivity. I've noticed quite a few commits in
github / lucee concerning database pools, changes to the way threads
are killed / timed out etc so am hoping some of this will filter down
to the stable branch soon.

We're also testing a recent (4.2 it is now) Microsoft SQL driver - no
problems so far.

On 11 September 2015 at 21:42, Scott Smith wrote:
> We are getting ready to put our first Lucee server into production today,
> but I decided to do a rudimentary load test of a page in my development
> environment beforehand (holding down F5 for about a 30 seconds to a minute
> to initiate a solid stretch of requests).
>
> I noticed I was able to consistently kill my app doing this. It throws an
> exception that specifies java.lang.ThreadDeath and then repeatedly shows the
> same exception:
> java.lang.StackTraceElement[]{lucee.runtime.db.DatasourceConnectionPool.getDatasourceConnection(DatasourceConnectionPool.java:60)
>
> The exception only takes down a single host and it's context. All other
> hosts continue to run just fine, but the one I take down will not recover
> without a restart of the service.
>
> I had someone take the same code and test it on our previous install using
> Railo (some where in the 4.2 version) and while I was able to kill the
> instance there too, it was a different in the way that it took down every
> host on the instance and had a different exception altogether.
>
> If anyone has any ideas as to whether or not we have an issue with our
> configuration, I'd appreciate it as I am somewhat uncomfortable adding this
> server to our production pool before I better understand what the issue is
> here. I thought it might be related to the database configuration itself,
> but then I thought how could the other hosts/contexts continue to run fine
> when they rely on the same datasource?
>
> Here is an example of our database connection:
>

Harry Klein

unread,
Sep 14, 2015, 8:18:07 AM9/14/15
to lu...@googlegroups.com

Hi Scott,

 

have you tried the MSSQL driver instead of jTDS?

I had problems with jTDS in the past and therefore used the MSSQL driver instead.

After reading several articles like

https://social.msdn.microsoft.com/Forums/en-US/36e7b9cf-5bc5-445d-874c-1d6f8e819b63/ms-jdbc-driver-performance-observations-versus-jtds?forum=sqldataaccess

jTDS looks to be faster – I have to investigate if this driver should be used instead.

 

But, the latest version seems to be 1.3.1 – from 2013-06-08 !

http://sourceforge.net/projects/jtds/files/jtds/

 

The version bundled with Lucee seems to be 1.2.8:

 

Manifest-Version: 1.0

Ant-Version: Apache Ant 1.8.2

Created-By: 1.4.2_19-b04 (Sun Microsystems Inc.)

Implementation-Title: jTDS JDBC Driver

Implementation-Version: 1.2.8

Implementation-URL: http://jtds.sourceforge.net

Specification-Title: JDBC

Specification-Version: 3.0

Main-Class: net.sourceforge.jtds.jdbc.Driver

 

-Harry

Scott Smith

unread,
Sep 14, 2015, 10:13:09 AM9/14/15
to lucee
I have not tried the Microsoft driver as we were using the jtds driver on our previous Railo setup, so I was trying to keep things as consistent as possible. I can certainly give that a run and see how it goes. The article you linked does not give the best impression of it in comparison to jtds, but it is worth a shot at this point. 

Harry Klein

unread,
Sep 14, 2015, 10:30:41 AM9/14/15
to lucee

Hi Scott,

 

>> The article you linked does not give the best impression of it in comparison to jtds

 

Well, I found these lines very interesting:


“… Compared to using JTDS, the MS Driver is:

  • allocating 7 times the memory,
  • consuming 3 times the CPU and
  • generating 3.5 times the network traffic.

…”

 

I would be cautious with jTDS with MSSQL 2014 – which is not supported. This question  from 2015-09-01 was not answered yet:

http://sourceforge.net/p/jtds/discussion/104389/thread/b53935c1/

 

And this important question from 2015-02-09 also:

http://sourceforge.net/p/jtds/discussion/104388/thread/1ee8ab88/

 

At this point I have no idea if the development of the jTDS is stagnant or has even stopped?

 

This was the latest news:

http://sourceforge.net/p/jtds/news/2013/06/jtds-jdbc-driver-128-and-131-released/

Scott Smith

unread,
Sep 14, 2015, 11:15:53 AM9/14/15
to lucee
I attempted to use the Microsoft driver, but it appears that it may not work for us. We have instances in our application where, within a single cfquery, we declare a table variable, populate it, select from it. With jtds we can them see the results from the select whereas with the Microsoft driver, we just get empty string back for the results. 

I also tried reverting to Java7. While it did not cause the same error, it still killed the instance. Unfortunately I wiped those errors logs from the Java7 attempt already, but if someone believes Java7 is our best bet I am sure can reproduce them.  I'd ideally like to get us upgrade to Java8 though. 

Geoff Parkhurst

unread,
Sep 14, 2015, 11:19:22 AM9/14/15
to lu...@googlegroups.com
On 14 September 2015 at 13:03, Scott Smith <scottad...@gmail.com> wrote:
> Yes we did indeed update to Java8. The last thing I did Friday before
> leaving was try swapping back to Java7 and see how that went. It appeared I
> was still able to take down my local instance, but I ended up just letting
> it spin and taking off for the weekend. I will jump into the logs this
> morning when I get in and confirm whether or not the outcome was different
> with Java7.

I suspect the errors won't be 'java.lang.ThreadDeath'

> Also, did you say you are using a different driver than what is packaged with Lucee?

A different *version* of the packaged driver, yes. 4.2 is relatively
recent (went gold a week or two ago)

https://www.microsoft.com/en-gb/download/details.aspx?id=11774

>Is the 4.2 driver being used in combination with Java8 or Java7?

With Java 8.

Out of interest, do you limit the connection pool and / or apply
timeouts to your queries?

In general: I don't know the full history, but I think Java 8 has
removed the Thread.Stop() function. My hunch is any running cfm page
on Lucee / Java 8 which times out causes this thread death error
because it's trying to stop() it unsuccessfully. My 2nd hunch is this
causes the *in use* database connection to be left hanging, your pool
'dries up' and you need to restart Tomcat to clear it... But I'm
guessing really & keeping a close eye on the commit history in
GitHub...

Scott Smith

unread,
Sep 14, 2015, 11:24:48 AM9/14/15
to lucee
Based on what is shows in the stack trace it sounds like are you are on to something. Our data-source configurations in the lucee-server.xml are configured with infinite connectionLimit and a 1 minute connectionTimeout. We generally default to a 50 second request timeout if I am not mistaken, but I am not aware of any query timeout we have in place. 

--
See Lucee at CFCamp Oct 22 & 23 2015 @ Munich Airport, Germany - Get your ticket NOW - http://www.cfcamp.org/
---
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.

thorste...@googlemail.com

unread,
Sep 14, 2015, 1:37:24 PM9/14/15
to Lucee
Microsoft published the last days a New jdbc driver. Maybe give it a try?

Scott Smith

unread,
Sep 14, 2015, 1:58:51 PM9/14/15
to lucee
I would indeed like to try that. This might be an obvious answer, but I have had trouble figuring out how to use anything but the version included with Lucee. Do I need to overwrite a JAR in lib?

Side note, I narrowed down the issue that I originally believed occurred when executing multiple statements in a single query using the Microsoft driver. I was wrong, it's more specific than that. 

This snippet works fine using the Microsoft driver:

                                        <cfset var qry = "" />
<cfset var rslt = "" />
<cfquery name="qry" result="rslt">
DECLARE @TestTable TABLE (ID INT)

INSERT INTO @TestTable(ID)
VALUES(1)

INSERT INTO @TestTable(ID)
VALUES(2)

SELECT * FROM @TestTable
</cfquery>
<cfdump var="#qry#" />
<cfdump var="#rslt#" />
<cfabort />

This one does not (however, it works using the JTDS driver):

                                        <cfset var qry = "" />
<cfset var rslt = "" />
<cfquery name="qry" result="rslt">
DECLARE @TestTable TABLE (ID INT)
DECLARE @TestOutputTable TABLE (ID INT)

INSERT INTO @TestTable(ID)
OUTPUT inserted.ID INTO @TestOutputTable
VALUES (1)

SELECT * FROM @TestOutputTable
</cfquery>
<cfdump var="#qry#" />
<cfdump var="#rslt#" />
<cfabort />

I would definitely be interested in updating to the latest Microsoft driver to see if this is still the case.

Thanks,
Scott

On Mon, Sep 14, 2015 at 12:37 PM, <thorste...@googlemail.com> wrote:
Microsoft published the last days a New jdbc driver. Maybe give it a try?
--
See Lucee at CFCamp Oct 22 & 23 2015 @ Munich Airport, Germany - Get your ticket NOW - http://www.cfcamp.org/
---
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.

Geoff Parkhurst

unread,
Sep 16, 2015, 8:27:10 AM9/16/15
to lu...@googlegroups.com
On 14 September 2015 at 18:58, Scott Smith <scottad...@gmail.com> wrote:
> This one does not (however, it works using the JTDS driver):
>
> <cfset var qry = "" />
> <cfset var rslt = "" />
> <cfquery name="qry" result="rslt">
> DECLARE @TestTable TABLE (ID INT)
> DECLARE @TestOutputTable TABLE (ID INT)
>
> INSERT INTO @TestTable(ID)
> OUTPUT inserted.ID INTO @TestOutputTable
> VALUES (1)
>
> SELECT * FROM @TestOutputTable
> </cfquery>
> <cfdump var="#qry#" />
> <cfdump var="#rslt#" />
> <cfabort />

FYI, this doesn't work on the Microsoft driver, version 4.2.6420.100

This, however *does* work:

SET NOCOUNT ON;
DECLARE @TestTable TABLE (ID INT)
DECLARE @TestOutputTable TABLE (ID INT)
INSERT INTO @TestTable(ID)
OUTPUT inserted.ID INTO @TestOutputTable
VALUES (1)
SELECT * FROM @TestOutputTable


The "1 row(s) affected" messages are screwing up the (?) driver's
interpretation of the results... The SET NOCOUNT ON; bit seems to
remove those messages and you get a result.

(We see similar things with full-text searches in stored procs - the
"warning! stop words used!" type messages get in the way of the 'real'
results.)

Hope that helps

Geoff

mark.s...@lovehoney.co.uk

unread,
Dec 8, 2015, 6:04:10 AM12/8/15
to Lucee
I have done some testing to determine what happens when a Lucee DB connection pool is overloaded.  The testing used the following setup:

  • CentOS 6.6
  • Tomcat 7.0.56
  • Java 1.8.0_51
  • MS SQL driver sqljdbc_4.2.6420
  • Lucee 4.5.2.018

I am using jMeter to request a page containing the following cfquery, which is designed to take more than 1 hour to return.

<cfquery
    name="test_sleep"
    datasource="{name of datasource}"
>
SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;
WAITFOR DELAY '01:00:10';
SELECT 1;
</cfquery>


I am also using FusionReactor to monitor the in-progress SQL sessions and the Tomcat JVM thread states.

The Lucee application request timeout is 50s.  The datasource connection pool size is unlimited.  The concurrency of the jMeter test is 500 and there is no ramp up time and no timer.

My observations are as follows...

1) Some HTTP sessions return in 20s or less, which is lower than the application timeout and lower than the SQL query duration.  I have no explanation for this (I currently have no visibility of the response data).

2) Lots of java.lang.ThreadDeath messages are logged, and these seem to be associated with the 50s application timeout being enforced, so not necessarily a bad thing.

3) After some time, things start to go wrong:  The majority of Tomcat JVM threads move from states RUNNABLE and TIMED_WAITING to BLOCKED.  When this happens, SQL activity drops to 0 i.e. no more database queries are attempted despite the continued influx of HTTP traffic.

To elaborate on point 3) above, the BLOCKED threads appear to be deadlocked within lucee.runtime.db.DatasourceConnectionPool.releaseDatasourceConnection()  I have provided an indicative thread dump below.  The point of contention appears to be the acquisition of a synchronous lock on the datasource connection stack.

"ajp-apr-8009-exec-1" #158 daemon prio=1 os_prio=0 tid=0x00007f57b40c7800 nid=0x6ace waiting for monitor entry [0x00007f57979f5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at lucee.runtime.db.DatasourceConnectionPool.releaseDatasourceConnection(DatasourceConnectionPool.java:104)
    - waiting to lock <0x00000000f12fcfd8> (a lucee.runtime.db.DCStack)
    at lucee.runtime.db.DatasourceConnectionPool.releaseDatasourceConnection(DatasourceConnectionPool.java:96)
    at lucee.runtime.db.DatasourceManagerImpl.releaseConnection(DatasourceManagerImpl.java:153)
    at lucee.runtime.tag.Query.executeDatasoure(Query.java:790)
    at lucee.runtime.tag.Query.doEndTag(Query.java:597)
    at test.index_cfm$cf.call(/var/lib/tomcat/lovehoney/wwwroot/test/index.cfm:10)
    at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:951)
    at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:903)
    at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:223)
    at lucee.runtime.listener.ModernAppListener.onRequest(ModernAppListener.java:101)
    at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2262)
    at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2225)
    at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:456)
    at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:47)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at sun.reflect.GeneratedMethodAccessor68.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:97)
    at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doNext(FusionReactorRequestHandler.java:472)
    at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doHttpServletRequest(FusionReactorRequestHandler.java:312)
    at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doFusionRequest(FusionReactorRequestHandler.java:192)
    at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.handle(FusionReactorRequestHandler.java:507)
    at com.intergral.fusionreactor.j2ee.filter.FusionReactorCoreFilter.doFilter(FusionReactorCoreFilter.java:36)
    at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:79)
    at sun.reflect.GeneratedMethodAccessor65.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at com.intergral.fusionreactor.agent.filter.FusionReactorStaticFilter.doFilter(FusionReactorStaticFilter.java:53)
    at com.intergral.fusionreactor.agent.pointcuts.NewFilterChainPointCut$1.invoke(NewFilterChainPointCut.java:41)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:503)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
    at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:188)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
    at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2399)
    - locked <0x00000000f7437398> (a org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Unknown Source)


In the past, I have attempted to collect thread dumps on failed nodes in our live environment and not obtained such a clear result (which is repeatable in the test environment).  This leads me to suspect that the BLOCKED threads will eventually move to a different state.  However, the nodes do not recover i.e. normal service is not resumed until a restart is performed.

mark.s...@lovehoney.co.uk

unread,
Dec 8, 2015, 12:07:40 PM12/8/15
to Lucee
I have noticed that setting the timeout attribute in the cfquery tag to a value lower than the application request timeout seems to mitigate the issue.  Some thread blocking still occurs, but the situation never becomes so bad the the server is unable to recover.

NB: Contrary to the documentation, the timeout value should be specified in seconds and not milliseconds, at least when using the MS SQL Server driver.

Nick S.

unread,
May 12, 2016, 12:32:29 PM5/12/16
to Lucee
Recently migrated to Lucee 4.5.2.018/Java 8 in production from Railo and we're starting to see this behavior as well on a busy Mura site using Oracle. Lots of random locking on lucee.runtime.db.DatasourceConnectionPool.getDatasourceConnection(DatasourceConnectionPool.java:61) until a restart. 

Not sure if adding a query timeout is a solution here but still doing some digging. 

If anyone has any new information on this, please let us know! 

Thanks

Christian Meis

unread,
Sep 19, 2016, 4:11:50 AM9/19/16
to Lucee
Unfortunately we're experiencing the same or a very similar thing here - Lucee 4.5.3.018 final, Tomcat 8.0.24 on Java 1.8.
The major difference is that we are connecting to a MySQL server, not MSSQL. 

Lots of errors like this one:

"ERROR","Thread-141","09/19/2016","09:55:53","controler","stop thread (22) because run into a timeout path: /opt/lucee/tomcat/webapps/ROOT/index.cfm.;java.lang.Throwable;java.lang.Throwable
        at java.lang.Object.wait(Native Method)
        at lucee.runtime.db.DatasourceConnectionPool.getDatasourceConnection(DatasourceConnectionPool.java:63)
        at lucee.runtime.db.DatasourceManagerImpl.getConnection(DatasourceManagerImpl.java:77)
        at lucee.runtime.db.DatasourceManagerImpl.getConnection(DatasourceManagerImpl.java:71)
[...]

The datasource is configured with a connection limit (which is way under MySQLs configured limit) and a connection timeout of 1 minute.

So far we found no way to get this running in a stable manner, sometimes having to restart Tomcat every few hours to keep the app running...

Does anyone have further insight into this?


Best regards,
Christian 

Christian Meis

unread,
Sep 19, 2016, 11:36:33 AM9/19/16
to Lucee
Talking to myself ;-)

Scanning JIRA gave that this seems to be LDEV-396 (https://luceeserver.atlassian.net/browse/LDEV-396), which is marked as resolved in 4.5.4.003 - which is the development channel.

Is there any chance to get this into a stable 4.5 release?

Best regards,
Christian

Mark Summers

unread,
Sep 19, 2016, 1:14:49 PM9/19/16
to lu...@googlegroups.com
If you look at the relevant JIRA ticket, you will notice two things...

1) Some code in the Lucee 4 fix that looks as though it will never actually run.  I have queried this.

2) A linked ticket about problems with transaction rollbacks, which apparently started when the LDEV-396 code was introduced.

Mark

--
Get 10% off of the regular price for this years CFCamp in Munich, Germany (Oct. 20th & 21st) with the Lucee discount code Lucee@cfcamp. 189€ instead of 210€. Visit https://ti.to/cfcamp/cfcamp-2016/discount/Lucee@cfcamp
---
You received this message because you are subscribed to a topic in the Google Groups "Lucee" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/lucee/etIjfig_pV8/unsubscribe.
To unsubscribe from this group and all its topics, send an email to lucee+unsubscribe@googlegroups.com.

To post to this group, send email to lu...@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages