failed to use freezer-agent restore with --overwrite

[Shangzhong Zhu]

The issue can be reproduced on CentOS7/tar 1.26,Ubuntu16.04/tar 1.28 and
SUSE11/tar 1.29.

Restore:
[root@cephfs102 .freezer]# freezer-agent --action restore --restore-abs-path /root/restore20161124 --container /root/backup20161124 --backup-name freezer-backup --storage local

Critical Error: Restore dir is not empty. Please use --overwrite or provide different path.

Restore with --overwrite option:
[root@cephfs102 .freezer]# freezer-agent --action restore --restore-abs-path /root/restore20161124 --container /root/backup20161124 --backup-name freezer-backup --storage local --overwrite

Process Process-2:
Traceback (most recent call last):
  File "/usr/lib64/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    self.run()
  File "/usr/lib64/python2.7/multiprocessing/process.py", line 114, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python2.7/site-packages/freezer/engine/tar/tar.py", line 138, in restore_level
    self.check_process_output(tar_process, 'Restore')
  File "/usr/lib/python2.7/site-packages/freezer/engine/tar/tar.py", line 168, in check_process_output
    .format(function, process.returncode))
Exception: Restore process failed with return code: 2
Critical Error: ('Engine error. Failed to restore.', {})

LOGs:
2016-11-24 16:49:54.365 1786837 INFO freezer.main [-] Begin freezer agent process with args: ['/usr/bin/freezer-agent', '--action', 'restore', '--restore-abs-path', '/root/restore20161124', '--container', '/root/backup20161124', '--backup-name', 'freezer-backup', '--storage', 'local', '--overwrite']
2016-11-24 16:49:54.366 1786837 INFO freezer.main [-] log file at /root/.freezer/freezer.log
2016-11-24 16:49:54.371 1786837 INFO freezer.job [-] Validating args for the restore job.
2016-11-24 16:49:54.372 1786837 INFO freezer.main [-] Job execution Started at: 2016-11-24 16:49:54
2016-11-24 16:49:54.372 1786837 INFO freezer.job [-] Executing FS restore...
2016-11-24 16:49:54.372 1786837 INFO freezer.engine.engine [-] Creating restore path: /root/restore20161124
2016-11-24 16:49:54.373 1786837 INFO freezer.engine.engine [-] Restore path creation completed
2016-11-24 16:49:54.374 1786837 INFO freezer.engine.engine [-] Restoring backup <freezer.storage.base.Backup object at 0x39dfd10>
2016-11-24 16:49:54.380 1786847 INFO freezer.storage.base [-] metadata content download ['{"encryption": false, "compression": "gzip", "engine_name": "tar"}']
2016-11-24 16:49:54.698 1786847 INFO freezer.engine.tar.tar [-] Pipe closed as EOF reached. Data transmitted successfully
2016-11-24 16:49:54.702 1786847 ERROR freezer.engine.tar.tar [-] Restore error: /usr/bin/gtar: ./.git: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/hooks: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/info: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/logs: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/logs/refs: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/logs/refs/heads: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/logs/refs/remotes: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/logs/refs/remotes/origin: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/objects: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/objects/pack: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/refs: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/refs/heads: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/refs/remotes: Cannot unlink: Directory not empty
/usr/bin/gtar: ./.git/refs/remotes/origin: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/common: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/engine: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/engine/tar: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/exceptions: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/lib: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/lib/pep3143daemon: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/mode: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/openstack: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/scheduler: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/scripts: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/snapshot: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/storage: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/freezer_tempest_plugin: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/freezer_tempest_plugin/services: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/freezer_tempest_plugin/tests: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/freezer_tempest_plugin/tests/api: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/freezer_tempest_plugin/tests/scenario: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/integration: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/engines: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/engines/tar: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/openstack: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/scheduler: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/snapshot: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/storages: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/tests/unit/utils: Cannot unlink: Directory not empty
/usr/bin/gtar: ./build/lib/freezer/utils: Cannot unlink: Directory not empty
/usr/bin/gtar: ./config-generator: Cannot unlink: Directory not empty
/usr/bin/gtar: ./devstack: Cannot unlink: Directory not empty
/usr/bin/gtar: ./devstack/lib: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc/source: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc/source/admin: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc/source/dev: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc/source/images: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc/source/images/admin: Cannot unlink: Directory not empty
/usr/bin/gtar: ./doc/source/user: Cannot unlink: Directory not empty
/usr/bin/gtar: ./etc: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer.egg-info: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/common: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/engine: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/engine/tar: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/exceptions: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/lib: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/lib/pep3143daemon: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/mode: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/openstack: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/scheduler: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/scripts: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/snapshot: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/storage: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/freezer_tempest_plugin: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/freezer_tempest_plugin/services: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/freezer_tempest_plugin/tests: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/freezer_tempest_plugin/tests/api: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/freezer_tempest_plugin/tests/scenario: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/integration: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/engines: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/engines/tar: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/openstack: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/scheduler: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/snapshot: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/storages: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/tests/unit/utils: Cannot unlink: Directory not empty
/usr/bin/gtar: ./freezer/utils: Cannot unlink: Directory not empty
/usr/bin/gtar: ./releasenotes: Cannot unlink: Directory not empty
/usr/bin/gtar: ./releasenotes/source: Cannot unlink: Directory not empty
/usr/bin/gtar: ./releasenotes/source/_static: Cannot unlink: Directory not empty
/usr/bin/gtar: ./releasenotes/source/_templates: Cannot unlink: Directory not empty
/usr/bin/gtar: ./specs: Cannot unlink: Directory not empty
/usr/bin/gtar: Exiting with failure status due to previous errors

