Log4J Failed to rename [logs/CacheClearance.log] to [logs/CacheClearance.log.2017-08-31].

[gir489]

I'm currently trying to fix an issue a Wildfly 10 integration issue that happens in the morning when the first call to a static class called ClearCache happens. (This was working fine on JBoss 4)

The appender is currently using DailyRollingFileAppender and a simple category for CacheCheck that we send to our Logger static class that calls loggerRepository.getLogger(category).info(message);

I googled the error and arrived here: 29726 – DailyRollingFileAppender : log4j:ERROR Failed to rename

The people writing in the comments proclaim that the use of File.renameTo is the culprit, because of how it works on Windows. (We're on a Windows server, so this kind of makes sense, I guess?)

After more googling, I arrived here: java - Reliable File.renameTo() alternative on Windows? - Stack Overflow

I put a breakpoint on DailyRollingFileAppender right after it calls this.closeFile(); I then tried to verify that the lock was broken on CacheClearence.log, but Windows says that java.exe still has a handle to the file.

I thought there was some inherent handle to the file from some kind of ghost module I wasn't seeing, so I restarted the server, verified the lock was broken, put a BP before I called ClearCache, lock was broken, called Logger.info("ChacheCheck", "Test"); Lock engaged. Stepped after this.closeFile(), lock still engaged.

I have NO idea what's causing this. I tried porting to Log4J 2 to see if that would help, but Log4J 2 doesn't use categories, it goes by strict class enforcement, so I figured out real fast that wasn't going to work from a static Logger class, we'd have to refactor our 500+ Java files to have a static member Logger logger = Logger.getLogger(this.getClass()); Which would be a massive pain to do.

[jaikiran]

Can you paste the entire exception stacktrace? Which exact version of WildFly 10 is this?

[jaikiran]

As to figuring out what is exactly holding locks on the file, maybe this tool will help https://docs.microsoft.com/en-us/sysinternals/downloads/process-explorer

[gir489]

There is no stack track. The error Failed to rename [logs/CacheClearance.log] to [logs/CacheClearance.log.2017-08-31] is all I get in the console.

This is most likely due to the fact that this.closeFile() doesn't throw an exception, and file.renameTo just returns true or file:

                this.closeFile();
                File target = new File(this.scheduledFilename);
                if (target.exists()) {
                    target.delete();
                }
                File file = new File(this.fileName);
                boolean result = file.renameTo(target);
                if (result) {
                    LogLog.debug(this.fileName + " -> " + this.scheduledFilename);
                } else {
                    LogLog.error("Failed to rename [" + this.fileName + "] to [" + this.scheduledFilename + "].");
                }

That's from DailyRollingFileAppender.class.

I've already determined that java.exe was holding a lock on it by stepping through the log code, and finding that once Log.info was called from ClearCache.java, the file was locked. However, I used handle.exe (which is just the command line version of process explorer) to find that java.exe was indeed the only EXE with a handle to the log.

I'm on Wildfly 10.1.0.

[gir489]

I figured it out. We were compartmentalizing multiple Logger repositories (which the Log4J spec says is for internal use only), and I don't even know how this was working on JBoss 4...

Fixed by just calling Logger.getLogger(category) instead of trying to do Log4J's job ourselves.