[
https://issues.apache.org/jira/browse/HBASE-21387?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ted Yu updated HBASE-21387:
---------------------------
Description:
During recent report from customer where ExportSnapshot failed:
{code}
2018-10-09 18:54:32,559 ERROR [VerifySnapshot-pool1-t2]
snapshot.SnapshotReferenceUtil: Can't find hfile:
44f6c3c646e84de6a63fe30da4fcb3aa in the real
(hdfs://in.com:8020/apps/hbase/data/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa)
or archive
(hdfs://in.com:8020/apps/hbase/data/archive/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa)
directory for the primary table.
{code}
We found the following in log:
{code}
2018-10-09 18:54:23,675 DEBUG
[00:16000.activeMasterManager-HFileCleaner.large-1539035367427]
cleaner.HFileCleaner: Removing:
hdfs:///apps/hbase/data/archive/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa
from archive
{code}
The root cause is race condition surrounding in progress snapshot(s) handling
between refreshCache() and getUnreferencedFiles().
There are two callers of refreshCache: one from RefreshCacheTask#run and the
other from SnapshotHFileCleaner.
Let's look at the code of refreshCache:
{code}
if (!name.equals(SnapshotDescriptionUtils.SNAPSHOT_TMP_DIR_NAME)) {
{code}
whose intention is to exclude in progress snapshot(s).
Suppose when the RefreshCacheTask runs refreshCache, there is some in progress
snapshot (about to finish).
When SnapshotHFileCleaner calls getUnreferencedFiles(), it sees that
lastModifiedTime is up to date. So cleaner proceeds to check in progress
snapshot(s). However, the snapshot has completed by that time, resulting in
some file(s) deemed unreferenced.
was:
During recent report from customer where ExportSnapshot failed:
{code}
2018-10-09 18:54:32,559 ERROR [VerifySnapshot-pool1-t2]
snapshot.SnapshotReferenceUtil: Can't find hfile:
44f6c3c646e84de6a63fe30da4fcb3aa in the real
(hdfs://in.com:8020/apps/hbase/data/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa)
or archive
(hdfs://in.com:8020/apps/hbase/data/archive/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa)
directory for the primary table.
{code}
We found the following in log:
{code}
2018-10-09 18:54:23,675 DEBUG
[00:16000.activeMasterManager-HFileCleaner.large-1539035367427]
cleaner.HFileCleaner: Removing:
hdfs:///apps/hbase/data/archive/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa
from archive
{code}
The root cause is race condition surrounding in progress snapshot(s) handling
between refreshCache() and getUnreferencedFiles().
There are two callers of refreshCache: one from RefreshCacheTask#run and the
other from SnapshotHFileCleaner.
Let's look at the code of refreshCache:
{code}
if (!name.equals(SnapshotDescriptionUtils.SNAPSHOT_TMP_DIR_NAME)) {
{code}
which only excludes the temp dir, but not in progress snapshot(s).
Suppose when the RefreshCacheTask runs refreshCache, SnapshotDirectoryInfo for
the in progress snapshot doesn't include all store file (leaving some hole in
cache).
When SnapshotHFileCleaner calls getUnreferencedFiles(), it sees that
lastModifiedTime is up to date. So cleaner proceeds to check in progress
snapshot(s). However, the snapshot has completed by that time, resulting in
some file(s) deemed unreferenced.
> Race condition surrounding in progress snapshot handling in snapshot cache
> leads to loss of snapshot files
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-21387
> URL: https://issues.apache.org/jira/browse/HBASE-21387
> Project: HBase
> Issue Type: Bug
> Reporter: Ted Yu
> Assignee: Ted Yu
> Priority: Major
> Labels: snapshot
> Attachments: 21387.v1.txt, 21387.v2.txt, 21387.v3.txt
>
>
> During recent report from customer where ExportSnapshot failed:
> {code}
> 2018-10-09 18:54:32,559 ERROR [VerifySnapshot-pool1-t2]
> snapshot.SnapshotReferenceUtil: Can't find hfile:
> 44f6c3c646e84de6a63fe30da4fcb3aa in the real
> (hdfs://in.com:8020/apps/hbase/data/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa)
> or archive
> (hdfs://in.com:8020/apps/hbase/data/archive/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa)
> directory for the primary table.
> {code}
> We found the following in log:
> {code}
> 2018-10-09 18:54:23,675 DEBUG
> [00:16000.activeMasterManager-HFileCleaner.large-1539035367427]
> cleaner.HFileCleaner: Removing:
> hdfs:///apps/hbase/data/archive/data/.../a/44f6c3c646e84de6a63fe30da4fcb3aa
> from archive
> {code}
> The root cause is race condition surrounding in progress snapshot(s) handling
> between refreshCache() and getUnreferencedFiles().
> There are two callers of refreshCache: one from RefreshCacheTask#run and the
> other from SnapshotHFileCleaner.
> Let's look at the code of refreshCache:
> {code}
> if (!name.equals(SnapshotDescriptionUtils.SNAPSHOT_TMP_DIR_NAME)) {
> {code}
> whose intention is to exclude in progress snapshot(s).
> Suppose when the RefreshCacheTask runs refreshCache, there is some in
> progress snapshot (about to finish).
> When SnapshotHFileCleaner calls getUnreferencedFiles(), it sees that
> lastModifiedTime is up to date. So cleaner proceeds to check in progress
> snapshot(s). However, the snapshot has completed by that time, resulting in
> some file(s) deemed unreferenced.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
