[ 
https://issues.apache.org/jira/browse/IGNITE-28870?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Oleg Valuyskiy updated IGNITE-28870:
------------------------------------
    Description: 
After the changes introduced in IGNITE-24130 / PR #11896, Ignite may log the 
following ERROR after a snapshot is successfully created:

 
{code:java}
Snapshot directory doesn't exist [snpName=<snapshot_name>, 
dir=<work_dir>/db/<node_storage>/snp]{code}
 

The snapshot itself may be successfully created in the configured snapshot 
directory. The error is logged during cleanup of temporary snapshot files.

Reproducer: [^SnapshotTmpDirCleanupReproducer.patch]
h3. Original cleanup logic

Before IGNITE-24130 / PR #11896, snapshot cleanup used two different temporary 
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}
These two directories represent different filesystem levels:
 * sft.tempFileTree().root() = <work_dir>/db/<node_storage>/snp/<snapshot_name>
 * sft.tempFileTree().nodeStorage() = 
<work_dir>/db/<node_storage>/snp/<snapshot_name>/db/<node_storage>

So the original logic was:
 * remove the node-specific temporary snapshot storage directory;
 * then check the temporary root directory of the current snapshot;
 * if the root directory has no other files left, remove it as well;
 * if snapshot processing finished with an error, remove the temporary root 
directory regardless of its contents.

h3. Regression after IGNITE-24130 / PR #11896

After the data region storage path support changes, the cleanup logic was 
refactored into a helper method:

 
{code:java}
public static void removeTmpSnapshotFiles(SnapshotFileTree sft, boolean err, 
IgniteLogger log) {
    NodeFileTree tmpFt = sft.tempFileTree();
    removeTmpDir(tmpFt.root(), err, log);
    for (File tmpDrStorage : tmpFt.extraStorages().values())
        removeTmpDir(tmpDrStorage.getParentFile(), err, log);
}
{code}
The helper currently 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}
This accidentally collapses the original two-level cleanup logic into a single 
directory. The method now:
 * removes the snapshot temporary root directory;
 * then tries to count files in that same directory;
 * then tries to delete the same directory again.

So after:

 
{code:java}
U.delete(dir);{code}
the following call may fail with NoSuchFileException:

 

 
{code:java}
U.fileCount(dir.toPath()){code}
This results in a false ERROR in the log even though the snapshot temporary 
directory has already been successfully removed.

 
h3. Expected behavior

The cleanup logic should preserve the original two-level semantics:
 * remove the node-specific temporary snapshot storage directory;
 * check the snapshot temporary root directory;
 * remove the root directory if it becomes empty;
 * remove the root directory if snapshot processing finished with an error;
 * do not call U.fileCount(...) on the directory that has just been deleted;
 * do not log an ERROR when the directory has already been removed successfully.

  was:
Title:

False ERROR is logged during snapshot temporary files cleanup

Description:

After the changes introduced in IGNITE-24130 / PR #11896, Ignite may log the 
following ERROR after a snapshot is successfully created:

{code:text}
Snapshot directory doesn't exist [snpName=<snapshot_name>, 
dir=<work_dir>/db/<node_storage>/snp]
{code}

Example:

{code:text}
Snapshot directory doesn't exist [snpName=20260708042126_snapshot, 
dir=/opt/ignite/NVME1/data/cell_03_node_03/snp]
{code}

The snapshot itself may be successfully created in the configured snapshot 
directory. The error is logged during cleanup of temporary snapshot files.

h3. Original cleanup logic

Before IGNITE-24130 / PR #11896, snapshot cleanup used two different temporary 
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}

These two directories represent different filesystem levels.

For example:
h1. {code:text}
sft.tempFileTree().root()

<work_dir>/db/<node_storage>/snp/<snapshot_name>
h1. sft.tempFileTree().nodeStorage()

<work_dir>/db/<node_storage>/snp/<snapshot_name>/db/<node_storage>
{code}

