#1 2019-12-08 23:18:27

kulhan
Member
Registered: 2019-12-08
Posts: 4

VM crashes during hot backup quiesced

Hi,

after successful trial with free version I have upgraded to Pro, however it now regularly crashes all my VMs during backup.

Seems there is a problem with creating snapshots, please check the logfiles below.

The same backup definitin works just fine executed from XSI GUI, only the cron job causes crashes.

===== XSI log =====

2019-12-08T04:42:07|  XSIBackup will backup your VMs while they are running, so that users can continue to use the VM
2019-12-08T04:42:07|  while the backup is taking place. You can also run --backup-how=cold|warm
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:42:07|  Hot backup selected for VM: [pfsense], will not be switched off
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:42:08|  [pfsense] info: boot partition is MBR
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:42:08|  Removing snapshots, please wait...
---------------------------------------------------------------------------------------------------------------------------------
53/164 blocks | Processed 32%ESC[0K^M54/164 blocks | Processed 33%ESC[0K^M55/164 blocks | Processed 34%ESC[0K^M56/164 blocks | Processed 34%ESC[0K^M57/164
blocks | Processed 35%ESC[0K^M58/164 blocks | Processed 35%ESC[0K^M59/164 blocks | Processed 36%ESC[0K^M60/164 blocks | Processed 37%ESC[0K^M61/164 blocks
| Processed 37%ESC[0K^M62/164 blocks | Processed 38%ESC[0K^M63/164 blocks | Processed 39%ESC[0K^M20
19-12-08T04:42:22|  Syncronizing config files
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:42:25|  [pfsense] info: VMWare Tools detected, taking snapshot QUIESCED(true)...
---------------------------------------------------------------------------------------------------------------------------------
64/164 blocks | Processed 39%ESC[0K^M65/164 blocks | Processed 40%ESC[0K^M66/164 blocks | Processed 40%ESC[0K^M67/164 blocks | Processed 41%ESC[0K^M68/164
blocks | Processed 42%ESC[0K^M69/164 blocks | Processed 42%ESC[0K^M70/164 blocks | Processed 43%ESC[0K^M71/164 blocks | Processed 43%ESC[0K^M72/164 blocks
| Processed 44%ESC[0K^M73/164 blocks | Processed 45%ESC[0K^M74/164 blocks | Processed 45%ESC[0K^M75/164 blocks | Processed 46%ESC[0K^M76/164 blocks | Proce
ssed 46%ESC[0K^M77/164 blocks | Processed 47%ESC[0K^M78/164 blocks | Processed 48%ESC[0K^M79/164 blocks | Processed 48%ESC[0K^M20
19-12-08T04:44:00|  [pfsense] error CLCRESN1: cannot create snapshot, details: Create Snapshot:
2019-12-08T04:44:00|  Create snapshot failed
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:44:01|  [pfsense] workaround: could not create quiesced snapshot, trying non-quiesced
---------------------------------------------------------------------------------------------------------------------------------
80/164 blocks | Processed 49%ESC[0K^M81/164 blocks | Processed 50%ESC[0K^M2019-12-08T04:44:12|  [pfsense] warning CLCRESN3: non-quiesced snapshot taken as a workaround measure
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:44:13|  Backing up virtual disks...
---------------------------------------------------------------------------------------------------------------------------------
2019-12-08T04:44:14|  DISK=/vmfs/volumes/datastore1/pfsense/pfsense-000001-delta.vmdk

==========================================

vmware.log

2019-12-08T04:42:13.584Z| vmx| I125: ConsolidateMirrorCombineStart: Combine '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-000001.vmdk' -> '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk' (node = scsi0:0): 2 links starting from 0. usesCurrent = 1, isNative = 0
2019-12-08T04:42:13.584Z| vmx| I125: Mirror_DiskCopy: Starting disk copy.
2019-12-08T04:42:15.667Z| vcpu-0| I125: Destroying virtual dev for scsi0:0 vscsi=8390
2019-12-08T04:42:15.667Z| vcpu-0| I125: VMMon_VSCSIStopVports: No such target on adapter
2019-12-08T04:42:15.769Z| vcpu-0| I125: Closing disk 'scsi0:0'
2019-12-08T04:42:15.769Z| vcpu-0| I125: SVMotion_DiskCloseCB: Closing disks in svmPhase 0. Not destroying mirror node.
2019-12-08T04:42:15.769Z| vcpu-0| I125: ConsolidateDiskCloseCB: Closing disk node 'scsi0:0' after combining '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-000001.vmdk' -> '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk'.
2019-12-08T04:42:15.770Z| vcpu-0| I125: DDB: "longContentID" = "daae80c863d4577cd72efcbb245d0dba" (was "758ea4919c42ca04ab114f534413926b")
2019-12-08T04:42:18.719Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-000001-delta.vmdk" : closed.
2019-12-08T04:42:18.729Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk" : closed.
2019-12-08T04:42:18.742Z| vcpu-0| A100: ConfigDB: Setting scsi0:0.fileName = "pfsense.vmdk"
2019-12-08T04:42:18.831Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-000001-delta.vmdk" : open successful (1115153) size = 0, hd = 0. Type 9
2019-12-08T04:42:18.832Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-000001-delta.vmdk" : closed.
2019-12-08T04:42:19.342Z| vcpu-0| I125: Checkpoint_Unstun: vm stopped for 3675352 us
2019-12-08T04:42:19.342Z| vcpu-0| I125: SCSI: switching scsi0 to push completion mode
2019-12-08T04:42:19.411Z| vcpu-0| A100: ConfigDB: Setting scsi0:0.redo = ""
2019-12-08T04:42:19.411Z| vcpu-0| I125: DISK: OPEN scsi0:0 '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk' persistent R[]
2019-12-08T04:42:19.422Z| vcpu-0| I125: AIOGNRC: Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (40003) (0x2013).
2019-12-08T04:42:19.422Z| vcpu-0| I125: AIOMGR: AIOMgr_OpenWithRetry: Descriptor file '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' locked (try 0)
2019-12-08T04:42:19.724Z| vcpu-0| I125: AIOGNRC: Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (40003) (0x2013).
2019-12-08T04:42:19.724Z| vcpu-0| I125: AIOMGR: AIOMgr_OpenWithRetry: Descriptor file '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' locked (try 1)
2019-12-08T04:42:20.025Z| vcpu-0| I125: AIOGNRC: Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (40003) (0x2013).
2019-12-08T04:42:20.025Z| vcpu-0| I125: AIOMGR: AIOMgr_OpenWithRetry: Descriptor file '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' locked (try 2)
2019-12-08T04:42:20.325Z| vcpu-0| I125: AIOGNRC: Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (40003) (0x2013).
2019-12-08T04:42:20.325Z| vcpu-0| I125: AIOMGR: AIOMgr_OpenWithRetry: Descriptor file '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' locked (try 3)
2019-12-08T04:42:20.657Z| vcpu-0| I125: AIOGNRC: Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (40003) (0x2013).
2019-12-08T04:42:20.657Z| vcpu-0| I125: AIOMGR: AIOMgr_OpenWithRetry: Descriptor file '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' locked (try 4)
2019-12-08T04:42:20.959Z| vcpu-0| I125: AIOGNRC: Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (40003) (0x2013).
2019-12-08T04:42:20.959Z| vcpu-0| I125: OBJLIB-FILEBE : FileBEOpen: can't open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk' : Failed to lock the file (262146).
2019-12-08T04:42:20.959Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk" : failed to open (Failed to lock the file): ObjLib_Open failed. Type 3
2019-12-08T04:42:20.959Z| vcpu-0| I125: DISKLIB-LINK  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk" : failed to open (Failed to lock the file). 
2019-12-08T04:42:20.959Z| vcpu-0| I125: DISKLIB-CHAIN : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk" : failed to open (Failed to lock the file).
2019-12-08T04:42:21.007Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk" : open successful (524309) size = 8589934592, hd = 0. Type 3
2019-12-08T04:42:21.007Z| vcpu-0| I125: DISKLIB-VMFS  : "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense-flat.vmdk" : closed.
2019-12-08T04:42:21.007Z| vcpu-0| I125: DISKLIB-LIB   : Failed to open '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk' with flags 0xa Failed to lock the file (16392).
2019-12-08T04:42:21.007Z| vcpu-0| I125: DISK: Cannot open disk '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk': Failed to lock the file (16392).
2019-12-08T04:42:21.008Z| vcpu-0| I125: Msg_Post: Error
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [vob.fssvec.LookupAndOpen.file.failed] File system specific implementation of LookupAndOpen[file] failed
2019-12-08T04:42:21.008Z| vcpu-0| I125: [msg.fileio.lock] Failed to lock the file
2019-12-08T04:42:21.008Z| vcpu-0| I125: [msg.disk.noBackEnd] Cannot open the disk '/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/pfsense.vmdk' or one of the snapshot disks it depends on.
2019-12-08T04:42:21.008Z| vcpu-0| I125: [msg.checkpoint.continuesync.error] An operation required the virtual machine to quiesce and the virtual machine was unable to continue running.
2019-12-08T04:42:21.008Z| vcpu-0| I125: ----------------------------------------
2019-12-08T04:42:21.346Z| vcpu-0| I125: SnapshotVMX_ConsolidateCancel: Requesting snapshot consolidate cancel.
2019-12-08T04:42:21.346Z| vcpu-0| I125: Msg_Post: Error
2019-12-08T04:42:21.346Z| vcpu-0| I125: [msg.poweroff.commitOn] Performing disk cleanup. Cannot power off.
2019-12-08T04:42:21.346Z| vcpu-0| I125: ----------------------------------------
2019-12-08T04:42:21.348Z| vcpu-0| I125: ConsolidateEnd: Failed to stun/unstun virtual machine while consolidating disks.
2019-12-08T04:42:22.029Z| vcpu-0| I125: VigorTransport_ServerSendResponse opID=vim-cmd-a0-8c91 seq=1120051: Completed Snapshot request.
2019-12-08T04:42:22.029Z| vcpu-0| I125: Turning off snapshot info cache.
2019-12-08T04:42:22.040Z| vcpu-0| I125: Turning off snapshot disk cache.
2019-12-08T04:42:22.040Z| vcpu-0| I125: ConsolidateEnd: Snapshot consolidate complete: The operation completed successfully (0).
2019-12-08T04:42:22.040Z| vcpu-0| I125: Vix: [68988 mainDispatch.c:4234]: VMAutomation_ReportPowerOpFinished: statevar=3, newAppState=1881, success=1 additionalError=0
2019-12-08T04:42:25.050Z| vcpu-0| I125: LSI: VMK call failed: 0xbad000e CCB=0x7c759600 targ=0x0 lun=0x0 cmd=0x2a
2019-12-08T04:42:25.819Z| vmx| I125: VigorTransportProcessClientPayload: opID=vim-cmd-12-8d34 seq=1120350: Receiving Snapshot.Take request.
2019-12-08T04:42:25.819Z| vmx| I125: SnapshotVMX_TakeSnapshot start: 'xsibackup', deviceState=0, lazy=0, quiesced=1, forceNative=0, tryNative=1, saveAllocMaps=0 cb=DBE8A44A20, cbData=DBEA2003D0
2019-12-08T04:42:25Z[+0.156]| vmx| W115: Caught signal 11 -- tid 68981 (addr 80)
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: rip 0xdbe8f021c7 rsp 0x36d987e05c0 rbp 0x36d987e0630
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: rax 0x0 rbx 0xdbea27d1d0 rcx 0x2 rdx 0x1 rsi 0x36d987e05e0 rdi 0xdbea259350
2019-12-08T04:42:25Z[+0.156]| vmx| I125:         r8 0x36d987e0670 r9 0x0 r10 0x0 r11 0x36d987e01d8 r12 0xdbea17fb80 r13 0x36d987e0668 r14 0xdbe9f8ff50 r15 0x80
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E05C0 : 0x000000dbea12d5f0 0x000000db00000001
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E05D0 : 0x0000036d987e0670 0x000000db00000000
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E05E0 : 0x0000000000000000 0x000000dbe9f8ff50
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E05F0 : 0x0000036d987e06b0 0x000000dbea12d5f0
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E0600 : 0x000000dbe9f894c0 0x0000036d987e0720
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E0610 : 0x000000dbea17fb80 0x000000dbea27d1d0
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E0620 : 0x000000dbe9f8ff50 0x0000000000000080
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SIGNAL: stack 36D987E0630 : 0x0000036d987e06b0 0x000000dbe8f16754
2019-12-08T04:42:25Z[+0.156]| vmx| I125: Backtrace:
2019-12-08T04:42:25Z[+0.156]| vmx| I125: Backtrace[0] 0000036d987e0040 rip=000000dbe8eb0fc7 rbx=000000dbe8eb0ac0 rbp=0000036d987e0060 r12=0000000000000000 r13=000000dbe9b47b01 r14=000000000000000a r15=0000036d987e0640
2019-12-08T04:42:25Z[+0.156]| vmx| I125: Backtrace[1] 0000036d987e0070 rip=000000dbe90e2660 rbx=0000036d987e0640 rbp=0000036d987e0280 r12=000000000000000b r13=000000dbe9b47b01 r14=000000000000000a r15=0000036d987e0640
2019-12-08T04:42:25Z[+0.156]| vmx| I125: Backtrace[2] 0000036d987e0290 rip=000000dbe90e2a64 rbx=0000000000000000 rbp=0000036d987e02e0 r12=000000dc2c0bb378 r13=000000dbe9b47b28 r14=000000dbe9b47b20 r15=000000000000000b
2019-12-08T04:42:25Z[+0.156]| vmx| I125: Backtrace[3] 0000036d987e02f0 rip=000000000039500f rbx=000000dbea27d1d0 rbp=0000036d987e0530 r12=0000036d987e0370 r13=0000036d987e0668 r14=000000dbe9f8ff50 r15=0000000000000080
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SymBacktrace[0] 0000036d987e0040 rip=000000dbe8eb0fc7 in function (null) in object /bin/vmx loaded at 000000dbe8834000
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SymBacktrace[1] 0000036d987e0070 rip=000000dbe90e2660 in function (null) in object /bin/vmx loaded at 000000dbe8834000
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SymBacktrace[2] 0000036d987e0290 rip=000000dbe90e2a64 in function (null) in object /bin/vmx loaded at 000000dbe8834000
2019-12-08T04:42:25Z[+0.156]| vmx| I125: SymBacktrace[3] 0000036d987e02f0 rip=000000000039500f
2019-12-08T04:42:25Z[+0.156]| vmx| E105: PANIC: Unexpected signal: 11.
2019-12-08T04:42:25Z[+87.979]| vmx| W115: A core file is available in "/vmfs/volumes/5a26ad1d-f05d61a4-2be6-5065f3f0a94c/pfsense/vmx-zdump.000"
2019-12-08T04:43:53.820Z| mks| W115: Panic in progress... ungrabbing
2019-12-08T04:43:53.820Z| mks| I125: MKS: Release starting (Panic)
2019-12-08T04:43:53.820Z| mks| I125: MKS: Release finished (Panic)
2019-12-08T04:43:53Z[+0.341]| vmx| I125: Writing monitor file `vmmcores.gz`
2019-12-08T04:43:53Z[+0.342]| vmx| W115: Dumping core for vcpu-0
2019-12-08T04:43:53Z[+0.342]| vmx| I125: CoreDump: dumping core with superuser privileges
2019-12-08T04:43:53Z[+0.342]| vmx| I125: VMK Stack for vcpu 0 is at 0x43912bb13000
2019-12-08T04:43:53Z[+0.342]| vmx| I125: Beginning monitor coredump
2019-12-08T04:43:54.801Z| mks| W115: Panic in progress... ungrabbing
2019-12-08T04:43:54.805Z| mks| I125: MKS: Release starting (Panic)
2019-12-08T04:43:54.805Z| mks| I125: MKS: Release finished (Panic)
2019-12-08T04:43:54Z[+0.035]| vmx| I125: End monitor coredump

Offline

#2 2019-12-09 13:07:30

admin
Administrator
Registered: 2017-04-21
Posts: 1,362

Re: VM crashes during hot backup quiesced

Well, the job is the very same, no matter if you launch it from the GUI or from the cron.
This seems to have to do with the time you launch the backup more than whether you launch it from the GUI or from the cron.
Try to use --backup-how=warm instead while you look for the root of the problem. A host reboot can also be a good idea in these cases.

Offline

#3 2019-12-10 02:42:29

kulhan
Member
Registered: 2019-12-08
Posts: 4

Re: VM crashes during hot backup quiesced

There is no collision with other jobs, nothing else running from crontab at the same time.

However, after reconfiguration and removal of the quiesce parameter it seems to run fine. I mean, it did not crash any VM for two days, which is definitely an improvement :-)

Offline

#4 2019-12-10 10:29:08

admin
Administrator
Registered: 2017-04-21
Posts: 1,362

Re: VM crashes during hot backup quiesced

Well, PFSense was based on FreeBSD, I guess it still does, right?:

- Have you installed open-vm-tools in it?
- Are you confident they are running?
- Do you know what services you need to quiesce in PFSense?, some DB maybe?
- Does this DB support quiescing through open-vm-tools?

Those are some of the check points you should go through before attempting to quiesce some OS/ Service. Quiescing is not a "just set quiescing option" operation.

Offline

#5 2019-12-10 10:36:13

kulhan
Member
Registered: 2019-12-08
Posts: 4

Re: VM crashes during hot backup quiesced

OK, I was too quick with the quiesce parameter. One VM has crashed tonight. No other job was running.

Backup definitions:

Old one, working fine (free version, 9.1.9)
=================

${XSI} --time="Tue 04:00|Fri 04:00" \
--backup-point="/vmfs/volumes/datastore1/backup/" \
--backup-vms="pfsense,WS2008!WS2008_1.vmdk" \
--backup-type=custom \
--backup-how=hot

================

new one, VMs crashing - PRO 11.2.12
----------------------------

--backup-prog=XSITools:z \
--backup-point=/vmfs/volumes/datastore1/backup/xsidata \
--backup-type=Custom \
--backup-vms="WS2008!WS2008_1.vmdk,pfsense" \
--backup-how=Hot \
--del-dirs=+14d \
--backup-id=daily \
--description="fw and money" \
--exec=yes

========================

vmware.log
--------------------
2019-12-10T04:29:50.484Z| vmx| I125: VigorTransportProcessClientPayload: opID=vim-cmd-9f-288a seq=1247322: Receiving Snapshot.Take request.
2019-12-10T04:29:50.484Z| vmx| I125: SnapshotVMX_TakeSnapshot start: 'xsibackup', deviceState=0, lazy=0, quiesced=0, forceNative=0, tryNative=1, saveAllocMaps=0 cb=4E813ACA20, cbData=4E828FDAA0
2019-12-10T04:29:50Z[+0.201]| vmx| W115: Caught signal 11 -- tid 6922849 (addr 4E8186A1C4)

HPE Customized Image ESXi 6.5.0 Update 1 version 650.U1.9.6.5


Unless there is a known remedy I will probably ask for a money back and switch to another solution. Not really happy being dragged out of my bed by end users complaining about dead system.

Offline

#6 2019-12-10 17:37:30

admin
Administrator
Registered: 2017-04-21
Posts: 1,362

Re: VM crashes during hot backup quiesced

(c)XSIBackup requests the ESXi system to take a snapshot on a given VM, but it doesn't take the snapshot itself. The messages you are posting aren't even produced by any (c)XSIBackup code.

Your system has become unstable and it fails to take a snapshot when requested to, that's where all your problems are coming from. We have plenty of experience with ESXi and we do know this might happen from time to time. First thing you should do is reboot the host whenever you have the chance to, this will most probably fix any issue.

If you continue to experience problems after a reboot, contact support, where we will be able to delve a bit more into your problem. In any case, as said, all that you seem to be suffering from is an unstable system, most probably due to memory corruption.

Offline

#7 2019-12-11 10:15:52

kulhan
Member
Registered: 2019-12-08
Posts: 4

Re: VM crashes during hot backup quiesced

It is worth mentioning that the instability is directly related to the running XSI backup as you can see even from the vmware.log file. It has never been experieced before upgrading to XSIbackup PRO, so please do not try to convince me that the VM crashes are not related to XSIBackup.

And yet again, the backup runs fine with the old version of XSIBackup Free. The problem is caused by the new version.

Offline

Board footer