Comprehensive data protection for all workloads
Post Reply
stuartmacgreen
Expert
Posts: 149
Liked: 34 times
Joined: May 01, 2012 11:56 am
Full Name: Stuart Green
Contact:
Contact stuartmacgreen

Explorer for Oracle fails to restore. Mount issue with LVM

Post by stuartmacgreen »

Support case ID: 01900942

First attempt at restoring Oracle database using Veeam 9 U2 and fails at the Mounting stage. Using "Restore to latest state to" source VM the backup was taken.

VM Guest OS: SUSE Linux Enterprise 11 SP4 (64bit)
Oracle: 11.2.0.4.0 - Enterprise 64BIT PRODUCTION
Oracle Database is stored on LVM Volumes within the Linux OS.
It is not Oracle ASM

Backup is successful every time. Just database backups no transaction logging taking place.

VEfO dialog throws this message:
Agent failed to process method {Mount.GenericMount}

Invalid shift offset: [62272831488]. Device size: [53686894592]
Digging deeper into logs shows that it enumerates disks , partitions and LVM Volume Groups from the backup files. Then just states it fails.

Reaching out to anyone come across problems or sticking issues they got resolved. Can't fathom whats going on.


The target VM for the restore is the source of the backup.

On this VM the contents of the log file detail the issue
/var/log/VeeamBackup/Agent.MountHost.log_cli.log

Code: Select all

