I almost created a new post for this, but it seems very related to what we were seeing in the first place. We are actually getting error messages in the logs that Redis failed to install even when s3 is installed. So there is something else afoot. I can reproduce this locally every time (or every time I’ve tried so far
) and it is happening on our DEV, QA, and Prod servers.
The really weird thing is, I’m not getting errors about Redis within the app. The app seems to be working even though it says it didn’t install Redis and Redis isn’t listed in the installed extensions via the admin (everything else shows as installed). I can see in the logs it is storing/retrieving from Redis.
Our LUCEE_EXTENSIONS
env var is like so…
LUCEE_EXTENSIONS="CED6227E-0F49-6367-A68D21AACA6B07E8;name=admin;version=1.0.0.5, D4EDFDBD-A9A3-E9AF-597322D767E0C949;name=oracle;version=21.3.0.0000, 671B01B8-B3B3-42B9-AC055A356BED5281;name=postgresql;version=42.2.20, 60772C12-F179-D555-8E2CD2B4F7428718;name=redis;version=3.0.0.51, 17AB52DE-B300-A94B-E058BD978511E39E;name=s3;version=2.0.2.19, B737ABC4-D43F-4D91-8E8E973E37C40D1B;name=imageExtension;version=2.0.0.26, 37C61C0A-5D7E-4256-8572639BE0CF5838;name=owasp;version=2.2.4.15"
I’ve also set LUCEE_LOGGING_FORCE_APPENDER=true
and LUCEE_LOGGING_FORCE_LEVEL=debug
.
Here is the output from running the container where the extensions are installed…
30-Jun-2025 11:45:50.610 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name: Apache Tomcat/11.0.6
30-Jun-2025 11:45:50.636 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built: Apr 1 2025 14:40:40 UTC
30-Jun-2025 11:45:50.638 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 11.0.6.0
30-Jun-2025 11:45:50.639 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name: Linux
30-Jun-2025 11:45:50.640 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version: 6.1.75-0-virt
30-Jun-2025 11:45:50.641 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture: amd64
30-Jun-2025 11:45:50.642 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home: /opt/java/openjdk
30-Jun-2025 11:45:50.642 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version: 21.0.7+6-LTS
30-Jun-2025 11:45:50.643 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor: Eclipse Adoptium
30-Jun-2025 11:45:50.644 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE: /usr/local/tomcat
30-Jun-2025 11:45:50.644 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME: /usr/local/tomcat
30-Jun-2025 11:45:50.724 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
30-Jun-2025 11:45:50.729 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
30-Jun-2025 11:45:50.729 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
30-Jun-2025 11:45:50.729 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
30-Jun-2025 11:45:50.730 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
30-Jun-2025 11:45:50.730 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang.reflect=ALL-UNNAMED
30-Jun-2025 11:45:50.730 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
30-Jun-2025 11:45:50.731 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
30-Jun-2025 11:45:50.731 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
30-Jun-2025 11:45:50.731 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
30-Jun-2025 11:45:50.732 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --enable-native-access=ALL-UNNAMED
30-Jun-2025 11:45:50.732 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms256m
30-Jun-2025 11:45:50.733 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx2048m
30-Jun-2025 11:45:50.734 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom
30-Jun-2025 11:45:50.735 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
30-Jun-2025 11:45:50.735 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
30-Jun-2025 11:45:50.736 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
30-Jun-2025 11:45:50.755 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [2.0.8] using APR version [1.7.2].
30-Jun-2025 11:45:50.801 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 3.0.13 30 Jan 2024]
30-Jun-2025 11:45:52.410 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8888"]
30-Jun-2025 11:45:52.512 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [2922] milliseconds
30-Jun-2025 11:45:52.594 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
30-Jun-2025 11:45:52.595 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/11.0.6]
"INFO","main","06/30/2025","11:46:02","controller","No extension(s) found to add/install"
"INFO","main","06/30/2025","11:46:02","controller","Extensions to install defined in env variable or system property:CED6227E-0F49-6367-A68D21AACA6B07E8;name=admin;version=1.0.0.5, D4EDFDBD-A9A3-E9AF-597322D767E0C949;name=oracle;version=21.3.0.0000, 671B01B8-B3B3-42B9-AC055A356BED5281;name=postgresql;version=42.2.20, 60772C12-F179-D555-8E2CD2B4F7428718;name=redis;version=3.0.0.51, 17AB52DE-B300-A94B-E058BD978511E39E;name=s3;version=2.0.2.19, B737ABC4-D43F-4D91-8E8E973E37C40D1B;name=imageExtension;version=2.0.0.26, 37C61C0A-5D7E-4256-8572639BE0CF5838;name=owasp;version=2.2.4.15"
"INFO","main","06/30/2025","11:46:05","extension","copy [CED6227E-0F49-6367-A68D21AACA6B07E8:1.0.0.5] to [/opt/lucee/server/lucee-server/context/extensions/available/CED6227E-0F49-6367-A68D21AACA6B07E8-1.0.0.5.lex]"
"INFO","main","06/30/2025","11:46:05","extension","remove Mapping [/lucee/admin]"
"DEBUG","main","06/30/2025","11:46:05","extension","Update Mapping [/lucee/admin]"
"INFO","main","06/30/2025","11:46:07","extension","copy [D4EDFDBD-A9A3-E9AF-597322D767E0C949:21.3.0.0000] to [/opt/lucee/server/lucee-server/context/extensions/available/D4EDFDBD-A9A3-E9AF-597322D767E0C949-21.3.0.0000.lex]"
"DEBUG","main","06/30/2025","11:46:07","extension","Deploy context [admin/dbdriver/Oracle.cfc]"
"DEBUG","main","06/30/2025","11:46:07","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/org.lucee.oracle-21.3.0.0000L.jar"
"DEBUG","main","06/30/2025","11:46:07","OSGi","Start bundle: [org.lucee.oracle:21.3.0.0000L]"
"INFO","main","06/30/2025","11:46:07","extension","Update JDBC Driver [Oracle 12c (Release 1):class:oracle.jdbc.OracleDriver;name:org.lucee.oracle;version:21.3.0.0000L;] from extension [Oracle 12c (Release 1):21.3.0.0000]"
"INFO","main","06/30/2025","11:46:08","extension","copy [671B01B8-B3B3-42B9-AC055A356BED5281:42.2.20] to [/opt/lucee/server/lucee-server/context/extensions/available/671B01B8-B3B3-42B9-AC055A356BED5281-42.2.20.lex]"
"DEBUG","main","06/30/2025","11:46:08","extension","Deploy context [admin/dbdriver/PostgreSql.cfc]"
"DEBUG","main","06/30/2025","11:46:08","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/org.postgresql.jdbc-42.2.20.jar"
"DEBUG","main","06/30/2025","11:46:08","OSGi","Start bundle: [org.postgresql.jdbc:42.2.20]"
"INFO","main","06/30/2025","11:46:08","extension","Update JDBC Driver [PostgreSQL:class:org.postgresql.Driver;name:org.postgresql.jdbc;version:42.2.20;] from extension [PostgreSQL:42.2.20]"
"INFO","main","06/30/2025","11:46:10","extension","copy [60772C12-F179-D555-8E2CD2B4F7428718:3.0.0.51] to [/opt/lucee/server/lucee-server/context/extensions/available/60772C12-F179-D555-8E2CD2B4F7428718-3.0.0.51.lex]"
"DEBUG","main","06/30/2025","11:46:10","extension","Deploy context [admin/cdriver/Redis.cfc]"
"DEBUG","main","06/30/2025","11:46:10","extension","Deploy fld [lucee-redis.fld]"
"DEBUG","main","06/30/2025","11:46:10","extension","Deploy tld/tldx [lucee-redis.tldx]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/redis.extension-3.0.0.51.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [redis.extension:3.0.0.51]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/org.lucee.aws-java-sdk-secretsmanager-all-1.12.454.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [org.lucee.aws-java-sdk-secretsmanager-all:1.12.454]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/com.fasterxml.jackson.core.jackson-core-2.15.0.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [com.fasterxml.jackson.core.jackson-core:2.15.0]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/com.fasterxml.jackson.core.jackson-databind-2.15.0.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [com.fasterxml.jackson.core.jackson-databind:2.15.0]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/com.fasterxml.jackson.core.jackson-annotations-2.15.0.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [com.fasterxml.jackson.core.jackson-annotations:2.15.0]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/com.fasterxml.jackson.dataformat.jackson-dataformat-cbor-2.15.0.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [com.fasterxml.jackson.dataformat.jackson-dataformat-cbor:2.15.0]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/joda-convert-1.2.0.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [joda-convert:1.2.0]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/joda-time-2.8.1.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [joda-time:2.8.1]"
"DEBUG","main","06/30/2025","11:46:10","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/org.mongodb.bson-4.2.3.jar"
"DEBUG","main","06/30/2025","11:46:10","OSGi","Start bundle: [org.mongodb.bson:4.2.3]"
"Severity","ThreadID","Date","Time","Application","Message"
"INFO","main","06/30/2025","11:46:12","extension","copy [17AB52DE-B300-A94B-E058BD978511E39E:2.0.2.19] to [/opt/lucee/server/lucee-server/context/extensions/available/17AB52DE-B300-A94B-E058BD978511E39E-2.0.2.19.lex]"
"DEBUG","main","06/30/2025","11:46:12","extension","Deploy fld [s3-functions.fld]"
"DEBUG","main","06/30/2025","11:46:12","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/org.lucee.s3.extension-2.0.2.19.jar"
"DEBUG","main","06/30/2025","11:46:12","OSGi","Start bundle: [org.lucee.s3.extension:2.0.2.19]"
"DEBUG","main","06/30/2025","11:46:12","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/org.lucee.aws-java-sdk-s3-all-1.12.758.jar"
"DEBUG","main","06/30/2025","11:46:12","OSGi","Start bundle: [org.lucee.aws-java-sdk-s3-all:1.12.758]"
"DEBUG","main","06/30/2025","11:46:12","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/jaxb-api-2.3.1.jar"
"DEBUG","main","06/30/2025","11:46:12","OSGi","Start bundle: [jaxb-api:2.3.1]"
"DEBUG","main","06/30/2025","11:46:12","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/bouncycastle.prov-1.38.0.jar"
"DEBUG","main","06/30/2025","11:46:12","OSGi","Start bundle: [bouncycastle.prov:1.38.0]"
"DEBUG","main","06/30/2025","11:46:13","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/bouncycastle.tsp-1.38.0.jar"
"DEBUG","main","06/30/2025","11:46:13","OSGi","Start bundle: [bouncycastle.tsp:1.38.0]"
"DEBUG","main","06/30/2025","11:46:13","OSGi","add bundle:/opt/lucee/server/lucee-server/bundles/bouncycastle.mail-1.38.0.jar"
"DEBUG","main","06/30/2025","11:46:13","OSGi","Start bundle: [bouncycastle.mail:1.38.0]"
"INFO","main","06/30/2025","11:46:13","extension","Update resource provider [s3] from extension [S3 Resource Extension:2.0.2.19]"
"INFO","main","06/30/2025","11:46:15","extension","copy [B737ABC4-D43F-4D91-8E8E973E37C40D1B:2.0.0.26] to [/opt/lucee/server/lucee-server/context/extensions/available/B737ABC4-D43F-4D91-8E8E973E37C40D1B-2.0.0.26.lex]"
"DEBUG","main","06/30/2025","11:46:15","extension","Deploy fld [image-function.fld]"
"DEBUG","main","06/30/2025","11:46:15","extension","Deploy tld/tldx [image-tag.tldx]"
"INFO","main","06/30/2025","11:46:16","extension","copy [37C61C0A-5D7E-4256-8572639BE0CF5838:2.2.4.15] to [/opt/lucee/server/lucee-server/context/extensions/available/37C61C0A-5D7E-4256-8572639BE0CF5838-2.2.4.15.lex]"
"DEBUG","main","06/30/2025","11:46:16","extension","Deploy fld [esapi-function.fld]"
"Severity","ThreadID","Date","Time","Application","Message"
"INFO","main","06/30/2025","11:46:16","controller","Successfully installed the following extensions: B737ABC4-D43F-4D91-8E8E973E37C40D1B;name=imageExtension;version=2.0.0.26, 37C61C0A-5D7E-4256-8572639BE0CF5838;name=owasp;version=2.2.4.15, 671B01B8-B3B3-42B9-AC055A356BED5281;name=postgresql;version=42.2.20, D4EDFDBD-A9A3-E9AF-597322D767E0C949;name=oracle;version=21.3.0.0000, 17AB52DE-B300-A94B-E058BD978511E39E;name=s3;version=2.0.2.19, CED6227E-0F49-6367-A68D21AACA6B07E8;name=admin;version=1.0.0.5"
"ERROR","main","06/30/2025","11:46:16","controller","Failed to install the following extensions: 60772C12-F179-D555-8E2CD2B4F7428718;name=redis;version=3.0.0.51"
"Severity","ThreadID","Date","Time","Application","Message"
"DEBUG","main","06/30/2025","11:46:16","dynamic","extract metadata from [lucee.commons.io.res.type.file.FileResourceProvider]"
"DEBUG","main","06/30/2025","11:46:17","dynamic","extract metadata from [lucee.runtime.cache.tag.request.RequestCacheHandler]"
"DEBUG","main","06/30/2025","11:46:17","dynamic","extract metadata from [lucee.runtime.cache.tag.timespan.TimespanCacheHandler]"
"DEBUG","main","06/30/2025","11:46:17","OSGi","add bundle:/opt/lucee/server/lucee-server/context/context/lucee-admin.lar"
"DEBUG","main","06/30/2025","11:46:17","dynamic","extract metadata from [lucee.runtime.dump.HTMLDumpWriter]"
"DEBUG","main","06/30/2025","11:46:17","dynamic","extract metadata from [lucee.runtime.dump.TextDumpWriter]"
"DEBUG","main","06/30/2025","11:46:17","dynamic","extract metadata from [lucee.runtime.dump.ClassicHTMLDumpWriter]"
"DEBUG","main","06/30/2025","11:46:17","dynamic","extract metadata from [lucee.runtime.dump.SimpleHTMLDumpWriter]"
"INFO","main","06/30/2025","11:46:17","startup","Touched monitors"
"INFO","main","06/30/2025","11:46:17","startup","Start CFML Controller"
"INFO","main","06/30/2025","11:46:17","startup","Init factory"
"INFO","main","06/30/2025","11:46:18","startup","Loaded config"
30-Jun-2025 11:46:18.163 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8888"]
30-Jun-2025 11:46:18.210 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [25692] milliseconds
"DEBUG","ControllerThread:1","06/30/2025","11:46:22","lucee.runtime.engine.Controler","Checking size of directory [/opt/lucee/server/lucee-server/context/temp]. Current size [0]. Max size [1073741824]."
"DEBUG","ControllerThread:1","06/30/2025","11:46:22","lucee.runtime.engine.Controler","Checking size of directory [/opt/lucee/server/lucee-server/context/cache]. Current size [0]. Max size [104857600]."
"INFO","Controller","06/30/2025","11:46:32","controller","controller took 5066ms to execute successfully."
Afterwards, here is the Lucee admin showing Redis is not installed, even though it seems to be working…
I can then install Redis (v 3.0.0.51) via the Admin and it will install correctly and show under the installed extensions.
Thoughts?
PS - The redis extension name was changed to imply it only works for Lucee 7+, even though this is the same extension ID we used before the name change. Does that have something to do with this?