/var/log/rear/log-file

log-file

2014-09-25 15:19:16.155733996 Relax-and-Recover 1.16.1 / Git
2014-09-25 15:19:16.157815486 Command line options: /bin/rear recover -d
2014-09-25 15:19:16.159735600 Using log file: /var/log/rear/rear-dellRHELqa2.log
2014-09-25 15:19:16.163255637 Combining configuration files
2014-09-25 15:19:16.165313927 Including /etc/rear/os.conf
2014-09-25 15:19:16.167403172 Skipping /etc/rear/recover.conf (file not found or empty)
2014-09-25 15:19:16.169795719 Including conf/Linux-i386.conf
2014-09-25 15:19:16.172284901 Including conf/GNU/Linux.conf
2014-09-25 15:19:16.176603210 Skipping /usr/share/rear/conf/Fedora.conf (file not found or empty)
2014-09-25 15:19:16.178635193 Skipping /usr/share/rear/conf/Fedora/i386.conf (file not found or empty)
2014-09-25 15:19:16.180857013 Skipping /usr/share/rear/conf/Fedora/6.conf (file not found or empty)
2014-09-25 15:19:16.183189857 Skipping /usr/share/rear/conf/Fedora/6/i386.conf (file not found or empty)
2014-09-25 15:19:16.185162929 Skipping /usr/share/rear/conf/RedHatEnterpriseServer.conf (file not found or empty)
2014-09-25 15:19:16.187070584 Skipping /usr/share/rear/conf/RedHatEnterpriseServer/i386.conf (file not found or empty)
2014-09-25 15:19:16.189069093 Skipping /usr/share/rear/conf/RedHatEnterpriseServer/6.conf (file not found or empty)
2014-09-25 15:19:16.191067966 Skipping /usr/share/rear/conf/RedHatEnterpriseServer/6/i386.conf (file not found or empty)
2014-09-25 15:19:16.192988295 Skipping /etc/rear/site.conf (file not found or empty)
2014-09-25 15:19:16.194909462 Including /etc/rear/local.conf
2014-09-25 15:19:16.196872405 Including /etc/rear/rescue.conf
2014-09-25 15:19:16.204232764 Using build area '/tmp/rear.V8HmdM8n8jkbfnx'
mkdir: created directory `/tmp/rear.V8HmdM8n8jkbfnx/rootfs'
mkdir: created directory `/tmp/rear.V8HmdM8n8jkbfnx/tmp'
2014-09-25 15:19:16.208600223 Running recover workflow
2014-09-25 15:19:16.210434177 Running 'setup' stage
2014-09-25 15:19:16.219695231 Including setup/default/01_pre_recovery_script.sh
2014-09-25 15:19:16.221729726 Finished running 'setup' stage in 0 seconds
2014-09-25 15:19:16.223915517 Running 'verify' stage
2014-09-25 15:19:16.234980687 Including verify/default/02_cciss_scsi_engage.sh
2014-09-25 15:19:16.238375907 Including verify/default/02_translate_url.sh
2014-09-25 15:19:16.241190291 Including verify/default/03_translate_tape.sh
2014-09-25 15:19:16.245833982 Including verify/default/04_validate_variables.sh
2014-09-25 15:19:16.249543949 Including verify/NETFS/default/05_check_NETFS_requirements.sh
2014-09-25 15:19:16.255359456 Skipping ping test
2014-09-25 15:19:16.267399987 Including verify/GNU/Linux/05_sane_recovery_check.sh
2014-09-25 15:19:16.270068901 Including verify/NETFS/default/06_mount_NETFS_path.sh
mkdir: created directory `/tmp/rear.V8HmdM8n8jkbfnx/outputfs'
2014-09-25 15:19:16.273548378 Added 'rmdir -v /tmp/rear.V8HmdM8n8jkbfnx/outputfs >&2' as an exit task
2014-09-25 15:19:16.282709962 Mounting with 'mount -v -t nfs -o rw,noatime,nolock 10.31.199.183:/NFS_DATA /tmp/rear.V8HmdM8n8jkbfnx/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 959
mount.nfs: timeout set for Thu Sep 25 15:21:16 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.V8HmdM8n8jkbfnx/outputfs type nfs (rw,noatime,nolock)
2014-09-25 15:19:25.362871928 Added 'umount -f -v '/tmp/rear.V8HmdM8n8jkbfnx/outputfs' >&2' as an exit task
2014-09-25 15:19:25.364961991 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-25 15:19:25.370259361 Including verify/NETFS/default/08_start_required_daemons.sh
2014-09-25 15:19:25.448176567 Including verify/NETFS/default/09_set_readonly_options.sh
2014-09-25 15:19:25.450226282 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-25 15:19:25.474139805 Including verify/GNU/Linux/26_recovery_storage_drivers.sh
find: `/tmp/rear.V8HmdM8n8jkbfnx/tmp/dev': No such file or directory
--- /var/lib/rear/recovery/storage_drivers	2014-09-17 21:47:39.000000000 +0530
+++ /tmp/rear.V8HmdM8n8jkbfnx/tmp/storage_drivers	2014-09-25 15:19:25.518652753 +0530
@@ -1,9 +1,10 @@
-ahci
-fcoe
-libfc
-libfcoe
-scsi_tgt
-scsi_transport_fc
+ata_generic
+ata_piix
+mptbase
+mptscsih
+mptspi
+pata_acpi
+scsi_transport_spi
 sd_mod
 sg
 sr_mod