2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar [-] 2 return code is not 0
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar [-] Restore process failed with return code: 2
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar Traceback (most recent call last):
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar File "/usr/lib/python2.7/site-packages/freezer/engine/tar/tar.py", line 138, in restore_level
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar self.check_process_output(tar_process, 'Restore')
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar File "/usr/lib/python2.7/site-packages/freezer/engine/tar/tar.py", line 168, in check_process_output
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar .format(function, process.returncode))
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar Exception: Restore process failed with return code: 2
2016-11-24 16:49:54.703 1786847 ERROR freezer.engine.tar.tar
2016-11-24 16:49:54.707 1786837 ERROR freezer.engine.engine [-] Engine error: Restore process failed with return code: 2
2016-11-24 16:49:54.707 1786837 ERROR freezer.engine.engine None
2016-11-24 16:49:54.707 1786837 ERROR freezer.engine.engine
2016-11-24 16:49:54.708 1786837 ERROR freezer.main [-] ('Engine error. Failed to restore.', {})
2016-11-24 16:49:54.708 1786837 ERROR freezer.main Traceback (most recent call last):
2016-11-24 16:49:54.708 1786837 ERROR freezer.main File "/usr/lib/python2.7/site-packages/freezer/main.py", line 227, in main
2016-11-24 16:49:54.708 1786837 ERROR freezer.main freezer_main(backup_args)
2016-11-24 16:49:54.708 1786837 ERROR freezer.main File "/usr/lib/python2.7/site-packages/freezer/main.py", line 111, in freezer_main
2016-11-24 16:49:54.708 1786837 ERROR freezer.main return run_job(backup_args, storage)
2016-11-24 16:49:54.708 1786837 ERROR freezer.main File "/usr/lib/python2.7/site-packages/freezer/main.py", line 124, in run_job
2016-11-24 16:49:54.708 1786837 ERROR freezer.main response = freezer_job.execute()
2016-11-24 16:49:54.708 1786837 ERROR freezer.main File "/usr/lib/python2.7/site-packages/freezer/job.py", line 273, in execute
2016-11-24 16:49:54.708 1786837 ERROR freezer.main recent_to_date=conf.restore_from_date)
2016-11-24 16:49:54.708 1786837 ERROR freezer.main File "/usr/lib/python2.7/site-packages/freezer/engine/engine.py", line 292, in restore
2016-11-24 16:49:54.708 1786837 ERROR freezer.main "Engine error. Failed to restore.")
2016-11-24 16:49:54.708 1786837 ERROR freezer.main EngineException: ('Engine error. Failed to restore.', {})
2016-11-24 16:49:54.708 1786837 ERROR freezer.main
2016-11-24 16:49:54.710 1786837 CRITICAL freezer.main [-] End freezer agent process unsuccessfully
2016-11-24 16:49:54.710 1786837 CRITICAL freezer.main [-] Critical Error: ('Engine error. Failed to restore.', {})

