#462 Issue closed: Disk layout creation failed with error "An error occurred during layout recreation." at the time of restoring RHEL6 on different hardware.

Labels: enhancement, support / question, fixed / solved / done

pramodbiradar89 opened issue at 2014-09-19 06:35:

Steps i followed:

1.Using rear took backup of a laptop(LENOVO h/w) which was having RHEL6 & LVM configured.
2.Backup out was USB .
3.Tried to recover a different hardware machine DELL, using the USB .
4.Then at the time of recovering machine got the error saying An error occurred during layout recreation.

Additional notes:
1.Target machine was having less space i.e. ~250 GB as compared to source machine ~260 GB.
2.Also tried to recover on VM having size 300GB but still faced same issue.

find rear log file for more info.

2014-09-19 10:23:11 Relax-and-Recover 1.16.1 / Git
2014-09-19 10:23:11 Command line options: /bin/rear recover
2014-09-19 10:23:11 Using log file: /var/log/rear/rear-RHEL6.log
2014-09-19 10:23:12 Including /etc/rear/os.conf
2014-09-19 10:23:12 Including conf/Linux-i386.conf
2014-09-19 10:23:12 Including conf/GNU/Linux.conf
2014-09-19 10:23:12 Including /etc/rear/local.conf
2014-09-19 10:23:12 Including /etc/rear/rescue.conf
2014-09-19 10:23:12 Using build area '/tmp/rear.fEzKk3KJu1KjUF3'
mkdir: created directory `/tmp/rear.fEzKk3KJu1KjUF3/rootfs'
mkdir: created directory `/tmp/rear.fEzKk3KJu1KjUF3/tmp'
2014-09-19 10:23:12 Running recover workflow
2014-09-19 10:23:12 Running 'setup' stage
2014-09-19 10:23:12 Including setup/default/01_pre_recovery_script.sh
2014-09-19 10:23:12 Finished running 'setup' stage in 0 seconds
2014-09-19 10:23:12 Running 'verify' stage
2014-09-19 10:23:13 Including verify/default/02_cciss_scsi_engage.sh
2014-09-19 10:23:13 Including verify/default/02_translate_url.sh
2014-09-19 10:23:13 Including verify/default/03_translate_tape.sh
2014-09-19 10:23:13 Including verify/default/04_validate_variables.sh
2014-09-19 10:23:13 Including verify/NETFS/default/05_check_NETFS_requirements.sh
2014-09-19 10:23:13 Skipping ping test
2014-09-19 10:23:14 Including verify/GNU/Linux/05_sane_recovery_check.sh
2014-09-19 10:23:14 Including verify/NETFS/default/06_mount_NETFS_path.sh
mkdir: created directory `/tmp/rear.fEzKk3KJu1KjUF3/outputfs'
2014-09-19 10:23:14 Mounting with 'mount -v -t nfs -o rw,noatime,nolock 10.31.199.183:/NFS_DATA /tmp/rear.fEzKk3KJu1KjUF3/outputfs'
mount.nfs: mount(2): Operation not permitted
mount.nfs: trying 10.31.199.183 prog 100003 vers 3 prot TCP port 2049
mount.nfs: trying 10.31.199.183 prog 100005 vers 3 prot UDP port 818
mount.nfs: timeout set for Fri Sep 19 10:25:14 2014
mount.nfs: trying text-based options 'nolock,vers=4,addr=10.31.199.183,clientaddr=10.31.199.181'
mount.nfs: trying text-based options 'nolock,addr=10.31.199.183'
mount.nfs: prog 100003, trying vers=3, prot=6
mount.nfs: prog 100005, trying vers=3, prot=17
10.31.199.183:/NFS_DATA on /tmp/rear.fEzKk3KJu1KjUF3/outputfs type nfs (rw,noatime,nolock)
2014-09-19 10:23:16 Including verify/NETFS/default/07_set_backup_archive.sh
/usr/share/rear/verify/NETFS/default/07_set_backup_archive.sh: line 13: [: ==: unary operator expected
2014-09-19 10:23:16 Including verify/NETFS/default/08_start_required_daemons.sh
2014-09-19 10:23:18 Including verify/NETFS/default/09_set_readonly_options.sh
2014-09-19 10:23:18 Including verify/GNU/Linux/23_storage_and_network_modules.sh
find: `/lib/modules/2.6.32-71.el6.x86_64/kernel/drivers/ide': No such file or directory
find: `/lib/modules/2.6.32-71.el6.x86_64/extra': No such file or directory
find: `/lib/modules/2.6.32-71.el6.x86_64/weak-updates': No such file or directory
2014-09-19 10:23:19 Including verify/GNU/Linux/26_recovery_storage_drivers.sh
find: `/tmp/rear.fEzKk3KJu1KjUF3/tmp/dev': No such file or directory
--- /var/lib/rear/recovery/storage_drivers  2014-09-17 14:50:36.000000000 +0530
+++ /tmp/rear.fEzKk3KJu1KjUF3/tmp/storage_drivers   2014-09-19 10:23:19.882368355 +0530
@@ -1,10 +1,7 @@
 ata_generic
 ata_piix
-mptbase
-mptscsih
-mptspi
 pata_acpi
-scsi_transport_spi
 sd_mod
 sg
 sr_mod
+vmw_pvscsi
2014-09-19 10:23:20 NOTICE: Will do driver migration
2014-09-19 10:23:20 Including verify/NETFS/default/55_check_backup_archive.sh
/usr/share/rear/verify/NETFS/default/55_check_backup_archive.sh: line 10: [: ==: unary operator expected
2014-09-19 10:23:20 Calculating backup archive size
2014-09-19 10:23:20 Backup archive size is 1.1G /tmp/rear.fEzKk3KJu1KjUF3/outputfs/RHEL6/backup.tar.gz (compressed)
2014-09-19 10:23:20 Including verify/NETFS/default/60_check_encryption_key.sh
2014-09-19 10:23:20 Including verify/NETFS/default/98_umount_NETFS_dir.sh
2014-09-19 10:23:20 Unmounting '/tmp/rear.fEzKk3KJu1KjUF3/outputfs'
10.31.199.183:/NFS_DATA umounted
rmdir: removing directory, `/tmp/rear.fEzKk3KJu1KjUF3/outputfs'
2014-09-19 10:23:20 Finished running 'verify' stage in 8 seconds
2014-09-19 10:23:20 Running 'layout/prepare' stage
2014-09-19 10:23:21 Including layout/prepare/default/01_prepare_files.sh
2014-09-19 10:23:21 Including layout/prepare/GNU/Linux/10_include_partition_code.sh
2014-09-19 10:23:21 Including layout/prepare/GNU/Linux/11_include_lvm_code.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/12_include_raid_code.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/13_include_filesystem_code.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/14_include_swap_code.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/15_include_drbd_code.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/16_include_luks_code.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/17_include_hpraid_code.sh
2014-09-19 10:23:22 Including layout/prepare/default/20_recreate_hpraid.sh
2014-09-19 10:23:22 Including layout/prepare/GNU/Linux/21_load_multipath.sh
2014-09-19 10:23:22 Including layout/prepare/default/25_compare_disks.sh
2014-09-19 10:23:22 Comparing disks.
2014-09-19 10:23:22 Looking for sda...
2014-09-19 10:23:22 Device sda exists.
2014-09-19 10:23:22 Device sda has size 304942678016, 17179869184 expected
2014-09-19 10:23:22 Switching to manual disk layout configuration.
2014-09-19 10:23:22 Including layout/prepare/default/30_map_disks.sh
2014-09-19 10:23:23 Original disk /dev/sda does not exist in the target system. Please choose an appropriate replacement.
2014-09-19 10:23:28 This is the disk mapping table:
2014-09-19 10:23:28     /dev/sda /dev/sda
2014-09-19 10:23:28 Including layout/prepare/default/31_remove_exclusions.sh
2014-09-19 10:23:28 Including layout/prepare/default/32_apply_mappings.sh
2014-09-19 10:23:28 Including layout/prepare/default/40_autoresize_disks.sh
2014-09-19 10:23:28 Total resize of 287762808832B
2014-09-19 10:23:28 Searching for resizeable partitions on disk /dev/sda (304942678016B)
Usage: grep [OPTION]... PATTERN [FILE]...
Try `grep --help' for more information.
2014-09-19 10:23:28 No resizeable partitions found.
2014-09-19 10:23:28 Including layout/prepare/default/50_confirm_layout.sh
2014-09-19 10:23:28 Please confirm that '/var/lib/rear/layout/disklayout.conf' is as you expect.
2014-09-19 10:23:32 User selected: 5) Continue recovery
2014-09-19 10:23:32 Including layout/prepare/default/51_list_dependencies.sh
2014-09-19 10:23:32 Including layout/prepare/default/52_exclude_components.sh
2014-09-19 10:23:32 Including layout/prepare/default/54_generate_device_code.sh
2014-09-19 10:23:32 Including layout/prepare/default/55_finalize_script.sh
2014-09-19 10:23:32 Including layout/prepare/default/60_show_unprocessed.sh
2014-09-19 10:23:32 Including layout/prepare/default/61_exclude_from_restore.sh
2014-09-19 10:23:32 Finished running 'layout/prepare' stage in 12 seconds
2014-09-19 10:23:32 Running 'layout/recreate' stage
2014-09-19 10:23:33 Including layout/recreate/default/10_ask_confirmation.sh
2014-09-19 10:23:33 Please confirm that '/var/lib/rear/layout/diskrestore.sh' is as you expect.
2014-09-19 10:23:35 User selected: 5) Continue recovery
2014-09-19 10:23:35 Including layout/recreate/default/20_run_script.sh
2014-09-19 10:23:35 Start system layout restoration.
  No volume groups found
+++ create_component /dev/sda disk
+++ local device=/dev/sda
+++ local type=disk
+++ local touchfile=disk--dev-sda
+++ '[' -e /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/disk--dev-sda ']'
+++ return 0
+++ Log 'Erasing MBR of disk /dev/sda'
+++ test 1 -gt 0
++++ Stamp
++++ date '+%Y-%m-%d %H:%M:%S '
+++ echo '2014-09-19 10:23:37 Erasing MBR of disk /dev/sda'
2014-09-19 10:23:37 Erasing MBR of disk /dev/sda
+++ dd if=/dev/zero of=/dev/sda bs=512 count=1
1+0 records in
1+0 records out
512 bytes (512 B) copied, 0.0932551 s, 5.5 kB/s
+++ sync
+++ LogPrint 'Creating partitions for disk /dev/sda (msdos)'
+++ Log 'Creating partitions for disk /dev/sda (msdos)'
+++ test 1 -gt 0
++++ Stamp
++++ date '+%Y-%m-%d %H:%M:%S '
+++ echo '2014-09-19 10:23:37 Creating partitions for disk /dev/sda (msdos)'
2014-09-19 10:23:37 Creating partitions for disk /dev/sda (msdos)
+++ Print 'Creating partitions for disk /dev/sda (msdos)'
+++ test 1
+++ echo -e 'Creating partitions for disk /dev/sda (msdos)'
+++ parted -s /dev/sda mklabel msdos
+++ sleep 1
+++ parted -s /dev/sda mkpart '"primary"' 32768B 524320767B
Warning: The resulting partition is not properly aligned for best performance.
+++ sleep 1
+++ parted -s /dev/sda set 1 boot on
+++ parted -s /dev/sda mkpart '"primary"' 524324864B 17178857471B
Warning: The resulting partition is not properly aligned for best performance.
+++ sleep 1
+++ parted -s /dev/sda set 2 lvm on
+++ partprobe -s /dev/sda
/dev/sda: msdos partitions 1 2
+++ sleep 10
+++ my_udevtrigger
+++ has_binary udevadm
+++ for bin in '$@'
+++ type udevadm
+++ return 0
+++ udevadm trigger
+++ my_udevsettle
+++ has_binary udevadm
+++ for bin in '$@'
+++ type udevadm
+++ return 0
+++ udevadm settle
+++ component_created /dev/sda disk
+++ local device=/dev/sda
+++ local type=disk
+++ local touchfile=disk--dev-sda
+++ touch /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/disk--dev-sda
+++ create_component /dev/sda1 part
+++ local device=/dev/sda1
+++ local type=part
+++ local touchfile=part--dev-sda1
+++ '[' -e /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/part--dev-sda1 ']'
+++ return 0
+++ component_created /dev/sda1 part
+++ local device=/dev/sda1
+++ local type=part
+++ local touchfile=part--dev-sda1
+++ touch /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/part--dev-sda1
+++ create_component /dev/sda2 part
+++ local device=/dev/sda2
+++ local type=part
+++ local touchfile=part--dev-sda2
+++ '[' -e /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/part--dev-sda2 ']'
+++ return 0
+++ component_created /dev/sda2 part
+++ local device=/dev/sda2
+++ local type=part
+++ local touchfile=part--dev-sda2
+++ touch /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/part--dev-sda2
+++ create_component pv:/dev/sda2 lvmdev
+++ local device=pv:/dev/sda2
+++ local type=lvmdev
+++ local touchfile=lvmdev-pv:-dev-sda2
+++ '[' -e /tmp/rear.fEzKk3KJu1KjUF3/tmp/touch/lvmdev-pv:-dev-sda2 ']'
+++ return 0
+++ LogPrint 'Creating LVM PV /dev/sda2'
+++ Log 'Creating LVM PV /dev/sda2'
+++ test 1 -gt 0
++++ Stamp
++++ date '+%Y-%m-%d %H:%M:%S '
+++ echo '2014-09-19 10:24:03 Creating LVM PV /dev/sda2'
2014-09-19 10:24:03 Creating LVM PV /dev/sda2
+++ Print 'Creating LVM PV /dev/sda2'
+++ test 1
+++ echo -e 'Creating LVM PV /dev/sda2'
+++ lvm vgchange -a n vg_RHEL6
  Volume group "vg_RHEL6" not found
+++ true
+++ lvm pvcreate -ff --yes -v --uuid kfW8hC-cod6-KpJI-KBCR-CB3D-QYgc-Q8vz6L /dev/sda2
  --restorefile is required with --uuid
  Run `pvcreate --help' for more information.
