Fix FileRenameAction when the source file doesn't exist

[king-tyler]

Fixes #2592
Fixes FileRenameAction when the source file doesn't exist.

Checklist

• Base your changes on 2.x branch if you are targeting Log4j 2; use main otherwise
• ./mvnw verify succeeds (if it fails due to code formatting issues reported by Spotless, simply run ./mvnw spotless:apply and retry)
• Non-trivial changes contain an entry file in the src/changelog/.2.x.x directory
• Tests for the changes are provided
• Commits are signed (optional, but highly recommended)

[github-actions]

Job	Requested goals	Build Tool Version	Build Outcome	Build Scan®
build-macos-latest	clean install	3.9.8	✅
build-ubuntu-latest	clean install	3.9.8	✅
build-windows-latest	clean install	3.9.8	✅

Generated by gradle/develocity-actions

[vy]

[@king-tyler, I am leaving this to @ppkarwasz, since he was the one who took care of #2952. Piotr will be back in a day or two.]

[ppkarwasz]

Hi @king-tyler and thank you for your contribution.

The FileRenameAction is one of the principal actions that is executed during a rollover. Personally I find it underspecified (what constitutes a success?) and overengineered (mixture of File methods and NIO). Could we try to simplify it?

IMHO the main purpose of the action is to leave space for a new log file and the action should not destroy data, so the logic could be:

1. If source does not exist, the action succeeds. This is your main point if I understand correctly.
2. If destination exists, the action fails: we do not want to destroy data due to bugs in the rolling file appenders.
3. If the parent directory is not null, call FileUtils.mkdir(), which should already handle edge cases like LOG4J2-3452: Fix race condition in FileUtils.mkdir() #809.
4. Call Files.move (or Files.delete if the file is empty) once. The ATOMIC_MOVE option does not seem necessary, since Java NIO will try to use an atomic method call if possible anyway.
5. That is all.

The current code goes on with some other techniques like "copy/delete".
"Copy/delete" is unreliable (can cause log event loss) if some (other) application writes to source, while the copy is made.
I don't think "copy/delete" is necessary in Log4j, because:

• on Windows "copy/delete" might be necessary if source is already opened without the FILE_SHARE_DELETE flag. That should not happen or at least the user should be aware that multiple apps are writing to the same file.
• on UNIX "copy/delete" might be necessary if the user has write permission to source and destination, but not the directory containing them. In this case "delete" will probably fail anyway.

@rgoers, @vy, what do you think?

[king-tyler]

2. If destination exists, the action fails: we do not want to destroy data due to bugs in the rolling file appenders.

The current implementation uses StandardCopyOptions.REPLACE_EXISTING: FileRenameAction.java#L209. It doesn't fail if the destination exists, and it does overwrite the the destination if it exists. I think this (along with your point 4) should be tracked in a separate issue and separate pull request.

The problem in #2592 is that if FileNameAction returns false (i.e., fails) during a rollover, then the appender stops logging to any file. Perhaps the issue should be resolved differently than this PR? Maybe the RollingFileManager essentially aborts the rollover and continues logging to the existing file if FileNameAction fails.

[ppkarwasz]

The problem in #2592 is that if FileNameAction returns false (i.e., fails) during a rollover, then the appender stops logging to any file. Perhaps the issue should be resolved differently than this PR? Maybe the RollingFileManager essentially aborts the rollover and continues logging to the existing file if FileNameAction fails.

Yes, I believe that the manager should reopen the log file regardless of the result of the FileRenameAction.
Looking at the source code:

logging-log4j2/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java

Lines 507 to 514 in f90dee8

	if (rollover(rolloverStrategy)) {
	try {
	size = 0;
	initialTime = System.currentTimeMillis();
	createFileAfterRollover();
	} catch (final IOException e) {
	logError("Failed to create file after rollover", e);
	}

logging-log4j2/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rolling/RollingFileManager.java

Lines 617 to 646 in f90dee8

	boolean success = true;
	try {
	final RolloverDescription descriptor = strategy.rollover(this);
	if (descriptor != null) {
	writeFooter();
	closeOutputStream();
	if (descriptor.getSynchronous() != null) {
	LOGGER.debug("RollingFileManager executing synchronous {}", descriptor.getSynchronous());
	try {
	success = descriptor.getSynchronous().execute();
	} catch (final Exception ex) {
	success = false;
	logError("Caught error in synchronous task", ex);
	}
	}
	if (success && descriptor.getAsynchronous() != null) {
	LOGGER.debug("RollingFileManager executing async {}", descriptor.getAsynchronous());
	asyncExecutor.execute(new AsyncAction(descriptor.getAsynchronous(), this));
	releaseRequired = false;
	}
	return success;
	}
	return false;
	} finally {
	if (releaseRequired) {
	semaphore.release();
	}
	}

The problem described in #2592 is on line 639, where the wrong variable is returned. There are two pairs of actions that must be executed one after another:

1. If closeOutputStream() on line 623 is executed, then createFileAfterRollover() on line 511 must be executed. This should happen regardless of the result of other actions including the result of the closeOutputStream() action itself. As man close(2) explains:

   Note, however, that a failure return should be used only for diagnostic purposes (i.e., a warning to the application that there may still be I/O pending or there may have been failed I/O) or remedial purposes (e.g., writing the file once more creating a backup).

   Since we can not write the log file once more if close() fails, we only can warn the user and reopen the file.

2. If the synchronous action (moving the file) on line 627 is successful, then the asynchronous action (compressing the file if necessary) on line 636 should be executed.

[ppkarwasz]

@king-tyler,

Do you plan some changes in this PR or should I close it in favor of #3226?

[king-tyler]

@king-tyler,

Do you plan some changes in this PR or should I close it in favor of #3226?

This one can be closed