[
https://issues.apache.org/jira/browse/IGNITE-28870?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Oleg Valuyskiy updated IGNITE-28870:
------------------------------------
Description:
h3. Problem
After a snapshot is successfully created, Ignite may log the following ERROR
during snapshot temporary directory cleanup:
{code:java}
Snapshot directory doesn't exist [snpName=<snapshot_name>,
dir=<work_dir>/db/<consistent_id>/snp]{code}
At the same time, the snapshot itself is successfully created in the configured
snapshot directory.
The error is misleading because it is logged after the snapshot has already
been successfully created and the temporary snapshot directory has already been
removed.
h3. Root cause
Before the changes introduced as part of {*}IGNITE-24130 / PR #11896{*},
snapshot cleanup logic used two different directories:
{code:java}
U.delete(sft.tempFileTree().nodeStorage());
// Delete snapshot directory if no other files exists.
try {
if (U.fileCount(sft.tempFileTree().root().toPath()) == 0 || err != null)
U.delete(sft.tempFileTree().root().toPath());
}
catch (IOException e) {
log.error("Snapshot directory doesn't exist [snpName=" + snpName + ", dir="
+ sft.tempFileTree().root() + ']');
}
{code}
The original logic was:
* delete the temporary directory of the current snapshot operation:
*sft.tempFileTree().nodeStorage()*
* then check the parent temporary snapshot root: *sft.tempFileTree().root()*
* if the parent temporary root has no other files/directories, delete it as
well
So the cleanup logic relied on two different filesystem levels:
{code:java}
<work_dir>/db/<consistent_id>/snp
└── <snapshot_name>{code}
Where:
* nodeStorage() pointed to the temporary directory of the current snapshot
* root() pointed to the parent temporary root directory that may contain
temporary directories of other snapshots
After the refactoring, this logic was extracted into a helper method that
receives only one directory:
{code:java}
private static void removeTmpDir(File dir, boolean err, IgniteLogger log) {
U.delete(dir);
// Delete snapshot directory if no other files exists.
try {
if (U.fileCount(dir.toPath()) == 0 || err)
U.delete(dir.toPath());
}
catch (IOException e) {
log.error("Snapshot directory doesn't exist [snpName=" + dir.getName()
+ ", dir=" + dir.getParentFile() + ']');
}
}
{code}
As a result, the same directory is used both as:
* the directory to delete
* the directory to inspect with U.fileCount(...);
* the directory to delete again
This breaks the original two-level cleanup logic. The method first deletes the
temporary snapshot directory:
{code:java}
U.delete(dir);{code}
Then it tries to count files in the same already deleted directory:
{code:java}
U.fileCount(dir.toPath()){code}
If the directory was successfully removed, U.fileCount(...) throws
{*}NoSuchFileException{*}, and Ignite logs an ERROR even though cleanup has
actually succeeded.
h3. Why err should not be used in the new helper
The current snapshot temporary directory is already deleted unconditionally:
{code:java}
U.delete(dir);{code}
Therefore, *err* is not needed to decide whether to remove the current snapshot
temporary directory.
Using *err* to delete the parent root directory seems to be questionable. The
error belongs to the current snapshot operation, while the parent temporary
root may contain other temporary snapshot directories. Therefore, the parent
root should only be removed when it becomes empty, not because the current
snapshot operation has failed.
h3. Expected behavior
Snapshot cleanup should:
* always delete the temporary directory of the current snapshot operation
* delete the parent temporary snapshot root only if it becomes empty after that
* not log ERROR if the temporary snapshot directory has already been
successfully removed
* not delete the parent temporary root just because the current snapshot
operation finished with an error
was:
h3. Problem
After a snapshot is successfully created, Ignite may log the following ERROR
during snapshot temporary directory cleanup:
{code:java}
Snapshot directory doesn't exist [snpName=<snapshot_name>,
dir=<work_dir>/db/<consistent_id>/snp]{code}
At the same time, the snapshot itself is successfully created in the configured
snapshot directory.
The error is misleading because it is logged after the snapshot has already
been successfully created and the temporary snapshot directory has already been
removed.
h3. Root cause
Before the changes introduced as part of {*}IGNITE-24130 / PR #11896{*},
snapshot cleanup logic used two different directories:
{code:java}
U.delete(sft.tempFileTree().nodeStorage());
// Delete snapshot directory if no other files exists.
try {
if (U.fileCount(sft.tempFileTree().root().toPath()) == 0 || err != null)
U.delete(sft.tempFileTree().root().toPath());
}
catch (IOException e) {
log.error("Snapshot directory doesn't exist [snpName=" + snpName + ", dir="
+ sft.tempFileTree().root() + ']');
}
{code}
The original logic was:
* delete the temporary directory of the current snapshot operation:
*sft.tempFileTree().nodeStorage()*
* then check the parent temporary snapshot root: *sft.tempFileTree().root()*
* if the parent temporary root has no other files/directories, delete it as
well
So the cleanup logic relied on two different filesystem levels:
{code:java}
<work_dir>/db/<consistent_id>/snp
└── <snapshot_name>{code}
Where:
* nodeStorage() pointed to the temporary directory of the current snapshot
* root() pointed to the parent temporary root directory that may contain
temporary directories of other snapshots
After the refactoring, this logic was extracted into a helper method that
receives only one directory:
{code:java}
private static void removeTmpDir(File dir, boolean err, IgniteLogger log) {
U.delete(dir);
// Delete snapshot directory if no other files exists.
try {
if (U.fileCount(dir.toPath()) == 0 || err)
U.delete(dir.toPath());
}
catch (IOException e) {
log.error("Snapshot directory doesn't exist [snpName=" + dir.getName()
+ ", dir=" + dir.getParentFile() + ']');
}
}
{code}
As a result, the same directory is used both as:
* the directory to delete
* the directory to inspect with U.fileCount(...);
* the directory to delete again
This breaks the original two-level cleanup logic. The method first deletes the
temporary snapshot directory:
{code:java}
U.delete(dir);{code}
Then it tries to count files in the same already deleted directory:
{code:java}
U.fileCount(dir.toPath()){code}
If the directory was successfully removed, U.fileCount(...) throws
{*}NoSuchFileException{*}, and Ignite logs an ERROR even though cleanup has
actually succeeded.
h3. Why err should not be used in the new helper
The current snapshot temporary directory is already deleted unconditionally:
{code:java}
U.delete(dir);{code}
Therefore, *err* is not needed to decide whether to remove the current snapshot
temporary directory.
Using *err* to delete the parent root directory seems to be questionable. The
error belongs to the current snapshot operation, while the parent temporary
root may contain other temporary snapshot directories. Therefore, the parent
root should only be removed when it becomes empty, not because the current
snapshot operation has failed.
Expected behavior
Snapshot cleanup should:
* always delete the temporary directory of the current snapshot operation;
* delete the parent temporary snapshot root only if it becomes empty after that;
* not log ERROR if the temporary snapshot directory has already been
successfully removed;
* not delete the parent temporary root just because the current snapshot
operation finished with an error.
h3. Proposed fix
The cleanup logic should restore the original two-level behavior:
{code:java}
private static void removeTmpDir(File dir, IgniteLogger log) {
File root = dir.getParentFile();
```
U.delete(dir);
// Delete snapshot temporary root if no other snapshot temporary directories
exist.
try {
if (root != null && U.fileCount(root.toPath()) == 0)
U.delete(root.toPath());
}
catch (NoSuchFileException ignored) {
// Temporary root has already been removed.
}
catch (IOException e) {
log.warning("Failed to clean up snapshot temporary root directory " +
"[snpName=" + dir.getName() + ", dir=" + root + ']', e);
}
```
}
{code}
The \{{err}} parameter can be removed from this helper because the current
snapshot temporary directory is deleted unconditionally, and the parent
temporary root should only be removed if it is empty.
h3. Test
Add a regression test that creates a snapshot successfully and verifies that no
false cleanup ERROR is logged.
Example scenario:
* start a single-node persistent cluster;
* create and check a snapshot;
* register a log listener for:
{code:text}
Snapshot directory doesn't exist [snpName=<snapshot_name>
{code}
* assert that the listener is not triggered.
The test should also cover the cleanup contract:
* the temporary directory of the current snapshot is removed;
* the parent \{{snp}} directory is removed only if it is empty.
h3. Impact
The issue does not necessarily mean that snapshot creation has failed. The
snapshot may be created successfully in the configured snapshot directory.
However, the false ERROR is confusing for users and operators, especially in
production environments, because it suggests that the snapshot directory is
missing even though the failure happens only during temporary directory cleanup
after successful snapshot creation.
> False ERROR is logged during snapshot temporary directory cleanup
> -----------------------------------------------------------------
>
> Key: IGNITE-28870
> URL: https://issues.apache.org/jira/browse/IGNITE-28870
> Project: Ignite
> Issue Type: Bug
> Reporter: Oleg Valuyskiy
> Assignee: Oleg Valuyskiy
> Priority: Minor
> Labels: ise
>
> h3. Problem
> After a snapshot is successfully created, Ignite may log the following ERROR
> during snapshot temporary directory cleanup:
> {code:java}
> Snapshot directory doesn't exist [snpName=<snapshot_name>,
> dir=<work_dir>/db/<consistent_id>/snp]{code}
> At the same time, the snapshot itself is successfully created in the
> configured snapshot directory.
> The error is misleading because it is logged after the snapshot has already
> been successfully created and the temporary snapshot directory has already
> been removed.
> h3. Root cause
> Before the changes introduced as part of {*}IGNITE-24130 / PR #11896{*},
> snapshot cleanup logic used two different directories:
> {code:java}
> U.delete(sft.tempFileTree().nodeStorage());
> // Delete snapshot directory if no other files exists.
> try {
> if (U.fileCount(sft.tempFileTree().root().toPath()) == 0 || err != null)
> U.delete(sft.tempFileTree().root().toPath());
> }
> catch (IOException e) {
> log.error("Snapshot directory doesn't exist [snpName=" + snpName + ",
> dir=" + sft.tempFileTree().root() + ']');
> }
> {code}
> The original logic was:
> * delete the temporary directory of the current snapshot operation:
> *sft.tempFileTree().nodeStorage()*
> * then check the parent temporary snapshot root: *sft.tempFileTree().root()*
> * if the parent temporary root has no other files/directories, delete it as
> well
> So the cleanup logic relied on two different filesystem levels:
> {code:java}
> <work_dir>/db/<consistent_id>/snp
> └── <snapshot_name>{code}
> Where:
> * nodeStorage() pointed to the temporary directory of the current snapshot
> * root() pointed to the parent temporary root directory that may contain
> temporary directories of other snapshots
> After the refactoring, this logic was extracted into a helper method that
> receives only one directory:
> {code:java}
> private static void removeTmpDir(File dir, boolean err, IgniteLogger log) {
> U.delete(dir);
> // Delete snapshot directory if no other files exists.
> try {
> if (U.fileCount(dir.toPath()) == 0 || err)
> U.delete(dir.toPath());
> }
> catch (IOException e) {
> log.error("Snapshot directory doesn't exist [snpName=" +
> dir.getName() + ", dir=" + dir.getParentFile() + ']');
> }
> }
> {code}
> As a result, the same directory is used both as:
> * the directory to delete
> * the directory to inspect with U.fileCount(...);
> * the directory to delete again
> This breaks the original two-level cleanup logic. The method first deletes
> the temporary snapshot directory:
> {code:java}
> U.delete(dir);{code}
> Then it tries to count files in the same already deleted directory:
> {code:java}
> U.fileCount(dir.toPath()){code}
> If the directory was successfully removed, U.fileCount(...) throws
> {*}NoSuchFileException{*}, and Ignite logs an ERROR even though cleanup has
> actually succeeded.
> h3. Why err should not be used in the new helper
> The current snapshot temporary directory is already deleted unconditionally:
> {code:java}
> U.delete(dir);{code}
> Therefore, *err* is not needed to decide whether to remove the current
> snapshot temporary directory.
> Using *err* to delete the parent root directory seems to be questionable. The
> error belongs to the current snapshot operation, while the parent temporary
> root may contain other temporary snapshot directories. Therefore, the parent
> root should only be removed when it becomes empty, not because the current
> snapshot operation has failed.
> h3. Expected behavior
> Snapshot cleanup should:
> * always delete the temporary directory of the current snapshot operation
> * delete the parent temporary snapshot root only if it becomes empty after
> that
> * not log ERROR if the temporary snapshot directory has already been
> successfully removed
> * not delete the parent temporary root just because the current snapshot
> operation finished with an error
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
