3 Replies Latest reply on Jun 20, 2019 4:53 PM by DerekShaw

    Unable to backup VM due to snapshot creation : How to debug ?

    BobLeHareng Lurker

      Hi there,

       

      This script is really usefull. I love it and use for my VMs without problem except one.

      I can't backup my freenas VM.

       

      Everytime i get this error :

       

      2019-05-22 07:45:59 -- info: Initiate backup for freenas

      2019-05-22 07:45:59 -- info: Creating Snapshot "ghettoVCB-snapshot-2019-05-22" for freenas

      2019-05-22 08:01:06 -- info: Snapshot timed out, failed to create snapshot: "ghettoVCB-snapshot-2019-05-22" for freenas

      2019-05-22 08:01:06 -- info: Backup Duration: 15.12 Minutes

      2019-05-22 08:01:06 -- info: ERROR: Unable to backup freenas due to snapshot creation!

       

       

      OK, but how can I debug this error ? The log is quite simple...

      I really want to backup this VM too

      An idea to debug that ?

      Many thanks !

       

      Bob

        • 1. Re: Unable to backup VM due to snapshot creation : How to debug ?
          daphnissov Guru
          vExpertCommunity Warriors

          Can you take a snapshot of your FreeNAS VM manually? From that error, it sounds like it's trying to quiesce it and the underlying storage can't keep up fast enough.

          • 2. Re: Unable to backup VM due to snapshot creation : How to debug ?
            BobLeHareng Lurker

            I can't create a manual snapshot.

             

            I'll check the var/log !

            • 3. Re: Unable to backup VM due to snapshot creation : How to debug ?
              DerekShaw Enthusiast

              NB - can't figure out how to mark up this post.

               

              I have the same issue.

               

              VM backs up fine when it is powered down.

              No pre-existing snapshots.

              Other VMs back up fine while running.

              OS is Ubuntu 14.04.6,  64-bit There are other VMs with Ubuntu, as well as windows servers.

              open-vm-tools  2:9.4.0-1280544-5ubuntu6.4 are installed

              This is a machine in mid-upgrade.  There are two VMDKs.

               

              I've attached the debug output

               

              Any hints welcome!

               

              -----

              since the uploaded file was compressed by this website, and I can't successfully download it (it creates a zero-byte file), below are the contents of the file (and I still can't figure out how to make this appear as "code"):

               

              vmware -vl;/vmfs/volumes/backupstore0/ghettoVCB/ghettoVCB.sh -f /vmfs/volumes/backupstore0/ghettoVCB/addenda+instructions/backup_only_these_machines -g /vmfs/volumes/backupstore0/ghettoVCB/ghettoVCB.conf -l /vmfs/volumes/backupstore0/_ghettobackups/ghettoVCB-adhoc-backup-$(date +%Y-%m-%d:%R:%S).log -d debug

               

              VMware ESXi 6.7.0 build-8169922

              VMware ESXi 6.7.0 GA

              2019-06-11 06:42:43 -- info: ============================== ghettoVCB LOG START ==============================

               

              2019-06-11 06:42:43 -- debug: Succesfully acquired lock directory - /tmp/ghettoVCB.work

               

              2019-06-11 06:42:43 -- debug: HOST VERSION: VMware ESXi 6.7.0 build-8169922

              2019-06-11 06:42:43 -- debug: HOST LEVEL: VMware ESXi 6.7.0 GA

              2019-06-11 06:42:43 -- debug: HOSTNAME: esxi2019.kibro.ho

               

              2019-06-11 06:42:43 -- info: CONFIG - USING GLOBAL GHETTOVCB CONFIGURATION FILE = /vmfs/volumes/backupstore0/ghettoVCB/ghettoVCB.conf

              2019-06-11 06:42:43 -- info: CONFIG - VERSION = 2018_04_23_1

              2019-06-11 06:42:43 -- info: CONFIG - GHETTOVCB_PID = 3038456

              2019-06-11 06:42:43 -- info: CONFIG - VM_BACKUP_VOLUME = /vmfs/volumes/backupstore0/_ghettobackups

              2019-06-11 06:42:43 -- info: CONFIG - VM_BACKUP_ROTATION_COUNT = 3

              2019-06-11 06:42:43 -- info: CONFIG - VM_BACKUP_DIR_NAMING_CONVENTION = 2019-06-11_06-42-43

              2019-06-11 06:42:43 -- info: CONFIG - DISK_BACKUP_FORMAT = thin

              2019-06-11 06:42:43 -- info: CONFIG - POWER_VM_DOWN_BEFORE_BACKUP = 0

              2019-06-11 06:42:43 -- info: CONFIG - ENABLE_HARD_POWER_OFF = 0

              2019-06-11 06:42:43 -- info: CONFIG - ITER_TO_WAIT_SHUTDOWN = 3

              2019-06-11 06:42:43 -- info: CONFIG - POWER_DOWN_TIMEOUT = 5

              2019-06-11 06:42:43 -- info: CONFIG - SNAPSHOT_TIMEOUT = 15

              2019-06-11 06:42:43 -- info: CONFIG - LOG_LEVEL = debug

              2019-06-11 06:42:43 -- info: CONFIG - BACKUP_LOG_OUTPUT = /vmfs/volumes/backupstore0/_ghettobackups/ghettoVCB-adhoc-backup-2019-06-11:06:42:43.log

              2019-06-11 06:42:43 -- info: CONFIG - ENABLE_COMPRESSION = 0

              2019-06-11 06:42:43 -- info: CONFIG - VM_SNAPSHOT_MEMORY = 0

              2019-06-11 06:42:43 -- info: CONFIG - VM_SNAPSHOT_QUIESCE = 1

              2019-06-11 06:42:43 -- info: CONFIG - ALLOW_VMS_WITH_SNAPSHOTS_TO_BE_BACKEDUP = 0

              2019-06-11 06:42:43 -- info: CONFIG - VMDK_FILES_TO_BACKUP = all

              2019-06-11 06:42:43 -- info: CONFIG - VM_SHUTDOWN_ORDER =

              2019-06-11 06:42:43 -- info: CONFIG - VM_STARTUP_ORDER =

              2019-06-11 06:42:43 -- info: CONFIG - RSYNC_LINK = 0

              2019-06-11 06:42:43 -- info: CONFIG - BACKUP_FILES_CHMOD =

              2019-06-11 06:42:43 -- info: CONFIG - EMAIL_LOG = 1

              2019-06-11 06:42:43 -- info: CONFIG - EMAIL_SERVER = 192.168.42.6

              2019-06-11 06:42:43 -- info: CONFIG - EMAIL_SERVER_PORT = 25

              2019-06-11 06:42:43 -- info: CONFIG - EMAIL_DELAY_INTERVAL = 1

              2019-06-11 06:42:43 -- info: CONFIG - EMAIL_FROM = ghettoVCB@kibro.com

              2019-06-11 06:42:43 -- info: CONFIG - EMAIL_TO = monitor@bisi.ca

              2019-06-11 06:42:43 -- info: CONFIG - WORKDIR_DEBUG = 0

              2019-06-11 06:42:46 -- debug: Storage Information before backup:

              2019-06-11 06:42:46 -- debug: SRC_DATASTORE: datastore0

              2019-06-11 06:42:46 -- debug: SRC_DATASTORE_CAPACITY: 63488.0

              3725.2 GB

              2019-06-11 06:42:46 -- debug: SRC_DATASTORE_FREE: 2371.4 GB

              2019-06-11 06:42:46 -- debug: SRC_DATASTORE_BLOCKSIZE: 1

              2019-06-11 06:42:46 -- debug: SRC_DATASTORE_MAX_FILE_SIZE: 256 GB

              2019-06-11 06:42:46 -- debug:

              2019-06-11 06:42:46 -- debug: DST_DATASTORE: backupstore0

              2019-06-11 06:42:46 -- debug: DST_DATASTORE_CAPACITY: 63488.0

              5247.5 GB

              2019-06-11 06:42:46 -- debug: DST_DATASTORE_FREE: 2468.9 GB

              2019-06-11 06:42:46 -- debug: DST_DATASTORE_BLOCKSIZE: NA

              2019-06-11 06:42:46 -- debug: DST_DATASTORE_MAX_FILE_SIZE: NA

              2019-06-11 06:42:46 -- debug:

              2019-06-11 06:42:46 -- debug: getVMDKs() - storage.vmdk###500:sysdrive.vmdk###100:

              2019-06-11 06:42:46 -- info: Initiate backup for imap-plus-1

              2019-06-11 06:42:46 -- info: Creating Snapshot "ghettoVCB-snapshot-2019-06-11" for imap-plus-1

              2019-06-11 06:42:49 -- debug: Waiting for snapshot "ghettoVCB-snapshot-2019-06-11" to be created

              2019-06-11 06:42:49 -- debug: Snapshot timeout set to: 900 seconds

              2019-06-11 06:42:49 -- debug: Waiting for snapshot creation to be completed - Iteration: 0 - sleeping for 60secs (Duration: 0 seconds)

              2019-06-11 06:43:50 -- debug: Waiting for snapshot creation to be completed - Iteration: 1 - sleeping for 60secs (Duration: 30 seconds)

              2019-06-11 06:44:50 -- debug: Waiting for snapshot creation to be completed - Iteration: 2 - sleeping for 60secs (Duration: 60 seconds)

              2019-06-11 06:45:50 -- debug: Waiting for snapshot creation to be completed - Iteration: 3 - sleeping for 60secs (Duration: 90 seconds)

              2019-06-11 06:46:51 -- debug: Waiting for snapshot creation to be completed - Iteration: 4 - sleeping for 60secs (Duration: 120 seconds)

              2019-06-11 06:47:51 -- debug: Waiting for snapshot creation to be completed - Iteration: 5 - sleeping for 60secs (Duration: 150 seconds)

              2019-06-11 06:48:51 -- debug: Waiting for snapshot creation to be completed - Iteration: 6 - sleeping for 60secs (Duration: 180 seconds)

              2019-06-11 06:49:52 -- debug: Waiting for snapshot creation to be completed - Iteration: 7 - sleeping for 60secs (Duration: 210 seconds)

              2019-06-11 06:50:52 -- debug: Waiting for snapshot creation to be completed - Iteration: 8 - sleeping for 60secs (Duration: 240 seconds)

              2019-06-11 06:51:52 -- debug: Waiting for snapshot creation to be completed - Iteration: 9 - sleeping for 60secs (Duration: 270 seconds)

              2019-06-11 06:52:53 -- debug: Waiting for snapshot creation to be completed - Iteration: 10 - sleeping for 60secs (Duration: 300 seconds)

              2019-06-11 06:53:53 -- debug: Waiting for snapshot creation to be completed - Iteration: 11 - sleeping for 60secs (Duration: 330 seconds)

              2019-06-11 06:54:53 -- debug: Waiting for snapshot creation to be completed - Iteration: 12 - sleeping for 60secs (Duration: 360 seconds)

              2019-06-11 06:55:54 -- debug: Waiting for snapshot creation to be completed - Iteration: 13 - sleeping for 60secs (Duration: 390 seconds)

              2019-06-11 06:56:54 -- debug: Waiting for snapshot creation to be completed - Iteration: 14 - sleeping for 60secs (Duration: 420 seconds)

              2019-06-11 06:57:54 -- info: Snapshot timed out, failed to create snapshot: "ghettoVCB-snapshot-2019-06-11" for imap-plus-1

              2019-06-11 06:57:54 -- debug: Removing /vmfs/volumes/backupstore0/_ghettobackups/imap-plus-1/imap-plus-1-2019-06-01_05-05-01

              2019-06-11 06:57:55 -- info: Slept 1 seconds to work around NFS I/O error

              2019-06-11 06:57:55 -- info: Backup Duration: 15.15 Minutes

              2019-06-11 06:57:55 -- info: ERROR: Unable to backup imap-plus-1 due to snapshot creation!

               

              2019-06-11 06:57:55 -- info: ###### Final status: ERROR: All VMs failed! ######

               

              2019-06-11 06:57:55 -- debug: Succesfully removed lock directory - /tmp/ghettoVCB.work

               

              2019-06-11 06:57:56 -- info: ============================== ghettoVCB LOG END ================================