2014-09-25 15:19:25.521732764 NOTICE: Will do driver migration
2014-09-25 15:19:25.523929335 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-25 15:19:25.531088047 Calculating backup archive size
2014-09-25 15:19:25.536468569 Backup archive size is 1.6G	/tmp/rear.V8HmdM8n8jkbfnx/outputfs/dellRHELqa2/backup.tar.gz (compressed)
2014-09-25 15:19:25.538931726 Including verify/NETFS/default/60_check_encryption_key.sh
2014-09-25 15:19:25.540910996 Including verify/NETFS/default/98_umount_NETFS_dir.sh
2014-09-25 15:19:25.545042953 Unmounting '/tmp/rear.V8HmdM8n8jkbfnx/outputfs'
10.31.199.183:/NFS_DATA umounted
2014-09-25 15:19:25.653476365 Removed 'umount -f -v '/tmp/rear.V8HmdM8n8jkbfnx/outputfs' >&2' from the list of exit tasks
rmdir: removing directory, `/tmp/rear.V8HmdM8n8jkbfnx/outputfs'
2014-09-25 15:19:25.657433967 Removed 'rmdir -v /tmp/rear.V8HmdM8n8jkbfnx/outputfs >&2' from the list of exit tasks
2014-09-25 15:19:25.660358932 Finished running 'verify' stage in 9 seconds
2014-09-25 15:19:25.662247122 Running 'layout/prepare' stage
2014-09-25 15:19:25.671541943 Including layout/prepare/default/01_prepare_files.sh
2014-09-25 15:19:25.676253829 Including layout/prepare/GNU/Linux/10_include_partition_code.sh
2014-09-25 15:19:25.686345643 Including layout/prepare/GNU/Linux/11_include_lvm_code.sh
2014-09-25 15:19:25.695773883 Including layout/prepare/GNU/Linux/12_include_raid_code.sh
2014-09-25 15:19:25.697906576 Including layout/prepare/GNU/Linux/13_include_filesystem_code.sh
2014-09-25 15:19:25.701031161 Including layout/prepare/GNU/Linux/14_include_swap_code.sh
2014-09-25 15:19:25.709233591 Including layout/prepare/GNU/Linux/15_include_drbd_code.sh
2014-09-25 15:19:25.711405178 Including layout/prepare/GNU/Linux/16_include_luks_code.sh
2014-09-25 15:19:25.713734201 Including layout/prepare/GNU/Linux/17_include_hpraid_code.sh
2014-09-25 15:19:25.716247376 Including layout/prepare/default/20_recreate_hpraid.sh
2014-09-25 15:19:25.719312276 Including layout/prepare/GNU/Linux/21_load_multipath.sh
2014-09-25 15:19:25.722424945 Including layout/prepare/default/25_compare_disks.sh
2014-09-25 15:19:25.724232888 Comparing disks.
2014-09-25 15:19:25.729029563 Looking for sda...
2014-09-25 15:19:25.730753124 Device sda exists.
2014-09-25 15:19:25.735486827 Device sda has size 17179869184, 250059350016 expected
2014-09-25 15:19:25.737567099 Switching to manual disk layout configuration.
2014-09-25 15:19:25.739792251 Including layout/prepare/default/30_map_disks.sh
2014-09-25 15:19:25.950254938 Original disk /dev/sda does not exist in the target system. Please choose an appropriate replacement.
2014-09-25 15:19:34.410750173 This is the disk mapping table:
2014-09-25 15:19:34.414589496     /dev/sda /dev/sda
2014-09-25 15:19:34.420326701 Including layout/prepare/default/31_remove_exclusions.sh
2014-09-25 15:19:34.426449300 Including layout/prepare/default/32_apply_mappings.sh
2014-09-25 15:19:34.439481399 Including layout/prepare/default/40_autoresize_disks.sh
2014-09-25 15:19:34.448778748 Total resize of -232879480832B
2014-09-25 15:19:34.450472236 Searching for resizeable partitions on disk /dev/sda (17179869184B)
Usage: grep [OPTION]... PATTERN [FILE]...
Try `grep --help' for more information.
2014-09-25 15:19:34.457364957 No resizeable partitions found.
2014-09-25 15:19:34.460912157 Including layout/prepare/default/50_confirm_layout.sh
2014-09-25 15:19:34.462817674 Please confirm that '/var/lib/rear/layout/disklayout.conf' is as you expect.
2014-09-25 15:19:45.246414347 User selected: 5) Continue recovery
2014-09-25 15:19:45.248715215 Including layout/prepare/default/51_list_dependencies.sh
2014-09-25 15:19:45.304408532 Including layout/prepare/default/52_exclude_components.sh
2014-09-25 15:19:45.308371594 Including layout/prepare/default/54_generate_device_code.sh
2014-09-25 15:19:45.316230576 Testing /dev/sda for dependencies...
2014-09-25 15:19:45.320532807 deps (0): 
2014-09-25 15:19:45.322356104 All dependencies for /dev/sda are present, processing...
2014-09-25 15:19:45.354233930 Partition primary on /dev/sda: size reduced to fit on disk.
2014-09-25 15:19:45.356216565 End changed from 250058149888 to 17179869184.
2014-09-25 15:19:45.372443074 Marking /dev/sda as done.
2014-09-25 15:19:45.378461320 Testing /dev/sda1 for dependencies...
2014-09-25 15:19:45.383255960 deps (1): /dev/sda
2014-09-25 15:19:45.386159566 All dependencies for /dev/sda1 are present, processing...
2014-09-25 15:19:45.391332155 Marking /dev/sda1 as done.
2014-09-25 15:19:45.397467610 Testing /dev/sda2 for dependencies...
2014-09-25 15:19:45.402208596 deps (1): /dev/sda
2014-09-25 15:19:45.405064799 All dependencies for /dev/sda2 are present, processing...
2014-09-25 15:19:45.410396614 Marking /dev/sda2 as done.
2014-09-25 15:19:45.416714046 Testing pv:/dev/sda2 for dependencies...
2014-09-25 15:19:45.421313380 deps (1): /dev/sda2
2014-09-25 15:19:45.424231567 All dependencies for pv:/dev/sda2 are present, processing...
2014-09-25 15:19:45.432300050 Marking pv:/dev/sda2 as done.
2014-09-25 15:19:45.438275429 Testing /dev/vg_dellrhelqa2 for dependencies...
2014-09-25 15:19:45.443590540 deps (1): pv:/dev/sda2
2014-09-25 15:19:45.446972466 All dependencies for /dev/vg_dellrhelqa2 are present, processing...
2014-09-25 15:19:45.459016831 Marking /dev/vg_dellrhelqa2 as done.
2014-09-25 15:19:45.465150503 Testing /dev/mapper/vg_dellrhelqa2-lv_root for dependencies...
2014-09-25 15:19:45.469888011 deps (1): /dev/vg_dellrhelqa2
2014-09-25 15:19:45.472766252 All dependencies for /dev/mapper/vg_dellrhelqa2-lv_root are present, processing...
2014-09-25 15:19:45.484898356 Marking /dev/mapper/vg_dellrhelqa2-lv_root as done.
2014-09-25 15:19:45.490950084 Testing /dev/mapper/vg_dellrhelqa2-lv_home for dependencies...
2014-09-25 15:19:45.495549891 deps (1): /dev/vg_dellrhelqa2
2014-09-25 15:19:45.498547187 All dependencies for /dev/mapper/vg_dellrhelqa2-lv_home are present, processing...
2014-09-25 15:19:45.510426842 Marking /dev/mapper/vg_dellrhelqa2-lv_home as done.
2014-09-25 15:19:45.516373123 Testing /dev/mapper/vg_dellrhelqa2-lv_swap for dependencies...
2014-09-25 15:19:45.521122308 deps (1): /dev/vg_dellrhelqa2
2014-09-25 15:19:45.523990362 All dependencies for /dev/mapper/vg_dellrhelqa2-lv_swap are present, processing...
2014-09-25 15:19:45.536943094 Marking /dev/mapper/vg_dellrhelqa2-lv_swap as done.
2014-09-25 15:19:45.542944849 Testing fs:/ for dependencies...
2014-09-25 15:19:45.547385514 deps (1): /dev/mapper/vg_dellrhelqa2-lv_root
2014-09-25 15:19:45.550382475 All dependencies for fs:/ are present, processing...
2014-09-25 15:19:45.560348176 Marking fs:/ as done.
2014-09-25 15:19:45.566518453 Testing fs:/boot for dependencies...
2014-09-25 15:19:45.571164616 deps (2): /dev/sda1 fs:/
2014-09-25 15:19:45.574940315 All dependencies for fs:/boot are present, processing...
2014-09-25 15:19:45.584680448 Marking fs:/boot as done.
2014-09-25 15:19:45.590782246 Testing fs:/home for dependencies...
2014-09-25 15:19:45.595302888 deps (2): /dev/mapper/vg_dellrhelqa2-lv_home fs:/
2014-09-25 15:19:45.599680060 All dependencies for fs:/home are present, processing...
2014-09-25 15:19:45.609450427 Marking fs:/home as done.
2014-09-25 15:19:45.615812022 Testing swap:/dev/mapper/vg_dellrhelqa2-lv_swap for dependencies...
2014-09-25 15:19:45.620515667 deps (1): /dev/mapper/vg_dellrhelqa2-lv_swap
2014-09-25 15:19:45.623464018 All dependencies for swap:/dev/mapper/vg_dellrhelqa2-lv_swap are present, processing...
2014-09-25 15:19:45.632158470 Marking swap:/dev/mapper/vg_dellrhelqa2-lv_swap as done.
2014-09-25 15:19:45.639332890 Including layout/prepare/default/55_finalize_script.sh
2014-09-25 15:19:45.642726295 Including layout/prepare/default/60_show_unprocessed.sh
2014-09-25 15:19:45.646551690 Including layout/prepare/default/61_exclude_from_restore.sh
2014-09-25 15:19:45.648908412 Finished running 'layout/prepare' stage in 20 seconds
2014-09-25 15:19:45.650889067 Running 'layout/recreate' stage
2014-09-25 15:19:45.671558713 Including layout/recreate/default/10_ask_confirmation.sh
2014-09-25 15:19:45.673685206 Please confirm that '/var/lib/rear/layout/diskrestore.sh' is as you expect.
2014-09-25 15:19:47.895134212 User selected: 5) Continue recovery
2014-09-25 15:19:47.898460705 Including layout/recreate/default/20_run_script.sh
2014-09-25 15:19:47.901800657 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.V8HmdM8n8jkbfnx/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.%N '
+++ echo '2014-09-25 15:19:47.963519557 Erasing MBR of disk /dev/sda'
2014-09-25 15:19:47.963519557 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.0139508 s, 36.7 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.%N '
+++ echo '2014-09-25 15:19:47.984064045 Creating partitions for disk /dev/sda (msdos)'
2014-09-25 15:19:47.984064045 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 17179869183B
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.V8HmdM8n8jkbfnx/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.V8HmdM8n8jkbfnx/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.V8HmdM8n8jkbfnx/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.V8HmdM8n8jkbfnx/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.V8HmdM8n8jkbfnx/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.V8HmdM8n8jkbfnx/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.%N '
+++ echo '2014-09-25 15:20:02.636955774 Creating LVM PV /dev/sda2'
2014-09-25 15:20:02.636955774 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_dellrhelqa2
+++ lvm pvcreate -ff --yes -v --uuid YSnfU0-LOME-28TF-1PUd-PEBl-RCyR-xxW8DH --norestorefile /dev/sda2
  WARNING: Forcing physical volume creation on /dev/sda2 of volume group "vg_dellrhelqa2"
    Set up physical volume for "/dev/sda2" with 32530360 available sectors
  Physical volume "/dev/sda2" successfully created
