We’re seeing
"INFO","Controller","06/25/2025","20:07:07","controller","controller took 28481ms to execute successfully."
every few hours in the combined application log.
I’m fairly sure we don’t have an application named “controller”.
Where is this coming from, and what does it mean ? Is it trying to report slow Application onApplicationStart() or something ?
We’re running almost exactly the stock version of the lucee/lucee:6.2.1.122-nginx Docker image.
BTW It’s not an error, it’s INFO.
The controler is the background thread which does a range of maintenance at a range of intervals, 1m, 5m, 1h
Are all the controller logs taking that long?
If it’s a background process I think Something Is Up, because it’s recording errors related to our own code, but doesn’t say which site it is … ex:
"ERROR","http-nio-8888-exec-17","06/26/2025","08:15:25","controller","key [USER] doesn't exist;lucee.runtime.exp.ExpressionException: key [USER] doesn't exist
at lucee.runtime.type.util.StructSupport.invalidKey(StructSupport.java:70)
at lucee.runtime.type.StructImpl.get(StructImpl.java:184)
at lucee.runtime.type.scope.storage.StorageScopeImpl.get(StorageScopeImpl.java:248)
at xxxx.yyyy.index_cfm$cf.call(/xxxx/yyyy/index.cfm:53)
I can’t tell you what code is on line 53 because it could be in any number of sites and the message only referrs to the web path, and doesn’t include an application name.
We also see time outs related to caches, but, again, doesn’t say what site or path (and “controller” is typoed):
"ERROR","Controller","06/26/2025","08:43:59","controler","was not able to stop controller thread running for 185289ms;java.lang.Throwable;java.lang.Throwable
at java.base/java.io.UnixFileSystem.getLastModifiedTime0(Native Method)
at java.base/java.io.UnixFileSystem.getLastModifiedTime(Unknown Source)
at java.base/java.io.File.lastModified(Unknown Source)
at lucee.commons.io.res.type.file.FileResource.lastModified(FileResource.java:679)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1398)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1407)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1407)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1407)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1407)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1407)
at lucee.commons.io.res.util.ResourceUtil.deleteFileOlderThan(ResourceUtil.java:1407)
at lucee.transformer.dynamic.DynamicClassLoader.cleanup(DynamicClassLoader.java:311)
at lucee.transformer.dynamic.DynamicInvoker.cleanup(DynamicInvoker.java:383)
how many files do you have under lucee-server\context\dynclasses ?
https://luceeserver.atlassian.net/browse/LDEV-5668
still reviewing the first error
544 files on one instance, 484 the other, based on find /opt/lucee/server/lucee-server/context/dynclasses -type f | wc -l
ok so I think that’s more of a side effect of other processes running slow, than that being the issue, as it’s the last step in the controller process.
Let’s shave this yak!
Regarding the first error, I believe that’s a client scope error. that’s all you have in the logs, there’s not more to the stacktrace than you shared?
Do you use onSessionEnd / onApplicationEnd ?
It’s hard to say, because we have several applications with a file that matches that path and it doesn’t say which 
We don’t have onXxxEnd() in general though, so probably not that…
We will be setting this.clientManagement = "No" ; in almost all the cases.
Maybe whatever controler.java is doing here is trying to load or render a page ? I don’t know why that would be happening.
Or could it even be miss-reporting the application name (this.name = "#cgi.SERVER_NAME# hub";) ?!? Because the stack trace looks much like a legitimate request ?
Here’s the full stack trace for the “key [USER]” error. It appears a few seconds after a few normal log messages from our app saying it was starting up, but this could be co-incidence.
If I had to guess, the line of code is <td>#session.user.fname# #session.user.sname#</td>, but we do the standard dance in onRequestStart to bounce to the login page, and our users can login fine.
if( not isDefined("session.loggedin") ){
session.originalPage=arguments.targetPage&'?'&CGI.QUERY_STRING;
try{
location url="/website/management/login.cfm";
}catch(any e){
// response buffer already flushed e.g. when migrations output
writeOutput("<script>window.location='/website/management/login.cfm'</script>")
}
return true;
}
With the login process ending with
<cfif ok>
<cfset session.loggedin = true/>
<cfset session.user = result.data.user/>
so you can’t get a loggedin without user
"ERROR","http-nio-8888-exec-17","06/26/2025","08:15:25","controller","key [USER] doesn't exist;lucee.runtime.exp.ExpressionException: key [USER] doesn't exist
at lucee.runtime.type.util.StructSupport.invalidKey(StructSupport.java:70)
at lucee.runtime.type.StructImpl.get(StructImpl.java:184)
at lucee.runtime.type.scope.storage.StorageScopeImpl.get(StorageScopeImpl.java:248)
at website.management.index_cfm$cf.call(/website/management/index.cfm:53)
at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1112)
at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1006)
at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:213)
at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:41)
at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2810)
at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2797)
at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2768)
at lucee.runtime.engine.Request.exe(Request.java:45)
at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1109)
at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1066)
at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
at lucee.loader.servlet.jakarta.CFMLServlet.service(CFMLServlet.java:52)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:710)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:130)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:109)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:79)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:116)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:718)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:396)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:903)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1744)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:59)
at java.base/java.lang.Thread.run(Unknown Source)
I think that’s just a plain old normal exception?
it’s just a bug that it seems all the errors are being logged with "controller"
If so, I’d really like to see that fixed for 6.2 because otherwise tracking down exceptions in multi-site using single mode is going to be impossible, and I also worry about what else might be miss-filed.