Hi Guys The other day my Windows 2019 VPS suddenly slowed do cfml #lucee

Hi Guys The other day my Windows 2019 VPS suddenl...

Charles Robertson

02/28/2024, 9:30 AM

Hi Guys The other day my Windows 2019 VPS suddenly slowed down, in terms of serving my websites. When I look at the task manger on my sever, Lucee Tomcat was at 98% CPU I restarted Lucee/Tomcat and the CPU usage is now between 0% - 20%. In fact, it is jumping around like a cat on a hot tin roof. My websites are now being served at a normal speed, which is pretty fast. Web pages take milliseconds to load. When I look at commons-daemon.log, it keeps logging the following, every minute:

Copy code

[2024-02-28 09:23:08] [info]  [63148] Service SERVICE_CONTROL_INTERROGATE signalled.

Does anyone know whether this is normal? And if not, does anyone know how to fix this?

Charles Robertson

02/28/2024, 10:09 AM

Having inspected

catalina.logs,

I can see an error that happens every minute as well:

Copy code

28-Feb-2024 01:14:06.526 WARNING [Thread-19008] javax.mail.Session.loadResource expected resource not found: /META-INF/javamail.default.address.map

Charles Robertson

02/28/2024, 10:15 AM

Now, I don’t have a mail client set up, as I just connect directly with my mail provider from

<cfmail>

, but here are my mail settings anyway: And I definitely don’t have any kind of process in my source code or schedule task that sends a mail every minute? As you can see, I haven’t set up a mail provider, although I am wondering whether I should uncheck

spool enable

Charles Robertson

02/28/2024, 10:22 AM

IMG_7198.jpg

bdw429s

02/28/2024, 1:59 PM

That mail warning is totally normal and not an issue

bdw429s

02/28/2024, 1:59 PM

I dont know what the service message means, but its probably unrelated.

bdw429s

02/28/2024, 2:00 PM

Before restarting your server, you should have inspected it with fusion reactor's thread analyzer to look for what threads wete consuming the most CPU.

bdw429s

02/28/2024, 2:01 PM

Or, if you dont have FR, pull some thread dumps from the JVM with jstack.

bdw429s

02/28/2024, 2:02 PM

High overall cpu usage could have been just about anything and there won't necessarily be any logs that tell you what was happening

Charles Robertson

02/28/2024, 2:12 PM

A while back I changed the default setting in:

Copy code

server.xml

In summary, I changed my _server.xml_: From: server.xml

Copy code

<Connector protocol="AJP/1.3"
			port="8009"
			secret="[secret value]"
			secretRequired="true"
			redirectPort="8443"
/>

/lucee/AJP13/BoncodeAJP13.settings

Copy code

<Settings>
  <Port>8009</Port>
  <Server>localhost</Server>   
  <MaxConnections>200</MaxConnections>
  <LogLevel>0</LogLevel>
  <LogDir>c:\temp</LogDir>
  <FlushThreshold>0</FlushThreshold>
  <EnableRemoteAdmin>False</EnableRemoteAdmin>
</Settings>

To: server.xml

Copy code

<Connector 
		protocol="AJP/1.3" 
		port="8009" 
		packetSize="65536" 
		secret="xxx" 
		secretRequired="true" 
		redirectPort="8443" 
		address="::1"
		enableLookups="false"
		keepAliveTimeout="-1"
		maxThreads="4000"
/>

/lucee/AJP13/BoncodeAJP13.settings

Copy code

<Settings>
<Server>::1</Server>
<Port>8009</Port>
<EnableRemoteAdmin>True</EnableRemoteAdmin>
<EnableHeaderDataSupport>True</EnableHeaderDataSupport>
<ModCFMLSecret>xxxx</ModCFMLSecret>
<RequestSecret>xxxx</RequestSecret>
<PacketSize>65536</PacketSize>
<MaxConnections>4000</MaxConnections>
</Settings>

In response to a post at: https://dev.lucee.org/t/performance-issue-with-lucee-ajp-and-iis/13390 I am wondering now, if this had an effect on my server? I am also having problems logging into my server administrator. My web administrator is fine, and once I am logged into the web administrator, I can get to its equivalent section in the server administrator, which is bizarre? I am also getting this error in lucee-stderr.logs:

Copy code