[Shangzhong Zhu (zhusz)]

CentOS7/tar 1.26:
add --overwrite for UNIX_TEMPLATE in class TarCommandRestoreBuilder(file: freezer/engine/tar/tar_builders.py)
it works well.

Ubuntu16.04/tar 1.28:
add --overwrite for UNIX_TEMPLATE in class TarCommandRestoreBuilder(file: freezer/engine/tar/tar_builders.py)
it works well.

SUSE11/tar 1.29
add --overwrite for UNIX_TEMPLATE in class TarCommandRestoreBuilder(file: freezer/engine/tar/tar_builders.py)
tar: '--overwrite' cannot be used with '--unlink-first'

related to change: https://review.openstack.org/#/c/351485/

[Shangzhong Zhu (zhusz)]

Here is the detailed descriptions about --unlink-first and overwrite option:

--unlink-first:
Remove files before extracting over them.
This can make tar run a bit faster if you know in advance that the extracted files all need to be removed.
Normally this option slows tar down slightly, so it is disabled by default.
(Refer to http://www.gnu.org/software/tar/manual/html_node/Unlink-First.html)

--overwrite:
Overwrite existing files and directory metadata when extracting files from an archive.
This causes tar to write extracted files into the file system without regard to the files already on the system;
i.e., files with the same names as archive members are overwritten when the archive is extracted.
It also causes tar to extract the ownership, permissions, and time stamps onto any preexisting files or directories.
If the name of a corresponding file name is a symbolic link,
the file pointed to by the symbolic link will be overwritten instead of the symbolic link itself (if this is possible).
Moreover, special devices, empty directories and even symbolic links are automatically removed if they are in the way of extraction.
Be careful when using the `--overwrite' option, particularly when combined with the `--absolute-names' (`-P') option,
as this combination can change the contents, ownership or permissions of any file on your system.
Also, many systems do not take kindly to overwriting files that are currently being executed.
(Refer to http://www.gnu.org/software/tar/manual/html_node/Overwrite-Old-Files.html#SEC76)

[Shangzhong Zhu (zhusz)]

More comments about --unlink-first and --overwrite:
(Refer to http://www.linuxcommand.org/man_pages/tar1.html)
--unlink-first
remove existing files before extracting files of the same name

--overwrite
overwrite existing files and directory metadata when extracting

(Refer to http://lists.gnu.org/archive/html/bug-tar/2005-05/msg00056.html)
--overwrite: No matter what the file timestamp is, replace it with
             the archive version. Notice, that replacing means
             unlinking old file and creating a new one in its stead.
--unlink-first: Same as --overwrite, the only difference being that
                --unlink-first tries to unlink file before opening
                (even if it does not exist), while --overwrite
                unlinks it only after opening it returns EEXIST.

[Shangzhong Zhu (zhusz)]

The error messgae "Cannot unlink: Directory not empty" is from the function remove_any_file() in the tar.
In the remove_any_file(), the system call "unlinkat" is called with flag AT_REMOVEDIR.
If the AT_REMOVEDIR flag is specified, then performs the equivalent of rmdir(2) on pathname.
(Refer to https://linux.die.net/man/2/unlinkat)
Finally, the error code ENOTEMPTY is returned by rmdir().
In the Linux Error Code, the ENOTEMPTY's description is "Directory not empty".

[Shangzhong Zhu (zhusz)]

In conclusion, the --overwrite option should be reserved when executing tar restore operation, the --unlink-first can be removed, I think.

The restore test case has been run with tar 1.26 in CentOS7 and tar 1.29 in Ubuntu16.04.
They all work well. I'll propose a patch for this solution later.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/404079

[Shangzhong Zhu (zhusz)]

when executing the tar with --unlink-first option, the remove_any_file function will be executed in the tar.

/* Remove FILE_NAME, returning 1 on success. If FILE_NAME is a directory,
   then if OPTION is RECURSIVE_REMOVE_OPTION is set remove FILE_NAME
   recursively; otherwise, remove it only if it is empty. If FILE_NAME is
   a directory that cannot be removed (e.g., because it is nonempty)
   and if OPTION is WANT_DIRECTORY_REMOVE_OPTION, then return -1.
   Return 0 on error, with errno set; if FILE_NAME is obviously the working
   directory return zero with errno set to zero. */
int
remove_any_file (const char *file_name, enum remove_option option)
{
  /* Try unlink first if we cannot unlink directories, as this saves
     us a system call in the common case where we're removing a
     non-directory. */
  bool try_unlink_first = cannot_unlink_dir ();

  if (try_unlink_first)
    {
      if (unlinkat (chdir_fd, file_name, 0) == 0)
 return 1;

      /* POSIX 1003.1-2001 requires EPERM when attempting to unlink a
  directory without appropriate privileges, but many Linux
  kernels return the more-sensible EISDIR. */
      if (errno != EPERM && errno != EISDIR)
 return 0;
    }

  if (safer_rmdir (file_name) == 0)
    return 1;

  switch (errno)
    {
    case ENOTDIR:
      return !try_unlink_first && unlinkat (chdir_fd, file_name, 0) == 0;

    case 0:
    case EEXIST:
#if defined ENOTEMPTY && ENOTEMPTY != EEXIST
    case ENOTEMPTY:
#endif
      switch (option)
 {
 case ORDINARY_REMOVE_OPTION:
   break;

 case WANT_DIRECTORY_REMOVE_OPTION:
   return -1;

 case RECURSIVE_REMOVE_OPTION:
   {
     char *directory = tar_savedir (file_name, 0);
     char const *entry;
     size_t entrylen;

     if (! directory)
       return 0;

     for (entry = directory;
   (entrylen = strlen (entry)) != 0;
   entry += entrylen + 1)
       {
  char *file_name_buffer = make_file_name (file_name, entry);
  int r = remove_any_file (file_name_buffer,
                                         RECURSIVE_REMOVE_OPTION);
  int e = errno;
  free (file_name_buffer);

  if (! r)
    {
      free (directory);
      errno = e;
      return 0;
    }
       }

     free (directory);
     return safer_rmdir (file_name) == 0;
   }
 }
      break;
    }

  return 0;
}

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/411345

[OpenStack Infra (hudson-openstack)]

Change abandoned by Shangzhong Zhu (<email address hidden>) on branch: master
Review: https://review.openstack.org/404079
Reason: Merge Conflict, please review
https://review.openstack.org/#/c/411345/

[OpenStack Infra (hudson-openstack)]

Change abandoned by Shangzhong Zhu (<email address hidden>) on branch: master
Review: https://review.openstack.org/404079

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/411345
Committed: https://git.openstack.org/cgit/openstack/freezer/commit/?id=888eb6bb00a44f27d3433b0f90410fad9b970986
Submitter: Jenkins
Branch: master

commit 888eb6bb00a44f27d3433b0f90410fad9b970986
Author: Shangzhong Zhu <email address hidden>
Date: Thu Dec 15 22:19:18 2016 +0800

    Replace --unlink-first with --overwrite

    The main reasons are listed as follow:
    1. The tar can't write data into an not empty directory without
       --overwrite option.
    2. When the tar is used to restore data to an not empty directory
       with --unlink-first option only, the tar will raise an error.
    3. The --unlink-first and --overwrite option can't be simultaneously
       used by tar 1.29.
    4. The --unlink-first removes files before extracting over them.
       This can make tar run a bit faster if you know in advance that the
       extracted files all need to be removed.Normally this option slows tar
       down slightly, so it is disabled by default.

    Change-Id: I3cf232ed86472c60c3fe4fcc3d38acbfaf14f9f2
    Closes-Bug: #1644467
    Signed-off-by: Shangzhong Zhu <email address hidden>

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/freezer 4.0.0.0b3 development milestone.