https://issues.apache.org/bugzilla/show_bug.cgi?id=48831
--- Comment #3 from Konstantin Kolinko <knst.koli...@gmail.com> 2010-03-01 09:56:24 UTC --- 1. The two first "Closing FileHandler" messages in catalina.log apparently originate from "catalina.bat stop" run. I added thread.hashCode() to the messages to catch that, but I now see that it can be demonstrated clearly by running the shutdown command with a different logging configuration (e.g. from a separate CATALINA_BASE). 2. The same instance of FileHandler is attached to several Loggers. When calling ClassLoaderLogManager#resetLogger() or LogManager#resetLogger() we have a loop on loggers, each of them closes all handlers that it is attached to. Thus the same handler is closed many times in a row. There may be several consequences to that, but one is a clear bug: - when undeploying a web application org.apache.catalina.loader.WebappClassLoader.clearReferences closes not only web application loggers, but through them also the handler that write to catalina.log and localhost.log and are shared between applications. The above issue can be seen from attached localhost.log. The logger is closed twice (note that an instance of PrintWriter is different each time). It still works because JULI FileHandler#closeWriter() sets FileHandler#date = "", and subsequent call to FileHandler#publish() will check the date value and reopen the logger. There is a certain time span in FileHandler#closeWriter() between nulling this.writer and resetting this.date and thus some messages might be lost in-between. 3. In proposed r910974: note, that Catalina#stop() calls getRuntime().removeShutdownHook(..) In that case I suppose we should call ClassLoaderLogManager.setUseShutdownHook(true); to re-enable ClassLoaderLogManager.shutdown(), or call shutdown() explicitly. I was not able to observe side effects from this issue, because, as seen from the logs, LogManager.Cleaner still runs at shutdown and closes the LogHandler for "catalina.log". Thus, no data loss occurred. But I think there will be circumstances when it'll be observed. It can be seen that in case of "catalina.bat stop" LogManager.Cleaner and ClassLoaderLogManager.Cleaner run in parallel (the first two messages in "catalina.log"). 4. I think that ClassLoaderLogManager#useShutdownHook has to be volatile. Otherwise I think ClassLoaderLogManager.Cleaner thread is likely not to see changes to its value. Though there is no proof. (ClassLoaderLogManager.shutdown() mentioned in the logs is from "catalina.bat stop" run). -- Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug. --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org
