[
https://issues.apache.org/jira/browse/IGNITE-28870?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Oleg Valuyskiy updated IGNITE-28870:
------------------------------------
Description:
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
>
>
> 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.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
