Bug 56608 - WatchedResource configured in $TomcatHome\conf\Catalina\localhost context XML file not triggering context reload after working for several days
Summary: WatchedResource configured in $TomcatHome\conf\Catalina\localhost context XML...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 6
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 6.0.39
Hardware: PC All
: P2 normal (vote)
Target Milestone: default
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-06-09 12:36 UTC by remnar
Modified: 2015-03-18 14:51 UTC (History)
0 users



Attachments
Log files for the day the error occurred and context reloading stopped being automatic. Context file for app in question included. (18.01 KB, application/x-zip-compressed)
2014-06-09 12:36 UTC, remnar
Details

Note You need to log in before you can comment on or make changes to this bug.
Description remnar 2014-06-09 12:36:20 UTC
Created attachment 31700 [details]
Log files for the day the error occurred and context reloading stopped being automatic.  Context file for app in question included.

I have set up a context XML file within $TOMCAT_HOME\conf\Catalina\localhost which has a docbase on a network fileshare.  I have set up a WatchedResource for a handful of files on this fileshare so that whenever one of the files is updated, the context is refreshed.  This works fine for sometime, but after a while, I see an error in the logs saying "java.io.IOException: The semaphore timeout period has expired" (Log file with full stack trace is uploaded).

After we notice this error, I had to start the context back via the Tomcat manager (to be expected, since it appears that a short network unavailability caused the issue).  However, once the application is started manually, the WatchedResources being updated no longer force the context to reload.  We have to reload the context manually until we do a full restart of the Tomcat service.
Comment 1 Konstantin Kolinko 2014-06-09 13:48:33 UTC
The error in the log is:
[[[
Jun 5, 2014 4:35:15 PM org.apache.catalina.startup.HostConfig checkResources
WARNING: Error delete redeploy resources from context [/CTIOutreachPrompts]
java.io.IOException: The semaphore timeout period has expired
	at java.io.WinNTFileSystem.canonicalize0(Native Method)
	at java.io.Win32FileSystem.canonicalize(Unknown Source)
	at java.io.File.getCanonicalPath(Unknown Source)
	at java.io.File.getCanonicalFile(Unknown Source)
	at org.apache.catalina.startup.HostConfig.checkResources(HostConfig.java:1246)
	at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1382)
	at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:306)
	at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142)
	at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1389)
	at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1653)
	at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1662)
	at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1642)
	at java.lang.Thread.run(Unknown Source)
]]]

> which has a docbase on a network fileshare.
Comment 2 Mark Thomas 2014-06-18 21:53:26 UTC
Could you provide some more detail please.

Is the context.xml file deleted from $TOMCAT_HOME\conf\Catalina\localhost when the error occurs?

What state is the app shown in in the Manager app (stopped, missing, ???)

What steps do you perform in the Manager app?
Comment 3 Mark Thomas 2014-07-07 16:36:47 UTC
Ping. Without the requested information this is likely to get closed as WORKSFORME.
Comment 4 remnar 2014-07-09 18:17:09 UTC
Sorry, I completely forgot to come back and update this ticket with the information.

The context file was deleted from the $TOMCAT_HOME\conf\Catalina\localhost directory.  We have a job that is scheduled to run every 5 minutes to check whether or not the context file exists, and if not replaces the file in the directory.  After this job ran and replaced the missing file, Tomcat was showing the application as stopped, and I had to manually start the context.  However, if one of the "WatchedResource" files was updated, the context would not refresh.  If I manually did a "Reload", the context would refresh correctly, but the "WatchedResources" would not trigger a refresh until Tomcat was restarted.
Comment 5 Mark Thomas 2014-07-09 18:30:46 UTC
OK. Things are getting clearer. A few more questions.

When you say manually do you mean with the Manager web application?

What caused the file to be deleted in the first place?

When the file was restored was it exactly the same as the old file including timestamps? If it was different, how was it different?

What are you host settings for autoDeploy and deployOnStartup?
Comment 6 remnar 2014-07-09 18:40:12 UTC
> When you say manually do you mean with the Manager web application?
Yes, I used the manager web application


> What caused the file to be deleted in the first place?
I'm honestly not sure on this part.  My assumption was that Tomcat deleted it for some reason once the network path became unavailable (I had seen the file get deleted seemingly randomly before, which is why we have the batch file that replaces the file if it goes missing).


> When the file was restored was it exactly the same as the old file including timestamps? If it was different, how was it different?
The file being restored is exactly the same.  Barring any weirdness in the windows "copy" command, even the timestamps should be the same.

> What are you host settings for autoDeploy and deployOnStartup?
We have left these settings as default.  From the $TOMCAT_HOME\conf\server.xml file for the autoDeploy:
<Host name="localhost"  appBase="webapps"
            unpackWARs="true" autoDeploy="true"
            xmlValidation="false" xmlNamespaceAware="false">

I cannot find the deployOnStartup setting, but if you let me know where it is set, I can show you that value to confirm.
Comment 7 Mark Thomas 2014-07-09 18:51:01 UTC
deployOnStartup will be in server.xml on the Host. It will use the default (true) if not specified.

Thanks for all the information. I think we have enough information to start looking at this.
Comment 8 Mark Thomas 2015-03-04 15:22:35 UTC
Sorry it has taken me a while to get around to looking at this.

I've been able to figure out what is going on. The sequence of events is:

1. Start with everything working
2. Network hosting docBase drops out
3. Tomcat detects this an undeploys the app
   This includes removing context.xml
4. Your script re-adds context.xml
5. Network still not available so Context fails to start. This failure happens
   before watched resources are added to the Context.
6. The network comes back up.
7. Context is re-loaded. (Re0loading does not re-parse context.xml)
8. Context is running without watched resource information

The work-around is to touch the context.xml file to trigger a re-deploy rather than to reload it through the manager.
Comment 9 Mark Thomas 2015-03-04 18:43:50 UTC
Further digging shows my analysis for step 5 is not quite correct. The issue - and it exists all the way up to trunk - is that when adding watched resources, relative resources are skipped if the docBase is not valid.
Comment 10 Mark Thomas 2015-03-05 12:25:08 UTC
Fixed in trunk, 8.0.x (for 8.0.21 onwards) and 7.0.x (for 7.0.60 onwards).

Proposed for 6.0.x.

Note a side effect of fixing this is that it will no longer be necessary to restart the application in the Manager. The newly appeared watched resource (when the network share returns) will trigger a reload which will start the app.
Comment 11 Christopher Schultz 2015-03-05 17:00:02 UTC
I'm excited that you found and fixed a possible multi-reload trigger, because that seems to happen to me with some regularity -- a series of reloads, one after another, and then things settle down. Often, there are enough reloads that I get tired of the applications pauses and just bounce Tomcat.
Comment 12 Mark Thomas 2015-03-18 14:51:13 UTC
Fixed for 6.0.44 onwards.