[20.09.2016 13:42:37] <140186332604160> cli| Mount.GenericMount
[20.09.2016 13:42:37] <140186332604160> cli|   (EString) Mounter.DisksMountPath = /tmp/Veeam.Mount.Disks.d9493877-2791-4682-a000-e48347ecfe03
[20.09.2016 13:42:37] <140186332604160> cli|   (EString) Mounter.FsMountPath = /tmp/Veeam.Mount.FS.d9493877-2791-4682-a000-e48347ecfe03
[20.09.2016 13:42:37] <140186332604160> cli|   (EString) Mounter.Type = FUSE
[20.09.2016 13:42:37] <140186332604160> cli|   (EString) Processing.Part[0].Type = OracleAsm
[20.09.2016 13:42:37] <140186332604160> cli|   (EStringArray) Source.InBackupFiles =
[20.09.2016 13:42:37] <140186332604160> cli|   {
[20.09.2016 13:42:37] <140186332604160> cli|     077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_4-flat.vmdk,
[20.09.2016 13:42:37] <140186332604160> cli|     077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_1-flat.vmdk,
[20.09.2016 13:42:37] <140186332604160> cli|     077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_5-flat.vmdk,
[20.09.2016 13:42:37] <140186332604160> cli|     077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk,
[20.09.2016 13:42:37] <140186332604160> cli|     077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_2-flat.vmdk,
[20.09.2016 13:42:37] <140186332604160> cli|     077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_6-flat.vmdk
[20.09.2016 13:42:37] <140186332604160> cli|   }
[20.09.2016 13:42:37] <140186332604160> cli|   (EStringArray) Source.Storages =
[20.09.2016 13:42:37] <140186332604160> cli|   {
[20.09.2016 13:42:37] <140186332604160> cli|     G:\SLES Test ORACLE\JPINKMAN.vm-748552016-09-19T134305.vib,
[20.09.2016 13:42:37] <140186332604160> cli|     G:\SLES Test ORACLE\JPINKMAN.vm-748552016-09-14T092955.vbk
[20.09.2016 13:42:37] <140186332604160> cli|   }
[20.09.2016 13:42:37] <140186332604160> cli|   (EString) Source.Type = Backup
[20.09.2016 13:42:37] <140186332604160> cli| - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
[20.09.2016 13:42:37] <140186332604160> cli| Performing mount.
[20.09.2016 13:42:37] <140186332604160> stg|   Opening remote backup for random access. Files for restore: [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_4-flat.vmdk;077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_1-flat.vmdk;077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_5-flat.vmdk;077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk;077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_2-flat.vmdk;077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_6-flat.vmdk]. Backups: [G:\SLES Test ORACLE\JPINKMAN.vm-748552016-09-19T134305.vib;G:\SLES Test ORACLE\JPINKMAN.vm-748552016-09-14T092955.vbk].
[20.09.2016 13:42:37] <140186332604160> cli|     Initializing remote mount session. Session type: 0.
[20.09.2016 13:42:37] <140186332604160> stg|     Request was queued to the remote agent. Waiting for acknowledge
[20.09.2016 13:42:39] <140186332604160> stg|     Acknowledge received. Backup successfully opened by the remote agent. Block size: [1048576].
[20.09.2016 13:42:39] <140186332604160> cli|   Backup item metadata is available.
[20.09.2016 13:42:39] <140186332604160> cli|     DefinedBlocksMask:  bin:14 01 00 00 00 00 00 00 17 00 00 00 00 00 00 00 78 da 63 60 60 68 60 00 03 01 06 06 0e 08 eb ff 08 07 00 a9 6c ff 99
[20.09.2016 13:42:39] <140186332604160> cli|   Backup item metadata is available.
[20.09.2016 13:42:39] <140186332604160> cli|     DefinedBlocksMask:  bin:14 04 00 00 00 00 00 00 1e 00 00 00 00 00 00 00 78 da 63 60 60 60 60 62 00 01 01 06 06 05 30 83 e1 ff 28 18 05 a3 60 c4 02 00 43 69 fc 60
[20.09.2016 13:42:39] <140186332604160> cli|   Backup item metadata is available.
[20.09.2016 13:42:39] <140186332604160> cli|     DefinedBlocksMask:  bin:14 0f 00 00 00 00 00 00 27 00 00 00 00 00 00 00 78 da ed c6 a1 11 c0 20 00 00 b1 77 d8 8e 8b 64 73 7a b0 06 89 4a b5 46 c7 57 f3 a6 0d 00 00 00 0f f8 01 88 0f f2 e2
[20.09.2016 13:42:39] <140186332604160> cli|   Backup item metadata is available.
[20.09.2016 13:42:39] <140186332604160> cli|     DefinedBlocksMask:  bin:14 05 00 00 00 00 00 00 20 00 00 00 00 00 00 00 78 da 63 60 60 68 60 62 00 01 01 06 06 0d 30 83 e1 ff 28 18 05 a3 60 14 8c 50 00 00 6a 12 fb f7
[20.09.2016 13:42:39] <140186332604160> cli|   Backup item metadata is available.
[20.09.2016 13:42:39] <140186332604160> cli|     DefinedBlocksMask:  bin:14 3b 00 00 00 00 00 00 34 00 00 00 00 00 00 00 78 da ed c6 31 11 00 20 0c 04 b0 c7 01 06 ea 15 99 b8 81 a3 2a 18 92 29 49 56 e5 99 c9 1e bd 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 1f b9 b2 e2 c9 ed
[20.09.2016 13:42:39] <140186332604160> cli|   Backup item metadata is available.
[20.09.2016 13:42:39] <140186332604160> cli|     DefinedBlocksMask:  bin:14 20 00 00 00 00 00 00 2a 00 00 00 00 00 00 00 78 da ed c6 c1 09 00 20 10 c0 b0 ba 81 fb 2f 7b 82 b8 84 90 3c 4a ab 76 bd ae 7b 03 00 00 00 00 00 00 00 7c ef 00 16 a8 e1 f3
[20.09.2016 13:42:39] <140186332604160> cli|   Intrusive data processing is required. Creating memory cached device objects.
[20.09.2016 13:42:39] <140186332604160> cli|   Parsing partition table on [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_4-flat.vmdk (mem cached)].
[20.09.2016 13:42:39] <140186332604160> dsk|     Oracle ASM label replacer: processing layout on device 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_4-flat.vmdk (mem cached).
[20.09.2016 13:42:39] <140186332604160> dsk|       Found disk partitions layout of type: [mbr].
[20.09.2016 13:42:39] <140186332604160> dsk|       Processing mbr/0.
[20.09.2016 13:42:39] <140186332604160> dsk|       Trying to read ASM label on device [Disk 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_4-flat.vmdk (mem cached), partition at offset 1048576].
[20.09.2016 13:42:39] <140186332604160> dsk|       No ASM label found.
[20.09.2016 13:42:39] <140186332604160> dsk|     ASM label was not found.
[20.09.2016 13:42:39] <140186332604160> cli|   Parsing partition table on [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_1-flat.vmdk (mem cached)].
[20.09.2016 13:42:39] <140186332604160> dsk|     Oracle ASM label replacer: processing layout on device 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_1-flat.vmdk (mem cached).
[20.09.2016 13:42:39] <140186332604160> dsk|       Found disk partitions layout of type: [mbr].
[20.09.2016 13:42:39] <140186332604160> dsk|       Processing mbr/0.
[20.09.2016 13:42:39] <140186332604160> dsk|       Trying to read ASM label on device [Disk 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_1-flat.vmdk (mem cached), partition at offset 32256].
[20.09.2016 13:42:39] <140186332604160> dsk|       No ASM label found.
[20.09.2016 13:42:39] <140186332604160> dsk|     ASM label was not found.
[20.09.2016 13:42:39] <140186332604160> cli|   Parsing partition table on [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_5-flat.vmdk (mem cached)].
[20.09.2016 13:42:39] <140186332604160> dsk|     Oracle ASM label replacer: processing layout on device 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_5-flat.vmdk (mem cached).
[20.09.2016 13:42:39] <140186332604160> dsk|       Found disk partitions layout of type: [mbr].
[20.09.2016 13:42:39] <140186332604160> dsk|       Processing mbr/0.
[20.09.2016 13:42:39] <140186332604160> dsk|       Trying to read ASM label on device [Disk 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_5-flat.vmdk (mem cached), partition at offset 1048576].
[20.09.2016 13:42:39] <140186332604160> dsk|       No ASM label found.
[20.09.2016 13:42:39] <140186332604160> dsk|     ASM label was not found.
[20.09.2016 13:42:39] <140186332604160> cli|   Parsing partition table on [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk (mem cached)].
[20.09.2016 13:42:39] <140186332604160> dsk|     Oracle ASM label replacer: processing layout on device 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk (mem cached).
[20.09.2016 13:42:39] <140186332604160> dsk|       Found disk partitions layout of type: [mbr].
[20.09.2016 13:42:39] <140186332604160> dsk|       Processing mbr/0.
[20.09.2016 13:42:39] <140186332604160> dsk|       Trying to read ASM label on device [Disk 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk (mem cached), partition at offset 32256].
[20.09.2016 13:42:39] <140186332604160> dsk|       No ASM label found.
[20.09.2016 13:42:39] <140186332604160> dsk|       Processing mbr/1.
[20.09.2016 13:42:39] <140186332604160> dsk|       Trying to read ASM label on device [Disk 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk (mem cached), partition at offset 106928640].
[20.09.2016 13:42:39] <140186332604160> dsk|       No ASM label found.
[20.09.2016 13:42:39] <140186332604160> dsk|       Processing mbr/2.
[20.09.2016 13:42:39] <140186332604160> dsk|       Trying to read ASM label on device [Disk 077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_3-flat.vmdk (mem cached), partition at offset 9236989440].
[20.09.2016 13:42:39] <140186332604160> dsk|       No ASM label found.
[20.09.2016 13:42:39] <140186332604160> dsk|     ASM label was not found.
[20.09.2016 13:42:39] <140186332604160> cli|   Detecting LVM physical volumes.
[20.09.2016 13:42:39] <140186332604160> dsk|     Enumerating LVM physical volumes.
[20.09.2016 13:42:39] <140186332604160> dsk|       Loaded metadata region content at offset: [4096].
[20.09.2016 13:42:39] <140186332604160> dsk|       LVM physical volume detected: [uVJFVz-eFwV-d5lD-ohKU-WzT7-8oV4-3WkiCN]. Device: [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_2-flat.vmdk (mem cached)].
[20.09.2016 13:42:39] <140186332604160> dsk|       Loaded metadata region content at offset: [4096].
[20.09.2016 13:42:39] <140186332604160> dsk|       LVM physical volume detected: [Q7Kui7-fEyg-dUS7-lSd6-xcwo-tlLW-uTWVNZ]. Device: [077f509f-feaf-4e52-82a9-0b679669f9b5 (vm-74855)\JPINKMAN_6-flat.vmdk (mem cached)].
[20.09.2016 13:42:39] <140186332604160> dsk|     Enumerating LVM physical volumes: [2] found.
[20.09.2016 13:42:39] <140186332604160> cli|   Detecting LVM physical volumes.
[20.09.2016 13:42:39] <140186332604160> dsk|     Enumerating LVM physical volumes.
[20.09.2016 13:42:39] <140186332604160> dsk|     Enumerating LVM physical volumes: [2] found.
[20.09.2016 13:42:39] <140186332604160> cli|   Extracting LVM logical volumes from device list...
[20.09.2016 13:42:39] <140186332604160> dsk|     Loading LVM volume groups...
[20.09.2016 13:42:39] <140186332604160> dsk|       Loading LVM volume groups metadata.
[20.09.2016 13:42:39] <140186332604160> dsk|         Parsing volume group metadata on physical volume: [uVJFVz-eFwV-d5lD-ohKU-WzT7-8oV4-3WkiCN].
[20.09.2016 13:42:39] <140186332604160> dsk|         Parsing volume group metadata on physical volume: [Q7Kui7-fEyg-dUS7-lSd6-xcwo-tlLW-uTWVNZ].
[20.09.2016 13:42:39] <140186332604160> dsk|       Loading LVM volume groups metadata: [2] found.
[20.09.2016 13:42:39] <140186332604160> dsk|       Loading volume group [stu_dg1].
[20.09.2016 13:42:39] <140186332604160> dsk|         Physical extent size: [4194304].
[20.09.2016 13:42:39] <140186332604160> dsk|         Trying to resolve volume [dbhome].
[20.09.2016 13:42:39] <140186332604160> dsk|           Building striped segment.
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating shifted device. First extent: [0]. Extent size: [4194304].
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating linear device of size [15032385536].
[20.09.2016 13:42:39] <140186332604160> dsk|           Building striped segment.
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating shifted device. First extent: [12799]. Extent size: [4194304].
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating linear device of size [7516192768].
[20.09.2016 13:42:39] <140186332604160> dsk|           Building striped segment.
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating shifted device. First extent: [3841]. Extent size: [4194304].
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating linear device of size [2042626048].
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating segmented device.
[20.09.2016 13:42:39] <140186332604160> dsk|             Segment size: [15032385536].
[20.09.2016 13:42:39] <140186332604160> dsk|             Segment size: [7516192768].
[20.09.2016 13:42:39] <140186332604160> dsk|             Segment size: [2042626048].
[20.09.2016 13:42:39] <140186332604160> dsk|           Overall device size: [24591204352].
[20.09.2016 13:42:39] <140186332604160> dsk|         Resolved LVM logical volume: [dbhome] with id [LeLFkd-P9J7-QDhx-riLc-dRFy-KcjW-Hav0iT].
[20.09.2016 13:42:39] <140186332604160> dsk|         Trying to resolve volume [saparch].
[20.09.2016 13:42:39] <140186332604160> dsk|           Building striped segment.
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating shifted device. First extent: [4352]. Extent size: [4194304].
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating linear device of size [16106127360].
[20.09.2016 13:42:39] <140186332604160> dsk|           Building striped segment.
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating shifted device. First extent: [14847]. Extent size: [4194304].
[20.09.2016 13:42:39] <140186332604160> dsk|           Creating shifted device. First extent: [14847]. Extent size: [4194304]. Failed.
[20.09.2016 13:42:39] <140186332604160> dsk|         Trying to resolve volume [saparch]. Failed.
[20.09.2016 13:42:39] <140186332604160> dsk|       Loading volume group [stu_dg1]. Failed.
[20.09.2016 13:42:39] <140186332604160> dsk|     Loading LVM volume groups... Failed.
[20.09.2016 13:42:39] <140186332604160> cli|   Extracting LVM logical volumes from device list... Failed.
[20.09.2016 13:42:39] <140186332604160> cli| Performing mount. Failed.
[20.09.2016 13:42:39] <140186332604160> cli| Stopping remote mount session
The SLES OS LVM layout looks like this

