Restarting tomcat on latest Lucee with the s3 extension enabled causes web contexts to fail.

Description

We have a problem using Lucee and the Amazon S3 Extension.

After we install the extension we can access the web context that also has an s3 mapping and load content via that mapping with no problem.

However, when we restart tomcat we get a blank page on that same context, and an error in the Application.log.

Then, without restarting tomcat, if we change the version of the S3 extension from within lucee/admin to a different version (for example either from 0.9.4.119 to 0.9.4.116, or from 0.9.4.116 to 0.9.4.119 ) we can connect to that context.

This is the error we get in the application.log :

error

"ERROR","ajp-nio-8009-exec-1","10/21/2019","11:48:18","","configuration;Request Error: Invalid class name: org.jets3t.service.utils.RestUtils$ConnManagerFactory;lucee.runtime.exp.PageRuntimeException: Request Error: Invalid class name: org.jets3t.service.utils.RestUtils$ConnManagerFactory
at org.jets3t.service.S3Service.listAllBuckets(S3Service.java:1461)
at org.lucee.extension.resource.s3.S3.list(S3.java:260)
at org.lucee.extension.resource.s3.S3.get(S3.java:600)
at org.lucee.extension.resource.s3.S3.exists(S3.java:453)
at org.lucee.extension.resource.s3.S3Resource.exists(S3Resource.java:320)
at lucee.runtime.config.ConfigWebUtil._getExistingFile(ConfigWebUtil.java:382)

 

This may be related to org.lucee.jets3t-0.9.4.0006L.jar which uses:

org.lucee.httpcomponents.httpclient;bundle-version=4.5.2

There is a bug in HttpClient 4.5.2 that reports the same error we are seeing. (https://issues.apache.org/jira/browse/HTTPCLIENT-1727)

Modifying the extension-s3 MANIFEST.MF to specify the httpclient org.lucee.httpcomponents.httpcore;bundle-version=4.5.3 didn't work

Also, modifying the extension-s3 MANIFEST.MF to specify the following didn't work:
org.lucee.httpcomponents.httpcore;bundle-version=4.4.10,
org.lucee.httpcomponents.httpclient;bundle-version=4.5.6

(org.lucee.httpcomponents.httpcore;bundle-version=4.4.10, org.lucee.httpcomponents.httpclient;bundle-version=4.5.6 are installed)

We see in the logs org-lucee-httpcomponents-httpcore-4-4-4.jar and org-lucee-httpcomponents-httpclient-4-5-2.jar

Application.log

"INFO","Thread-567","10/22/2019","13:22:22","lucee.runtime.CFMLFactoryImpl","Reset 2 Unused PageContexts"
"INFO","ajp-nio-8009-exec-2","10/22/2019","13:22:24","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\com.mysql.cj-8.0.15.jar"
"INFO","ajp-nio-8009-exec-2","10/22/2019","13:22:24","OSGi","start bundle:com.mysql.cj:8.0.15"
"INFO","Thread-631","10/22/2019","13:22:45","lucee.runtime.CFMLFactoryImpl","Reset 2 Unused PageContexts"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\s3.extension-0.9.4.122-SNAPSHOT.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:s3.extension:0.9.4.122-SNAPSHOT"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\org.lucee.bouncycastle.bcprov-1.52.0.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:org.lucee.bouncycastle.bcprov:1.52.0"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\org.lucee.jets3t-0.9.4.0006L.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:org.lucee.jets3t:0.9.4.0006L"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\org-lucee-httpcomponents-httpcore-4-4-4.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:org.lucee.httpcomponents.httpcore:4.4.4"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\org-lucee-httpcomponents-httpclient-4-5-2.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:org.lucee.httpcomponents.httpclient:4.5.2"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\jackson-core-asl-1.9.13.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:jackson-core-asl:1.9.13"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\jackson-mapper-asl-1.9.13.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:jackson-mapper-asl:1.9.13"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","add bundle:C:\lucee\tomcat\lucee-server\bundles\java.xmlbuilder-1.1.0.jar"
"INFO","ajp-nio-8009-exec-3","10/22/2019","13:23:25","OSGi","start bundle:java.xmlbuilder:1.1.0"

Environment

tomcat 8.5 latest
tomcat 9.0.27 (latest)
Java 8 (latest openjdk)
Java 11 (built in with lucee installer)
Lucee 5.3.4.54-RC
Lucee 5.3.3.62 (release version)

OS Windows Server 2016 (10.0) 64bit

Activity

Show:
steve duke
October 23, 2019, 3:22 PM

we have also reproduced the issue on docker/linux by starting up a new instance on docker, adding the s3 extension, adding an s3 mapping in the web context, then restarting lucee: web context blank page:

  • clean lucee ( min config is mysql latest extension + lucee/docs&admin extensions)

  • add the s3 extension latest

  • go to the web context admin, add a valid s3 mapping

  • check a test web context page to see it's still live

  • restart lucee (docker: lucee server admin > restart)

  • check any page on the web context: blank page

"ERROR","http-nio-8888-exec-10","10/23/2019","10:17:38","configuration","Request Error: Invalid class name: org.jets3t.service.utils.RestUtils$ConnManagerFactory;Request Error: Invalid class name: org.jets3t.service.utils.RestUtils$ConnManagerFactory;lucee.runtime.exp.PageRuntimeException: Request Error: Invalid class name: org.jets3t.service.utils.RestUtils$ConnManagerFactory
at org.jets3t.service.S3Service.listAllBuckets(S3Service.java:1461)
at org.lucee.extension.resource.s3.S3.list(S3.java:260)
at org.lucee.extension.resource.s3.S3.get(S3.java:600)
at org.lucee.extension.resource.s3.S3.exists(S3.java:453)
at org.lucee.extension.resource.s3.S3Resource.exists(S3Resource.java:320)
at lucee.runtime.config.ConfigWebUtil._getExistingFile(ConfigWebUtil.java:382)
at lucee.runtime.config.ConfigWebUtil.getExistingResource(ConfigWebUtil.java:370)
at lucee.runtime.MappingImpl.<init>(MappingImpl.java:141)

Stephan Mosco
October 24, 2019, 3:22 PM

This issue happens when using a lucee resource mapping (set in the lucee web context admin>mappings) that has an s3 access key in it.

Switching to using the same s3 access key in a variable that can be passed to cffile/cfdirectory calls, instead of using the mapping, and deleting the mapping makes the issue go away.

Also notable, restarting or shutting down lucee takes about 60 seconds longer if there is an s3 mapping configured, removing the mapping makes restarts/shutdown much faster.

 

Zac Spitzer
October 24, 2019, 3:35 PM

Hey can you file a separate bug about the shutdown performance problem, add the labels performance,s3,mappings and shutdown and link it back to this task?

Zac Spitzer
November 5, 2019, 3:47 PM

just filed in regards to the slow shutdown problem

Andrew Dixon
March 29, 2020, 5:03 PM

I’ve just come across this same issue as well with versions 0.9.4.122, 0.9.4.119 & 0.9.4.116 on Lucee 5.3.3.62, and couldn’t get any version earlier than 0.9.4.116 to install on Lucee 5.3.3.62, came up with an error in the admin. Worked around this issue by moving the mapping into the Application.cfc using the this.mappingstructure.

Assignee

Unassigned

Reporter

steve duke

Priority

New

Fix versions

None

Sprint

5.3.8 Sprint 3

Affects versions

Configure