lucee.runtime.exp.RequestTimeoutException: request [/lucee/admin/server.cfm (<zip://C>:\domains\WEB-INF\lucee\context\lucee-admin.lar!/server.cfm)] has run into a timeout (timeout: [50] seconds) and has been stopped. The thread started [56354] ms ago.
	at java.base@11.0.17/java.io.WinNTFileSystem.getBooleanAttributes(Native Method)
	at java.base@11.0.17/java.io.File.isFile(Unknown Source)
	at lucee.commons.io.res.type.file.FileResource.isFile(FileResource.java:589)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1178)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1174)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1186)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1174)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1186)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1174)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1186)
	at lucee.commons.io.res.util.ResourceUtil.getChildCount(ResourceUtil.java:1174)
	at lucee.runtime.tag.Admin.setScopeDirInfo(Admin.java:1250)
	at lucee.runtime.tag.Admin.doGetContexts(Admin.java:1243)
	at lucee.runtime.tag.Admin._doStartTag(Admin.java:817)
	at lucee.runtime.tag.Admin.doStartTag(Admin.java:355)
	at overview_cfm$cf.call(/admin/overview.cfm:283)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1054)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:946)
	at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:927)
	at web_cfm$cf.call(/admin/web.cfm:492)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1054)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:946)
	at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:927)
	at server_cfm$cf.call(/admin/server.cfm:2)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1054)
	at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:946)
	at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:219)
	at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44)
	at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2490)
	at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2476)
	at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2447)
	at lucee.runtime.engine.Request.exe(Request.java:45)
	at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1198)
	at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1144)
	at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
	at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:779)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base@11.0.17/java.lang.Thread.run(Unknown Source)
lucee.runtime.exp.RequestTimeoutException: request [/lucee/admin/server.cfm (<zip://C>:\domains\WEB-INF\lucee\context\lucee-admin.lar!/server.cfm)] has run into a timeout (timeout: [50] seconds) and has been stopped. The thread started [56722] ms ago.
	at java.base@11.0.17/java.io.WinNT28-Feb-2024 12:01:07.922 SEVERE [http-nio-8888-exec-5] org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun Error running socket processor
	java.lang.ThreadDeath
		at java.base/java.lang.Thread.stop(Unknown Source)
		at lucee.commons.io.SystemUtil._stop(SystemUtil.java:1342)
		at lucee.commons.io.SystemUtil.stop(SystemUtil.java:1333)
		at lucee.commons.io.StopThread.run(SystemUtil.java:1755)

Charles Robertson

02/28/2024, 2:14 PM

I used to be able to log into my server administrator without any problem and I think the problem may have started, around the time I changed my server.xml. But I cannot be 100% sure that it happened, at this time?

bdw429s

02/28/2024, 2:19 PM

You've got too much correlation with dubious causation. The login issue which you haven't quite described is likely unrelated to your server.xml which prolly has nothing to do with your report of high cpu.

bdw429s

02/28/2024, 2:20 PM

And the request being timed out, there's no telling if that is related or just a random thing.

bdw429s

02/28/2024, 2:20 PM

Fix one thing at a time. Reset your admin pass if neccessary. And then, if your server is having high cpu, measure it and see what it's doing right then!

👍 1

Charles Robertson

02/29/2024, 4:15 PM

I just thought I'd let you that I have now resolved one of my issues:

Copy code

lucee.runtime.exp.RequestTimeoutException: request [/lucee/admin/server.cfm (<zip://C>:\domains\WEB-INF\lucee\context\lucee-admin.lar!/server.cfm)] has run into a timeout (timeout: [50] seconds) and has been stopped. The thread started [56722] ms ago.

This prevented me from accessing the Lucee Server Admin

overview

section. I managed to increase the request scope timeout from 50s to 5m 50s, and after about 60s, the Lucee Server Admin

overview

section appeared. 🙂 Not sure why it is taking so long to access this one page, but I am just happy to have it working again? Now the only issue, outstanding, is:

Copy code

[2024-02-28 09:23:08] [info]  [63148] Service SERVICE_CONTROL_INTERROGATE signalled.

I have now created an account with FusionReactor and will set up the trial version. Hopefully, this will shine some light on the issue? I did however find this: https://lists.apache.org/thread/hyrnzrqo4zbgh4rltyk1pd7og0mdjy6w The comments indicated that the responder, may have been a Tomcat engineer, who had inadvertently added some code, that was logging stuff at the wrong level?

Copy code

Nothing to worry about. Just some new logging that should probably be 
logging at debug level. I reviewed the associated PR but didn't realize 
the code was called every minute.

I may just upgrade my version of Tomcat?

11 Views

Open in Slack

Previous Next