search

lamw / ghettoVCB

ghettoVCB
MIT License
1.29k stars 365 forks source link

Issue on backup VM #236

Closed ucola closed 3 years ago

ucola commented 3 years ago

Hi all

I know a lot of posts with error cases, but no one helps me...

We have on our ESXi 5 VMs, all works fine, but one fails. The log is bellow. Any ideas? Thank for helping

Logging output to "/tmp/ghettoVCB-2021-04-16_01-00-01-2571945.log" ...
2021-04-16 01:00:01 -- info: ============================== ghettoVCB LOG START ==============================

2021-04-16 01:00:01 -- debug: Succesfully acquired lock directory - /tmp/ghettoVCB.work

2021-04-16 01:00:01 -- debug: HOST VERSION: VMware ESXi 6.7.0 build-17499825
2021-04-16 01:00:01 -- debug: HOST LEVEL: VMware ESXi 6.7.0 Update 3
2021-04-16 01:00:01 -- debug: HOSTNAME: localhost

2021-04-16 01:00:01 -- info: CONFIG - USING GLOBAL GHETTOVCB CONFIGURATION FILE = /vmfs/volumes/datastore1/_configs/ghettoVCB.conf
2021-04-16 01:00:01 -- info: CONFIG - VERSION = 2020_10_10_4
2021-04-16 01:00:01 -- info: CONFIG - GHETTOVCB_PID = 2571945
2021-04-16 01:00:01 -- info: CONFIG - VM_BACKUP_VOLUME = /vmfs/volumes/datastore1/_backup
2021-04-16 01:00:02 -- info: CONFIG - ENABLE_NON_PERSISTENT_NFS = 0
2021-04-16 01:00:02 -- info: CONFIG - VM_BACKUP_ROTATION_COUNT = 7
2021-04-16 01:00:02 -- info: CONFIG - VM_BACKUP_DIR_NAMING_CONVENTION = 2021-04-16_01-00-00
2021-04-16 01:00:02 -- info: CONFIG - DISK_BACKUP_FORMAT = thin
2021-04-16 01:00:02 -- info: CONFIG - POWER_VM_DOWN_BEFORE_BACKUP = 0
2021-04-16 01:00:02 -- info: CONFIG - ENABLE_HARD_POWER_OFF = 0
2021-04-16 01:00:02 -- info: CONFIG - ITER_TO_WAIT_SHUTDOWN = 3
2021-04-16 01:00:02 -- info: CONFIG - POWER_DOWN_TIMEOUT = 5
2021-04-16 01:00:02 -- info: CONFIG - SNAPSHOT_TIMEOUT = 15
2021-04-16 01:00:02 -- info: CONFIG - LOG_LEVEL = debug
2021-04-16 01:00:02 -- info: CONFIG - BACKUP_LOG_OUTPUT = /tmp/ghettoVCB-2021-04-16_01-00-01-2571945.log
2021-04-16 01:00:02 -- info: CONFIG - ENABLE_COMPRESSION = 0
2021-04-16 01:00:02 -- info: CONFIG - VM_SNAPSHOT_MEMORY = 0
2021-04-16 01:00:02 -- info: CONFIG - VM_SNAPSHOT_QUIESCE = 0
2021-04-16 01:00:02 -- info: CONFIG - ALLOW_VMS_WITH_SNAPSHOTS_TO_BE_BACKEDUP = 1
2021-04-16 01:00:02 -- info: CONFIG - VMDK_FILES_TO_BACKUP = all
2021-04-16 01:00:02 -- info: CONFIG - VM_SHUTDOWN_ORDER = 
2021-04-16 01:00:02 -- info: CONFIG - VM_STARTUP_ORDER = 
2021-04-16 01:00:02 -- info: CONFIG - RSYNC_LINK = 0
2021-04-16 01:00:02 -- info: CONFIG - BACKUP_FILES_CHMOD = 
2021-04-16 01:00:02 -- info: CONFIG - EMAIL_LOG = 0
2021-04-16 01:00:02 -- info: CONFIG - ENABLE NFS IO HACK = 0