+++ component_created pv:/dev/sda2 lvmdev
+++ local device=pv:/dev/sda2
+++ local type=lvmdev
+++ local touchfile=lvmdev-pv:-dev-sda2
+++ touch /tmp/rear.V8HmdM8n8jkbfnx/tmp/touch/lvmdev-pv:-dev-sda2
+++ create_component /dev/vg_dellrhelqa2 lvmgrp
+++ local device=/dev/vg_dellrhelqa2
+++ local type=lvmgrp
+++ local touchfile=lvmgrp--dev-vg_dellrhelqa2
+++ '[' -e /tmp/rear.V8HmdM8n8jkbfnx/tmp/touch/lvmgrp--dev-vg_dellrhelqa2 ']'
+++ return 0
+++ LogPrint 'Creating LVM VG vg_dellrhelqa2'
+++ Log 'Creating LVM VG vg_dellrhelqa2'
+++ test 1 -gt 0
++++ Stamp
++++ date '+%Y-%m-%d %H:%M:%S.%N '
+++ echo '2014-09-25 15:20:02.874967116 Creating LVM VG vg_dellrhelqa2'
2014-09-25 15:20:02.874967116 Creating LVM VG vg_dellrhelqa2
+++ Print 'Creating LVM VG vg_dellrhelqa2'
+++ test 1
+++ echo -e 'Creating LVM VG vg_dellrhelqa2'
+++ '[' -e /dev/vg_dellrhelqa2 ']'
+++ lvm vgcreate --physicalextentsize 4096k vg_dellrhelqa2 /dev/sda2
  Volume group "vg_dellrhelqa2" successfully created