Code: Select all

# pvs
  PV         VG      Fmt  Attr PSize   PFree
  /dev/sdc   stu_dg1 lvm2 a--   64.00g 4.00g
  /dev/sdd   stu_dg2 lvm2 a--  118.00g    0
Tue Sep 20@14:36:17
# lvs
  LV      VG      Attr      LSize   Pool Origin Data%  Move Log Copy%  Convert
  dbhome  stu_dg1 -wi-ao---  22.90g
  saparch stu_dg1 -wi-ao---  21.00g
  sapdb   stu_dg1 -wi-ao---   9.09g
  sapmnt  stu_dg1 -wi-ao---   5.00g
  usr_sap stu_dg1 -wi-ao---   2.00g
  sapdata stu_dg2 -wi-ao--- 118.00g
The filesystem looks like this:

Code: Select all

# df -h
Filesystem                                       Size       Used      Avail     Use% Mounted
/dev/sda2                                        8.4G       6.8G       1.2G      86% /
udev                                             4.0G       152K       4.0G       1% /dev
tmpfs                                             12G       656K        12G       1% /dev/shm
/dev/sda1                                         99M        26M        69M      28% /boot
/dev/sda3                                        1.4G       292M       1.1G      22% /tmp
/dev/mapper/stu_dg1-dbhome                        23G        13G        11G      53% /oracle/STU
/dev/mapper/stu_dg1-saparch                       21G       2.5G        19G      12% /oracle/STU/saparch
/dev/mapper/stu_dg1-sapmnt                       5.0G       1.3G       3.8G      26% /sapmnt/STU
/dev/mapper/stu_dg1-usr_sap                      2.0G       1.8G       296M      86% /usr/sap/STU
/dev/mapper/stu_dg1-sapdb                        9.1G       6.6G       2.6G      72% /sapdb
/dev/mapper/stu_dg2-sapdata                      118G       104G        15G      89% /oracle/STU/sapdata1
/dev/sde1                                         30G       2.0G        28G       7% /oracle/stage
/dev/sdf1                                        2.0G       1.6G       446M      78% /usr/sap/DAA
/dev/sde1                                         30G       2.0G        28G       7% /usr/sap/trans
Top
Mike Resseler
Product Manager
Posts: 8045
Liked: 1263 times
Joined: Feb 08, 2013 3:08 pm
Full Name: Mike Resseler
Location: Belgium
Contact:
Contact Mike Resseler

Re: Explorer for Oracle fails to restore. Mount issue with L

Post by Mike Resseler »

Hey,

I'm no expert in Oracle but what I do see is that you are using SUSE 11 with Oracle 11 and according to our release notes we only support SUSE 12 WITH oracle 12 so this might be an issue. (https://www.veeam.com/pdf/release_notes ... tes_en.pdf) However, since you already have a support case, let's wait what support have to say

Please keep this thread updated

Many thanks
Mike
Top
Post Reply

Return to “Veeam Backup & Replication”



Who is online

Users browsing this forum: Bing [Bot] and 71 guests