2021-04-16 01:00:05 -- debug: Storage Information before backup: 
2021-04-16 01:00:05 -- debug: SRC_DATASTORE: datastore1
2021-04-16 01:00:05 -- debug: SRC_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 01:00:05 -- debug: SRC_DATASTORE_FREE: 1263.0 GB
2021-04-16 01:00:05 -- debug: SRC_DATASTORE_BLOCKSIZE: 1
2021-04-16 01:00:05 -- debug: SRC_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 01:00:05 -- debug: 
2021-04-16 01:00:05 -- debug: DST_DATASTORE: datastore1
2021-04-16 01:00:05 -- debug: DST_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 02:32:38 -- debug: SRC_DATASTORE_FREE: 1112.5 GB
2021-04-16 02:32:38 -- debug: SRC_DATASTORE_BLOCKSIZE: 1
2021-04-16 02:32:38 -- debug: SRC_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 02:32:38 -- debug: 
2021-04-16 02:32:38 -- debug: DST_DATASTORE: datastore1
2021-04-16 02:32:38 -- debug: DST_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 02:32:38 -- debug: DST_DATASTORE_FREE: 1112.5 GB
2021-04-16 02:32:38 -- debug: DST_DATASTORE_BLOCKSIZE: 1
2021-04-16 02:32:38 -- debug: DST_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 02:32:38 -- debug: 
2021-04-16 02:32:40 -- debug: Storage Information before backup: 
2021-04-16 02:32:40 -- debug: SRC_DATASTORE: datastore1
2021-04-16 02:32:40 -- debug: SRC_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 02:32:40 -- debug: SRC_DATASTORE_FREE: 1112.5 GB
2021-04-16 02:32:40 -- debug: SRC_DATASTORE_BLOCKSIZE: 1
2021-04-16 02:32:41 -- debug: SRC_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 02:32:41 -- debug: 
2021-04-16 02:32:41 -- debug: DST_DATASTORE: datastore1
2021-04-16 02:32:41 -- debug: DST_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 02:32:41 -- debug: DST_DATASTORE_FREE: 1112.5 GB
2021-04-16 02:32:41 -- debug: DST_DATASTORE_BLOCKSIZE: 1
2021-04-16 02:32:41 -- debug: DST_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 02:32:41 -- debug: 
2021-04-16 02:32:41 -- debug: getVMDKs() - srvvl02_1.vmdk###1000:
2021-04-16 02:32:42 -- info: Initiate backup for srvvl02
2021-04-16 02:32:42 -- info: Creating Snapshot "ghettoVCB-snapshot-2021-04-16" for srvvl02
2021-04-16 02:32:42 -- debug: Waiting for snapshot "ghettoVCB-snapshot-2021-04-16" to be created
2021-04-16 02:32:42 -- debug: Snapshot timeout set to: 900 seconds
2021-04-16 02:32:43 -- debug: findVMDK() - Searching for VMDK: "srvvl02_1.vmdk" to backup
2021-04-16 02:32:43 -- debug: /sbin/vmkfstools -i "/vmfs/volumes/datastore1/srvvl02/srvvl02_1.vmdk" -a "lsilogic" -d "thin" "/vmfs/volumes/datastore1/_backup/srvvl02/srvvl02-2021-04-16_01-00-00/srvvl02_1.vmdk"
Option --adaptertype is deprecated and hence will be ignored
Destination disk format: VMFS thin-provisioned
Cloning disk '/vmfs/volumes/datastore1/srvvl02/srvvl02_1.vmdk'...

