Why is Tomcat 8.5 reloading context

Question

It seems like since we upgraded tomcat to version 8+ we aways get a context reload on startup. However it only seems to happen in our development environments (windows OS with eclipse and tomcat 8.5). Our production environments (linux OS with tomcat 8.5) do not have this issue. Ill post it below but I do not see any indication of why this is happenign from the tomcat logs. I know this is normally behavior with something in the web apps directory is changed, but for the life of me i cannot figure out what is doing it. There must be some way to track it down though.

This first chunk of log is it fully starting

Feb 18, 2017 9:53:41 AM org.apache.tomcat.util.digester.SetPropertiesRule begin WARNING: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'source' to 'org.eclipse.jst.jee.server:Stackoverflow-commproxy' did not find a matching property. Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Server version: Apache Tomcat/8.5.11 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Server built: Jan 10 2017 21:02:52 UTC Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Server number: 8.5.11.0 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: OS Name: Windows 10 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: OS Version: 10.0 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Architecture: amd64 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Java Home: C:\Program Files\Java\jdk1.8.0_91\jre Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: JVM Version: 1.8.0_91-b14 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: JVM Vendor: Oracle Corporation Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: CATALINA_BASE: C:\CodeRepos\work\EclipseWorkspace.metadata.plugins\org.eclipse.wst.server.core\tmp0 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: CATALINA_HOME: C:\tomcat\apache-tomcat-8.5.11 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcatalina.base=C:\CodeRepos\work\EclipseWorkspace.metadata.plugins\org.eclipse.wst.server.core\tmp0 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dcatalina.home=C:\tomcat\apache-tomcat-8.5.11 Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dwtp.deploy=C:\CodeRepos\work\EclipseWorkspace.metadata.plugins\org.eclipse.wst.server.core\tmp0\wtpwebapps Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Djava.endorsed.dirs=C:\tomcat\apache-tomcat-8.5.11\endorsed Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.VersionLoggerListener log INFO: Command line argument: -Dfile.encoding=Cp1252 Feb 18, 2017 9:53:41 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jdk1.8.0_91\bin;C:\WINDOWS\Sun\Java\bin;C:\WINDOWS\system32;C:\WINDOWS;C:/Program Files/Java/jre1.8.0_121/bin/server;C:/Program Files/Java/jre1.8.0_121/bin;C:/Program Files/Java/jre1.8.0_121/lib/amd64;C:\ProgramData\Oracle\Java\javapath;C:\Python27\;C:\Python27\Scripts;C:\Program Files (x86)\Intel\iCLS Client\;C:\Program Files\Intel\iCLS Client\;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\Intel\Intel(R) Management Engine Components\DAL;C:\Program Files (x86)\Intel\Intel(R) Management Engine Components\DAL;C:\Program Files\Intel\Intel(R) Management Engine Components\IPT;C:\Program Files (x86)\Intel\Intel(R) Management Engine Components\IPT;C:\Program Files (x86)\GtkSharp\2.12\bin;C:\Users\dever.dnx\bin;C:\Program Files\Microsoft DNX\Dnvm\;C:\Program Files\Microsoft SQL Server\120\Tools\Binn\;C:\Program Files (x86)\Windows Kits\10\Windows Performance Toolkit\;c:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn\ManagementStudio\;c:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn\;c:\Program Files\Microsoft SQL Server\110\Tools\Binn\;c:\Program Files (x86)\Microsoft SQL Server\110\DTS\Binn\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Program Files (x86)\Windows Live\Shared;C:\WINDOWS\system32\config\systemprofile.dnx\bin;C:\Program Files\Microsoft SQL Server\130\Tools\Binn\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Microsoft Emulator Manager\1.0\;C:\Program Files\Git\cmd;C:\Program Files\nodejs\;C:\Program Files\Emscripten\emscripten\1.35.0;C:\Program Files\Emscripten;C:\Program Files\Emscripten\clang\e1.35.0_64bit;C:\Program Files\Emscripten\node\0.12.2_64bit;C:\Program Files\Emscripten\python\2.7.5.3_64bit;C:\Program Files\Emscripten\java\7.45_64bit\bin;C:\Program Files\Emscripten\crunch\1.03;C:\Program Files\Emscripten\mingw\4.6.2_32bit;C:\Program Files\TortoiseSVN\bin;C:\JavaProgramFiles\jdk1.8.0_91\bin;C:\Ruby193\bin;C:\program files\apache-maven-3.3.9\bin;c:\Program Files\MongoDB\Server\3.2\bin;C:\JavaProgramFiles\apache-ant-1.9.7\bin;C:\JavaProgramFiles\xmlbeans-1.0.3\bin;C:\Users\dever\AppData\Local\Microsoft\WindowsApps;C:\Users\dever\AppData\Roaming\npm;C:\Program Files\eclipse\jee-neon\eclipse;;. Feb 18, 2017 9:53:41 AM org.apache.coyote.AbstractProtocol init INFO: Initializing ProtocolHandler ["http-nio-8080"] Feb 18, 2017 9:53:41 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector INFO: Using a shared selector for servlet write/read Feb 18, 2017 9:53:41 AM org.apache.coyote.AbstractProtocol init INFO: Initializing ProtocolHandler ["ajp-nio-8009"] Feb 18, 2017 9:53:41 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector INFO: Using a shared selector for servlet write/read Feb 18, 2017 9:53:41 AM org.apache.catalina.startup.Catalina load INFO: Initialization processed in 610 ms Feb 18, 2017 9:53:41 AM org.apache.catalina.core.StandardService startInternal INFO: Starting service Catalina Feb 18, 2017 9:53:41 AM org.apache.catalina.core.StandardEngine startInternal INFO: Starting Servlet Engine: Apache Tomcat/8.5.11 Feb 18, 2017 9:53:44 AM org.apache.jasper.servlet.TldScanner scanJars INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time. Feb 18, 2017 9:53:44 AM org.apache.catalina.core.ApplicationContext log INFO: No Spring WebApplicationInitializer types detected on classpath Feb 18, 2017 9:53:44 AM org.apache.catalina.core.ApplicationContext log INFO: Initializing Spring root WebApplicationContext 2017-02-18 09:53:45.755 [localhost-startStop-1] INFO com.stackoverflow.util.common.AppConfigPostProcessor - Setting system property: org.jboss.logging.provider=slf4j 2017-02-18 09:53:45.757 [localhost-startStop-1] INFO com.stackoverflow.util.common.AppConfigPostProcessor - Setting default timezone to: UTC 2017-02-18 09:53:47.990 [localhost-startStop-1] INFO com.stackoverflow.util.concurrent.ThreadPoolTaskScheduler - Initializing ExecutorService 'taskScheduler' 2017-02-18 09:53:47.997 [localhost-startStop-1] INFO com.stackoverflow.service.commproxy.LoggingServiceImpl - Logging Service: init successfully 2017-02-18 09:53:48.011 [localhost-startStop-1] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: initializing Stackoverflow Device Service... 2017-02-18 09:53:48.314 [localhost-startStop-1] INFO com.stackoverflow.cache.mapdb.MapDBCacheManager - Opened StackoverflowCommProxyCacheV4 MapDB store. File location C:\Users\dever\AppData\Local\Temp\StackoverflowCommProxyCacheV4.DeviceMetaDataCache 2017-02-18 09:53:48.314 [localhost-startStop-1] DEBUG com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: loading local DeviceMetaData cache 2017-02-18 09:53:48.316 [taskScheduler-1] DEBUG com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: starting device pool refresh task Feb 18, 2017 5:53:48 PM org.apache.coyote.AbstractProtocol start INFO: Starting ProtocolHandler [http-nio-8080] Feb 18, 2017 5:53:48 PM org.apache.coyote.AbstractProtocol start INFO: Starting ProtocolHandler [ajp-nio-8009] Feb 18, 2017 5:53:48 PM org.apache.catalina.startup.Catalina start INFO: Server startup in 6928 ms 2017-02-18 09:53:49.774 [taskScheduler-1] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: received list of device metadata with 15 items from Stackoverflow Cloud Services 2017-02-18 09:53:49.775 [taskScheduler-1] DEBUG com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: device metadata cache contains 15 items 2017-02-18 09:53:49.806 [taskScheduler-1] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: performed refresh cycle. Time spent: 1490 ms Feb 18, 2017 5:53:58 PM org.apache.catalina.core.StandardContext reload INFO: Reloading Context with name [/stackoverflow-commproxy] has started