+++ lvm vgchange --available y vg_dellrhelqa2
  0 logical volume(s) in volume group "vg_dellrhelqa2" now active
+++ component_created /dev/vg_dellrhelqa2 lvmgrp
+++ local device=/dev/vg_dellrhelqa2
+++ local type=lvmgrp
+++ local touchfile=lvmgrp--dev-vg_dellrhelqa2
+++ touch /tmp/rear.V8HmdM8n8jkbfnx/tmp/touch/lvmgrp--dev-vg_dellrhelqa2
+++ create_component /dev/mapper/vg_dellrhelqa2-lv_root lvmvol
+++ local device=/dev/mapper/vg_dellrhelqa2-lv_root
+++ local type=lvmvol
+++ local touchfile=lvmvol--dev-mapper-vg_dellrhelqa2-lv_root
+++ '[' -e /tmp/rear.V8HmdM8n8jkbfnx/tmp/touch/lvmvol--dev-mapper-vg_dellrhelqa2-lv_root ']'
+++ return 0
+++ LogPrint 'Creating LVM volume vg_dellrhelqa2/lv_root'
+++ Log 'Creating LVM volume vg_dellrhelqa2/lv_root'
+++ test 1 -gt 0
++++ Stamp
++++ date '+%Y-%m-%d %H:%M:%S.%N '
+++ echo '2014-09-25 15:20:03.215972617 Creating LVM volume vg_dellrhelqa2/lv_root'
2014-09-25 15:20:03.215972617 Creating LVM volume vg_dellrhelqa2/lv_root
+++ Print 'Creating LVM volume vg_dellrhelqa2/lv_root'
+++ test 1
+++ echo -e 'Creating LVM volume vg_dellrhelqa2/lv_root'
+++ lvm lvcreate -l 12800 -n lv_root vg_dellrhelqa2
  Insufficient free extents (3970) in volume group vg_dellrhelqa2: 12800 required
2014-09-25 15:20:03.280451651 An error occurred during layout recreation.
2014-09-25 15:20:07.549341442 User selected: 6) Abort Relax-and-Recover
2014-09-25 15:20:07.551344523 Error detected during restore.
2014-09-25 15:20:07.553161408 Restoring backup of /var/lib/rear/layout/disklayout.conf
2014-09-25 15:20:07.556837795 ERROR: There was an error restoring the system layout. See /var/log/rear/rear-dellRHELqa2.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-dellRHELqa2.log for details.
===================
2014-09-25 15:20:07.563580723 Running exit tasks.
2014-09-25 15:20:07.566189135 Exit task 'cleanup_build_area_and_end_program'
2014-09-25 15:20:07.568060319 Finished in 51 seconds
2014-09-25 15:20:07.569859489 You should also rm -Rf /tmp/rear.V8HmdM8n8jkbfnx
2014-09-25 15:20:07.571891544 End of program reached
2014-09-25 15:20:07.573740999 Exit task 'exec 8>&-'
2014-09-25 15:20:07.575679344 Exit task 'exec 7>&-'