[jboss-jira] [JBoss JIRA] (LOGMGR-256) Failure to rotate logfile on Windows system because of already open file lock

Failure to rotate logfile on Windows system because of already open file lock ----------------------------------------------------------------------------- Key: LOGMGR-256 URL: https://issues.jboss.org/browse/LOGMGR-256 Project: JBoss Log Manager Issue Type: Bug Affects Versions: 2.1.13.Final Reporter: Patrick Colbaut Assignee: James Perkins Priority: Major Fix For: 1.5.10.Final, 2.0.12.Final, 2.1.14.Final, 2.2.0.Final, 3.0.0.Final I've run into a similar error to the one described in LOGMGR-154, using the jboss-logmanager 2.1.13.Final release on a system that's still running Windows 7. Of note: The server.log file is configured to be rotated on boot. {code:java} LogManager error of type GENERIC_FAILURE: Failed to move file C:\wildfly\standalone\log\server.log to C:\wildfly\standalone\log\server.log.1. java.nio.file.FileSystemException: C:\wildfly\standalone\log\server.log -> C:\wildfly\standalone\log\server.log.1: The process cannot access the file because it is being used by another process. at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86) at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97) at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:387) at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287) at java.nio.file.Files.move(Files.java:1395) at org.jboss.logmanager.handlers.SuffixRotator.move(SuffixRotator.java:246) at org.jboss.logmanager.handlers.SuffixRotator.rotate(SuffixRotator.java:174) at org.jboss.logmanager.handlers.SuffixRotator.rotate(SuffixRotator.java:233) at org.jboss.logmanager.handlers.SuffixRotator.rotate(SuffixRotator.java:193) at org.jboss.logmanager.handlers.SizeRotatingFileHandler.setFile(SizeRotatingFileHandler.java:142) at org.jboss.logmanager.handlers.FileHandler.setFileName(FileHandler.java:189) at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.applyPostCreate(AbstractPropertyConfiguration.java:217) at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.applyPostCreate(AbstractPropertyConfiguration.java:197) at org.jboss.logmanager.config.LogContextConfigurationImpl.doApplyPostCreate(LogContextConfigurationImpl.java:313) at org.jboss.logmanager.config.LogContextConfigurationImpl.doPrepare(LogContextConfigurationImpl.java:345) at org.jboss.logmanager.config.LogContextConfigurationImpl.prepare(LogContextConfigurationImpl.java:289) at org.jboss.as.logging.logmanager.ConfigurationPersistence.prepare(ConfigurationPersistence.java:299) at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler.execute(LoggingOperations.java:106) at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:999) at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:743) at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467) at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1411) at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:521) at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:472) at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:434) at org.jboss.as.server.ServerService.boot(ServerService.java:435) at org.jboss.as.server.ServerService.boot(ServerService.java:394) at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:374) at java.lang.Thread.run(Thread.java:748){code} A similar error will also occur if a compression suffix is used, although it will be the Files.delete(File) instead the Files.move(File, File) call which will fail. Debugging shows that SizeRotatingFileHandler.setFileName(String) is called once immediately during server boot (initialization via logging.properties) and again a short time after (via the logging subsystem I'm guessing). This second call results in the error above, because the SizeRotatingFileHandler instance already holds a file lock via its outputStream field, but a rotation is still attempted, as the file should rotate on boot and already contains content at that point in time. To confirm whether this process internal file lock is responsible, I additionally checked for other processes that might own such a handle. The only listed one is the Java process running Wildfly. As far as I can tell, this kind of error case should be easily fixed by adding an additional setFileInternal(null) call to clean up the open lock before actually triggering the rotation, as seen in this snippet: {code:java} public void setFile(final File file) throws FileNotFoundException { synchronized (outputLock) { // Check for a rotate if (rotateOnBoot && maxBackupIndex > 0 && file != null && file.exists() && file.length() > 0L) { setFileInternal(null); suffixRotator.rotate(getErrorManager(), file.toPath(), maxBackupIndex); } setFileInternal(file); } } {code} Manually adding the above mentioned call seems to allow everything to work as intended. And while the fact that the second setting of the same file name triggers an additional log file rotation (as rotateOnBoot = true in the used configuration) slightly annoys me, that's probably a problem for a different followup bug.