Notice how there is no error and none of the operations which took place would have touched the disk. With a slight exception for logging. Which does log to file however with our settings like this it really shouldnt be touching the web apps directory:

log4j2.xml

    <?xml version="1.0" encoding="UTF-8"?>
<Configuration monitorInterval="180">
    <Properties>
        <!-- change the path to conference logs below to fit your system -->
        <Property name="LOG_DIR">C:\CodeRepos\logs\</Property>

And the rest of the log file:

Feb 18, 2017 5:53:58 PM org.apache.catalina.core.ApplicationContext log INFO: Closing Spring root WebApplicationContext 2017-02-18 09:53:58.514 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: destroying Stackoverflow Device Service... 2017-02-18 09:53:58.543 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.cache.mapdb.MapDBCacheManager - Closed StackoverflowCommProxyCacheV4.DeviceMetaDataCache MapDB store 2017-02-18 09:53:58.545 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.util.concurrent.ThreadPoolTaskScheduler - Shutting down ExecutorService 'taskScheduler' Feb 18, 2017 5:53:58 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads WARNING: The web application [Stackoverflow-commproxy] appears to have started a thread named [Log4j2-Log4j2Scheduled-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093) java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) java.lang.Thread.run(Thread.java:745) Feb 18, 2017 5:54:00 PM org.apache.jasper.servlet.TldScanner scanJars INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time. Feb 18, 2017 5:54:00 PM org.apache.catalina.core.ApplicationContext log INFO: No Spring WebApplicationInitializer types detected on classpath Feb 18, 2017 5:54:00 PM org.apache.catalina.core.ApplicationContext log INFO: Initializing Spring root WebApplicationContext 2017-02-18 17:54:01.637 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.util.common.AppConfigPostProcessor - Setting system property: org.jboss.logging.provider=slf4j 2017-02-18 17:54:01.639 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.util.common.AppConfigPostProcessor - Setting default timezone to: UTC 2017-02-18 17:54:03.732 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.util.concurrent.ThreadPoolTaskScheduler - Initializing ExecutorService 'taskScheduler' 2017-02-18 17:54:03.739 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.service.commproxy.LoggingServiceImpl - Logging Service: init successfully 2017-02-18 17:54:03.751 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: initializing Stackoverflow Device Service... 2017-02-18 17:54:04.024 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] INFO com.stackoverflow.cache.mapdb.MapDBCacheManager - Opened StackoverflowCommProxyCacheV4 MapDB store. File location C:\Users\dever\AppData\Local\Temp\StackoverflowCommProxyCacheV4.DeviceMetaDataCache 2017-02-18 17:54:04.024 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] DEBUG com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: loading local DeviceMetaData cache 2017-02-18 17:54:04.025 [taskScheduler-1] DEBUG com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: starting device pool refresh task Feb 18, 2017 5:54:04 PM org.apache.catalina.core.StandardContext reload INFO: Reloading Context with name [/Stackoverflow-commproxy] is completed 2017-02-18 17:54:04.987 [taskScheduler-1] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: received list of device metadata with 15 items from Stackoverflow Cloud Services 2017-02-18 17:54:04.987 [taskScheduler-1] DEBUG com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: device metadata cache contains 15 items 2017-02-18 17:54:05.020 [taskScheduler-1] INFO com.stackoverflow.service.commproxy.DeviceServiceImpl - Device Service: performed refresh cycle. Time spent: 995

We can see an error regarding some thread that log4j started and couldnt stop but other than that there is no indication of what caused the context reload, and the error regarding log4j is only happening because of the reload.

How can I track down the cause of context reload. We have several projects suffering for this issue some it seems something more global than a specific process or class.

Haven't received any answers so I just wanted to reiterate the fact that Im really looking for my next step in troubleshooting this? Some other log to look at or some way to find out what is triggering the context reload

Answer 1

You may try the following settings:

1. Open your server configuration from Eclipse Servers View
   • then make sure that in this editors Server Options section "Modules auto reload by default" is unchecked
   • also make sure that in that editors Publishing section "Never publish automatically" is selected
2. Open context menu of your server in Eclipse Servers View
   • select "Add and Remove..."
   • in the dialog make sure that "If server is started, publish changes immediately" is unchecked and Finish (you might also have to remove all webapps first and add them again in another step)