So the original logic was:
 * remove the node-specific temporary snapshot storage directory;

 * then check the temporary root directory of the current snapshot;

 * if the root directory has no other files left, remove it as well;

 * if snapshot processing finished with an error, remove the temporary root 
directory regardless of its contents, because the temporary state of this 
snapshot is considered invalid.

In other words, the original code intentionally worked with two different 
directories:

{code:text}
<snapshot_temp_root>/<snapshot_name> -- root()
└── db/<node_storage> -- nodeStorage()
{code}

h3. Regression after IGNITE-24130 / PR #11896

After the data region storage path support changes, the cleanup logic was 
refactored into a helper method:

{code:java}
public static void removeTmpSnapshotFiles(SnapshotFileTree sft, boolean err, 
IgniteLogger log) {
NodeFileTree tmpFt = sft.tempFileTree();

 

{{removeTmpDir(tmpFt.root(), err, log);

for (File tmpDrStorage : tmpFt.extraStorages().values())
    removeTmpDir(tmpDrStorage.getParentFile(), err, log);}}

}
{code}

The helper currently 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}

This accidentally collapses the original two-level cleanup logic into a single 
directory.

The method now:
 * removes the snapshot temporary root directory;

 * then tries to count files in the same directory;

 * then tries to delete the same directory again.

So after:

{code:java}
U.delete(dir);
{code}

the following call may fail with \{{NoSuchFileException}}:

{code:java}
U.fileCount(dir.toPath())
{code}

This results in a false ERROR in the log even though the snapshot temporary 
directory has already been successfully removed.

h3. Expected behavior

The cleanup logic should preserve the original two-level semantics:
 * remove the node-specific temporary snapshot storage directory;

 * check the snapshot temporary root directory;

 * remove the root directory if it becomes empty;

 * remove the root directory if snapshot processing finished with an error;

 * do not call \{{U.fileCount(...)}} on the directory that has just been 
deleted;

 * do not log an ERROR when the directory has already been removed successfully.

h3. Proposed fix

The helper should accept both directories explicitly:

{code:java}
private static void removeTmpDir(File nodeStorage, File root, boolean err, 
IgniteLogger log) {
U.delete(nodeStorage);

 

{{// Delete snapshot temporary root if no other files exist or snapshot cleanup 
is performed after an error.
try \{
    if (err || U.fileCount(root.toPath()) == 0)
        U.delete(root.toPath());
}
catch (NoSuchFileException ignored) \{
    // Temporary snapshot root has already been removed.
}
catch (IOException e) \{
    log.warning("Failed to clean up snapshot temporary directory " +
        "[snpName=" + root.getName() + ", dir=" + root + ']', e);
}}}

}
{code}

And the cleanup should pass both the node-specific storage and the 
corresponding root:

{code:java}
public static void removeTmpSnapshotFiles(SnapshotFileTree sft, boolean err, 
IgniteLogger log) {
NodeFileTree tmpFt = sft.tempFileTree();

 

{{removeTmpDir(tmpFt.nodeStorage(), tmpFt.root(), err, log);

for (File tmpDrStorage : tmpFt.extraStorages().values())
    removeTmpDir(tmpDrStorage, tmpDrStorage.getParentFile(), err, log);}}

}
{code}

h3. Why the \{{err}} flag should be kept

The \{{err}} flag was meaningful in the original cleanup logic.

It should not be used to delete a common directory shared by unrelated 
snapshots. However, in this case \{{root}} is the temporary root of the current 
snapshot operation:

{code:text}
<work_dir>/db/<node_storage>/snp/<snapshot_name>
{code}

Therefore, if the current snapshot operation fails, the temporary root 
directory of this snapshot may contain incomplete or invalid temporary files. 
In that case it is reasonable to remove it regardless of whether it is empty.

So the intended behavior is:
 * on success: delete \{{root}} only if it is empty after \{{nodeStorage}} has 
been removed;

 * on error: delete \{{root}} regardless of its contents.

The condition should also check \{{err}} first:

