I am running a web application (Ruby on rails) in a tomcat(9) container. Most of the setup is default. By default it'll have 10 threads ready to accept requests when Catalina is up. But I found this log in the log
INFO [http-nio-8080-exec-1] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance
If this happens that request will be slow. (I think it will wait for the instance to be loaded) This usually happens when the container is just started but it will also happen when the container runs for a while.
Also when this happens, CPU usage will increase and I think it should be loading application resources.
I cannot find anything on google that matches that message. Although Tomcat is ready to take up to 10 requests (threads), but it looks like some threads are not actually ready (and this unready thread number is random), and when it is hit, it needs to load resources.
Can anyone help? Not sure if it is Tomcat or my application configuration issue.
Update: Can see this warning message if Tomcat has to create new threads. Test case: set minSpareThread="5", usually will see this warning messages for thread 1-5. When I send 10 current requests to the server, I can see thread 6-10 in the log.
01-Feb-2024 07:55:59.410 INFO [http-nio-8080-exec-1] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 07:56:44.305 INFO [http-nio-8080-exec-2] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:30:55.785 INFO [http-nio-8080-exec-1] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.337 INFO [http-nio-8080-exec-1] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.339 INFO [http-nio-8080-exec-2] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.340 INFO [http-nio-8080-exec-6] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.344 INFO [http-nio-8080-exec-7] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.346 INFO [http-nio-8080-exec-8] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.347 INFO [http-nio-8080-exec-9] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance 01-Feb-2024 09:46:21.351 INFO [http-nio-8080-exec-10] org.apache.catalina.core.ApplicationContext.log INFO: pool was empty - getting new application instance
Also another point is if I set minSpareThreads=5, I suppose to see 5 threads in tomcat manager server status? Although tomcat manager shows http-nio-8080 has current thread count:5, but usually only 2 or 3 threads are on the thread table, not 5.