2014-09-19 10:24:03 An error occurred during layout recreation.
2014-09-19 10:25:10 User selected: 6) Abort Relax-and-Recover
2014-09-19 10:25:10 Error detected during restore.
2014-09-19 10:25:10 Restoring backup of /var/lib/rear/layout/disklayout.conf
2014-09-19 10:25:10 ERROR: There was an error restoring the system layout. See /var/log/rear/rear-RHEL6.log for details.
=== Stack trace ===
Trace 0: /bin/rear:249 main
Trace 1: /usr/share/rear/lib/recover-workflow.sh:30 WORKFLOW_recover
Trace 2: /usr/share/rear/lib/framework-functions.sh:81 SourceStage
Trace 3: /usr/share/rear/lib/framework-functions.sh:42 Source
Trace 4: /usr/share/rear/layout/recreate/default/20_run_script.sh:63 source
Message: There was an error restoring the system layout. See /var/log/rear/rear-RHEL6.log for details.
===================
2014-09-19 10:25:10 Running exit tasks.
2014-09-19 10:25:10 Finished in 123 seconds
2014-09-19 10:25:10 Removing build area /tmp/rear.fEzKk3KJu1KjUF3
rmdir: removing directory, `/tmp/rear.fEzKk3KJu1KjUF3'
2014-09-19 10:25:10 End of program reached

gdha commented at 2014-09-19 06:53:

@pramodbiradar89 it would be nice to view a debug session. The grep error is quite interesting to find out what exactly went wrong. Also, the files under /var/lib/rear/layout directory would be nice to view and the script which was generated /usr/share/rear/layout/recreate/default/20_run_script.sh (is an auto generated script so you won't find it if you do not run rear recover

PS: you can dump files at gist.github.com

pramodbiradar89 commented at 2014-09-19 08:21:

@gdha

Please find the link for debug session logs

https://gist.github.com/pramodbiradar89/257012b2d32f06935915

pramodbiradar89 commented at 2014-09-19 08:32:

@gdha Please find the files under /var/lib/rear/layout dir:

https://gist.github.com/pramodbiradar89/b4363d764a5852c3c8df

pramodbiradar89 commented at 2014-09-19 08:36:

@gdha Also the /usr/share/rear/layout/recreate/default/20_run_script.sh :

https://gist.github.com/pramodbiradar89/51e3a5669592be9fe9f5

gdha commented at 2014-09-20 02:15:

@pramodbiradar89

+++ lvm pvcreate -ff --yes -v --uuid kfW8hC-cod6-KpJI-KBCR-CB3D-QYgc-Q8vz6L /dev/sda2
  --restorefile is required with --uuid

Could you compare 11_include_lvm_code.sh with this one https://github.com/rear/rear/blob/master/usr/share/rear/layout/prepare/GNU/Linux/11_include_lvm_code.sh ? We should have the option --norestorefile I think after the uuid

pramodbiradar89 commented at 2014-09-21 16:15:

@gdha i compared this file with the file you given & found it similar.
Still i am attaching this file for your reference.

https://gist.github.com/pramodbiradar89/c05b1e4a3a2a71798c19

pramodbiradar89 commented at 2014-09-22 10:12:

@gdha Request you to please let me know your comments/findings on this so that this issue gets resolved asap.

Any updates .

gdha commented at 2014-09-23 13:55:

@pramodbiradar89 what is the output of lvm version?

pramodbiradar89 commented at 2014-09-23 16:33:

@gdha I think ,it is having lvm2 as version.

So is it like for lvm2 it will fail ?

gdha commented at 2014-09-24 07:42:

@pramodbiradar89 if the lvm version shows a version higher then listed below then

if version_newer "$lvm_version" 2.02.73 ; then
FEATURE_LVM_RESTOREFILE="y"
fi

then the norestorefile option will be added. that was the reason why I would like to see the exact version of your lvm

pramodbiradar89 commented at 2014-09-24 12:49:

@gdha Please find screenshot which shows the details about the LVM version.

image

Also if you need any other extra logs then please ping me.

Thanks,
Pramod

gdha commented at 2014-09-25 09:47:

@pramodbiradar89 what is the exact version of RHEL6 you are using? cat /etc/issue.net
A possible solution would be upgrading lvm or you could try to change the line in file /usr/share/rear/layout/prepare/GNU/Linux/11_include_lvm_code.sh:
if version_newer "$lvm_version" 2.02.73 ; then into if version_newer "$lvm_version" 2.02.71 ; then
Then, try it again and let me know how it worked out.

pramodbiradar89 commented at 2014-09-25 11:27:

@gdha
Please find the output of /etc/issue

image

Also i tried by changing if version_newer "$lvm_version" 2.02.71 ; then i got following error:

image

image

Also attaching the log file in debug mode for your reference:

https://gist.github.com/pramodbiradar89/aab16c513178143083be

gdha commented at 2014-09-25 11:59:

@pramodbiradar89 OK, thanks, so now pvcreate works fine. The error you are seeing:

+++ lvm lvcreate -l 12800 -n lv_root vg_dellrhelqa2
Insufficient free extents (3970) in volume group vg_dellrhelqa2: 12800 required

just means that you do not have enough disk space to recreate your lvol. You should edit the diskrestore.sh file and change the number 12800 into 3970 and retry. However, keep in mind that the lvol might be too small to fit the data. Just that you know this is not a issue of rear, but of the end-user if he wishes to restore on a smaller disk.
I will reflect your test into our code and change the requirement of 2.02.73 into 2.02.71

exedor commented at 2014-12-20 17:43:

I am getting the exact same error during restore on fedora 20 with standard partitions. Here is the layout:

Filesystem Size Used Avail Use% Mounted on
/dev/sda3 67G 19G 46G 29% /
devtmpfs 896M 0 896M 0% /dev
tmpfs 906M 0 906M 0% /dev/shm
tmpfs 906M 520K 905M 1% /run
tmpfs 906M 0 906M 0% /sys/fs/cgroup
tmpfs 906M 8.0K 906M 1% /tmp
/dev/sda1 2.9G 72M 2.7G 3% /boot

I noticed the generated scripts are using specific byte values for partition recreation. Any particular reason why? Wouldn't sticking to percentages and letting parted figure out the best byte boundary for the partition be a better option?

This was with the latest checkout of the master branch which I assume has the fix mentioned in this ticket?

gdha commented at 2014-12-20 17:59:

did you look in the log file of rear where the error happened?

On Sat, Dec 20, 2014 at 6:43 PM, jb notifications@github.com wrote:

I am getting the exact same error during restore on fedora 20 with
standard partitions. Here is the layout:

Filesystem Size Used Avail Use% Mounted on
/dev/sda3 67G 19G 46G 29% /
devtmpfs 896M 0 896M 0% /dev
tmpfs 906M 0 906M 0% /dev/shm
tmpfs 906M 520K 905M 1% /run
tmpfs 906M 0 906M 0% /sys/fs/cgroup
tmpfs 906M 8.0K 906M 1% /tmp
/dev/sda1 2.9G 72M 2.7G 3% /boot

I noticed the generated scripts are using specific byte values for
partition recreation. Any particular reason why? Wouldn't sticking to
percentages and letting parted figure out the best byte boundary for the
partition be a better option?


Reply to this email directly or view it on GitHub
https://github.com/rear/rear/issues/462#issuecomment-67743468.

exedor commented at 2014-12-20 18:42:

Yes briefly just after posting (granted should have been before) and it looks like it actually has nothing to do with the partition size. The last executed command is udevadm settle which has the following output to the console just before the rear abort option menu shows up:

Creating partitions for disk /dev/sda (msdos)

udevadm settle - timeout of 120 seconds reached, the event queue contains:
/sys/devices/system/cpu/cpu0 (1162)
/sys/devices/system/cpu/cpu1 (1163)
/sys/devices/system/cpu/cpu2 (1164)
/sys/devices/system/cpu/cpu3 (1165)
/sys/devices/system/cpu/cpu0 (2095)
/sys/devices/system/cpu/cpu1 (2096)
/sys/devices/system/cpu/cpu2 (2097)
/sys/devices/system/cpu/cpu3 (2098)
An error occurred during layout creation.

Something else must be failing that is causing udev events to be stuck. It's an SSD drive with a relatively straight forward partition scheme so I'm surprised something would be taking this long or getting stuck.

Actually upon closer examination, it may have absolutely nothing to do with rear at all. I'm seeing a lot of history online about problems with programs executing udevadm --settle at boot and USB stick booting causing problems with it timing out.

gdha commented at 2015-02-11 11:01:

@exedor Sorry did not saw your last posting from Dec 20, 2014. Most likely your issue will be fixed in rear-1.17 as udev related things were drastically adapted, modified and tested by SuSe and myself. We have spend long time on it. See #533 for more details.


[Export of Github issue for rear/rear.]