Clone: 10% done.
Clone: 11% done.
Clone: 12% done.
Clone: 13% done.
Clone: 14% done.
Clone: 15% done.
Clone: 16% done.
Clone: 17% done.
Clone: 18% done.
Clone: 19% done.
Clone: 20% done.
Clone: 21% done.
Clone: 22% done.
Clone: 23% done.
Clone: 24% done.
Clone: 25% done.
Clone: 26% done.
Clone: 27% done.
Clone: 28% done.
Clone: 29% done.
Clone: 30% done.
Clone: 31% done.
Clone: 32% done.
Clone: 33% done.
Clone: 34% done.
Clone: 35% done.
Clone: 36% done.
Clone: 37% done.
Clone: 38% done.
Clone: 39% done.
Clone: 40% done.
Clone: 41% done.
Clone: 42% done.
Clone: 43% done.
Clone: 44% done.
Clone: 45% done.
Clone: 46% done.
Clone: 47% done.
Clone: 48% done.
Clone: 49% done.
Clone: 50% done.
Clone: 51% done.
Clone: 52% done.
Clone: 53% done.
Clone: 54% done.
Clone: 55% done.
Clone: 56% done.
Clone: 57% done.
Clone: 58% done.
Clone: 59% done.
Clone: 60% done.
Clone: 61% done.
Clone: 62% done.
Clone: 63% done.
Clone: 64% done.
Clone: 65% done.
Clone: 66% done.
Clone: 67% done.
Clone: 68% done.
Clone: 69% done.
Clone: 70% done.
Clone: 71% done.
Clone: 72% done.
Clone: 73% done.
Clone: 74% done.
Clone: 75% done.
Clone: 76% done.
Clone: 77% done.
Clone: 78% done.
Clone: 79% done.
Clone: 80% done.
Clone: 81% done.
Clone: 82% done.
Clone: 83% done.
Clone: 84% done.
Clone: 85% done.
Clone: 86% done.
Clone: 87% done.
Clone: 88% done.
Clone: 89% done.
Clone: 90% done.
Clone: 91% done.
Clone: 92% done.
Clone: 93% done.
Clone: 94% done.
Clone: 95% done.
Clone: 96% done.
Clone: 97% done.
Clone: 98% done.
2021-04-16 05:50:13 -- info: ERROR: error in backing up of "/vmfs/volumes/datastore1/srvvl02/srvvl02_1.vmdk" for srvvl02
2021-04-16 05:50:14 -- info: Removing snapshot from srvvl02 ...
2021-04-16 05:50:14 -- info: Backup Duration: 197.53 Minutes
2021-04-16 05:50:14 -- info: ERROR: Unable to backup srvvl02 due to error in VMDK backup!

2021-04-16 05:50:16 -- debug: Storage Information before backup: 
2021-04-16 05:50:16 -- debug: SRC_DATASTORE: datastore1
2021-04-16 05:50:16 -- debug: SRC_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 05:50:16 -- debug: SRC_DATASTORE_FREE: 194.9 GB
2021-04-16 05:50:16 -- debug: SRC_DATASTORE_BLOCKSIZE: 1
2021-04-16 05:50:16 -- debug: SRC_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 05:50:16 -- debug: 
2021-04-16 05:50:16 -- debug: DST_DATASTORE: datastore1
2021-04-16 05:50:16 -- debug: DST_DATASTORE_CAPACITY: 63488.0
3712.5 GB
2021-04-16 05:50:16 -- debug: DST_DATASTORE_FREE: 194.9 GB
2021-04-16 05:50:16 -- debug: DST_DATASTORE_BLOCKSIZE: 1
2021-04-16 05:50:16 -- debug: DST_DATASTORE_MAX_FILE_SIZE: 256 GB
2021-04-16 05:50:16 -- debug:
dpalic commented 3 years ago

do you have enough storage on both storages (vmdk location and backup target location) do you have done a consolidation of your vmdk file(s) of the given vm? please check both

ucola commented 3 years ago

Hi dpalic

Yes, we have enough storage on both storages, and yes we have consolidate the disks.

Right now we have remove ghettoVCB and we use another Backup-Tool