{code:java}
if (err || U.fileCount(root.toPath()) == 0)
{code}

This avoids calling \{{U.fileCount(...)}} when the root directory should be 
removed anyway due to an error.

h3. Test

A regression test can reproduce the issue as follows:
 * start a persistent node;

 * create a snapshot;

 * register a log listener for:

{code:text}
Snapshot directory doesn't exist [snpName=<snapshot_name>
{code}
 * verify that the snapshot is created successfully;

 * verify that the false cleanup ERROR is not logged.

The test should also validate that the temporary snapshot root cleanup follows 
the intended behavior:
 * node-specific temporary storage is removed;

 * snapshot temporary root is removed when it becomes empty;

 * cleanup does not try to count files in a directory that has already been 
deleted.

h3. Impact

This issue does not necessarily indicate snapshot creation failure. The 
snapshot may be created successfully in the configured snapshot directory.

However, the false ERROR is misleading for users and operators because it 
suggests that a snapshot directory is missing, while in reality the message is 
produced by the cleanup code after the temporary directory has already been 
removed.


> 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
>         Attachments: SnapshotTmpDirCleanupReproducer.patch
>
>
> After the changes introduced in IGNITE-24130 / PR #11896, Ignite may log the 
> following ERROR after a snapshot is successfully created:
>  
> {code:java}
> Snapshot directory doesn't exist [snpName=<snapshot_name>, 
> dir=<work_dir>/db/<node_storage>/snp]{code}
>  
> The snapshot itself may be successfully created in the configured snapshot 
> directory. The error is logged during cleanup of temporary snapshot files.
> Reproducer: [^SnapshotTmpDirCleanupReproducer.patch]
> h3. Original cleanup logic
> Before IGNITE-24130 / PR #11896, snapshot cleanup used two different 
> temporary 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}
> These two directories represent different filesystem levels:
>  * sft.tempFileTree().root() = 
> <work_dir>/db/<node_storage>/snp/<snapshot_name>
>  * sft.tempFileTree().nodeStorage() = 
> <work_dir>/db/<node_storage>/snp/<snapshot_name>/db/<node_storage>
> So the original logic was:
>  * remove the node-specific temporary snapshot storage directory;
>  * then check the temporary root directory of the current snapshot;
>  * if the root directory has no other files left, remove it as well;
>  * if snapshot processing finished with an error, remove the temporary root 
> directory regardless of its contents.
> h3. Regression after IGNITE-24130 / PR #11896
> After the data region storage path support changes, the cleanup logic was 
> refactored into a helper method:
>  
> {code:java}
> public static void removeTmpSnapshotFiles(SnapshotFileTree sft, boolean err, 
> IgniteLogger log) {
>     NodeFileTree tmpFt = sft.tempFileTree();
>     removeTmpDir(tmpFt.root(), err, log);
>     for (File tmpDrStorage : tmpFt.extraStorages().values())
>         removeTmpDir(tmpDrStorage.getParentFile(), err, log);
> }
> {code}
> The helper currently 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}
> This accidentally collapses the original two-level cleanup logic into a 
> single directory. The method now:
>  * removes the snapshot temporary root directory;
>  * then tries to count files in that same directory;
>  * then tries to delete the same directory again.
> So after:
>  
> {code:java}
> U.delete(dir);{code}
> the following call may fail with NoSuchFileException:
>  
>  
> {code:java}
> U.fileCount(dir.toPath()){code}
> This results in a false ERROR in the log even though the snapshot temporary 
> directory has already been successfully removed.
>  
> h3. Expected behavior
> The cleanup logic should preserve the original two-level semantics:
>  * remove the node-specific temporary snapshot storage directory;
>  * check the snapshot temporary root directory;
>  * remove the root directory if it becomes empty;
>  * remove the root directory if snapshot processing finished with an error;
>  * do not call U.fileCount(...) on the directory that has just been deleted;
>  * do not log an ERROR when the directory has already been removed 
> successfully.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

Reply via email to