Seite 1 von 2

was ist dieser "parallel"-Snapshot?

Verfasst: 31.08.2015, 16:14
von Odi
Hallo,
ich wundere mich schon längere Zeit über eine seltsamkeit bei Snapshots bei manchen Servern. Hatte schon einen spezialisten hier und auch ein Veeam-Ticket.
Beide konnten nicht wirklich was dazu sagen.
Vielleicht kann ja jemand von euch den entscheidenden Hinweis geben?

Anbei der Screenshot des seltsamen Snapshots.
Wie gesagt ist das nur bei manchen Servern so.

Normal kenn ich die Snapshots nur "seriell" aber dieser hier sieht eher parallel aus.


Bild



grüße
Tibor

Verfasst: 31.08.2015, 18:43
von ~thc
Der Snapshot wurde am 23.8. angelegt und zu einem späteren Zeitpunkt wurde ein "Gehe zu" zum Urzustand ausgeführt. Die zwischenzeitlichen Änderungen (vom Anlegen des Snapshots bis zum "Gehe zu") im Snapshot sind damit verworfen und inaktiv. Alle späteren Änderungen (ab dem "Gehe zu") sind auf den Basis-VM-Disks.

Verfasst: 31.08.2015, 20:48
von Odi
Ahhhja...das wird die Erklährung sein.

Aber warum kommt es dazu?

Ich hab nur einen Snapshot gemacht und sonst nichts?!

Unmittelbar nach dem Snapshot habe ich den beigefügten Screenshot gemacht.

Seltsam, oder?

Verfasst: 31.08.2015, 20:52
von ~thc
Ich muss mich korrigieren - das geht nicht so, wie ich vermutete. Man kann nicht einfach mit dem Snapshot-Manager zum Urzustand wechseln.

Wenn du nur einen Snapshot gemacht hast und sonst nichts, habe ich auch keine Erklärung dafür.

Du kannst aber den Inhalt der DIsk-Deskriptor-Dateien (die kleinen, wenige Hundert Byte großen VMDK-Dateien) der VM hier posten.

Verfasst: 01.09.2015, 10:36
von JustMe
Stimmt; man kann nicht zum Urzustand wechseln. Aber zu einem weiteren Snapshot, der zwischen Urzustand und "...vor OS-Update" liegt, und diesen dann loeschen :-)

Danach sieht das Bild so wie im Beispiel aus, denn eine Rueckkehr in die Basisdateien ist verwehrt, da der weiter bestehende Snapshot ja auf einen bestimmten (alten) Stand dieser Basisdateien vertraut..

Um das zu bestaetigen, waere neben den kleinen .vmdk-Dateien auch noch die neueste vmware.log oder zumindest die aktuelle .vmx noetig.

PS: Wenn man, um dieses Szenario wie abgebildet zu erreichen, den aktiven "mittleren" Snapshot loescht, dann zeigt der Snapshot-Manager (zumindest bei mir) ueberhaupt kein "You are here" mehr an :grin:

Verfasst: 01.09.2015, 11:34
von Odi
danke für die mithilfe!!

also die vmdk-files sind die virtuellen Festplatten und daher mehrere GB groß.
kleine vmdk's hab ich nicht.

interessanterweise gibts auch keine vmware.log dateien!!!

hier der inhalt der vmx:

##############################################

.encoding = "UTF-8"
config.version = "8"
virtualHW.version = "7"
svga.present = "TRUE"
vmci0.present = "TRUE"
displayName = "SAB16 (Printsrv)"
extendedConfigFile = "SAB16 (Printsrv).vmxf"
floppy0.present = "FALSE"
svga.vramSize = "16777216"
numvcpus = "2"
memSize = "6144"
sched.cpu.units = "mhz"
sched.cpu.latencySensitivity = "normal"
tools.upgrade.policy = "manual"
scsi0.virtualDev = "lsisas1068"
scsi0.present = "TRUE"
vmci.filter.enable = "TRUE"
ide1:0.startConnected = "FALSE"
ide1:0.autodetect = "TRUE"
ide1:0.deviceType = "atapi-cdrom"
ide1:0.clientDevice = "TRUE"
ide1:0.present = "TRUE"
scsi0:0.deviceType = "scsi-hardDisk"
scsi0:0.fileName = "SAB16 (Printsrv).vmdk"
sched.scsi0:0.shares = "normal"
scsi0:0.present = "TRUE"
ethernet0.virtualDev = "vmxnet3"
ethernet0.networkName = "VM Network"
ethernet0.addressType = "vpx"
ethernet0.generatedAddress = "00:50:56:a4:00:09"
ethernet0.present = "TRUE"
guestOS = "windows7srv-64"
logging = "FALSE"
toolScripts.afterPowerOn = "TRUE"
toolScripts.afterResume = "TRUE"
toolScripts.beforeSuspend = "TRUE"
toolScripts.beforePowerOff = "TRUE"
tools.syncTime = "FALSE"
tools.guest.desktop.autolock = "FALSE"
uuid.bios = "42 24 c6 75 ca 34 c2 2c-41 c8 86 d2 1a ea 8e 50"
vc.uuid = "50 24 38 4f 1c c9 31 93-ca fb 12 c4 12 ff f1 3e"
pciBridge0.present = "true"
pciBridge4.present = "true"
pciBridge4.virtualDev = "pcieRootPort"
pciBridge4.functions = "8"
pciBridge5.present = "true"
pciBridge5.virtualDev = "pcieRootPort"
pciBridge5.functions = "8"
pciBridge6.present = "true"
pciBridge6.virtualDev = "pcieRootPort"
pciBridge6.functions = "8"
pciBridge7.present = "true"
pciBridge7.virtualDev = "pcieRootPort"
pciBridge7.functions = "8"
nvram = "SAB16 (Printsrv).nvram"
virtualHW.productCompatibility = "hosted"
sched.scsi0:0.throughputCap = "off"
disk.EnableUUID = "true"
snapshot.action = "keep"
pciBridge6.pciSlotNumber = "23"
pciBridge7.pciSlotNumber = "24"
vmci0.pciSlotNumber = "33"
scsi0.pciSlotNumber = "160"
scsi0.sasWWID = "50 05 05 65 ca 34 c2 20"
ethernet0.pciSlotNumber = "192"
pciBridge0.pciSlotNumber = "17"
replay.supported = "FALSE"
unity.wasCapable = "FALSE"
vmotion.checkpointFBSize = "16777216"
hostCPUID.0 = "0000000f756e65476c65746e49656e69"
hostCPUID.1 = "000306f20010080077fefbffbfebfbff"
hostCPUID.80000001 = "0000000000000000000000212c100800"
guestCPUID.0 = "0000000f756e65476c65746e49656e69"
guestCPUID.1 = "000306f20001080082d822030fabfbff"
guestCPUID.80000001 = "00000000000000000000000128100800"
userCPUID.0 = "0000000f756e65476c65746e49656e69"
userCPUID.1 = "000306f20001080082d822030fabfbff"
userCPUID.80000001 = "00000000000000000000000128100800"
evcCompatibilityMode = "FALSE"
pciBridge4.pciSlotNumber = "21"
pciBridge5.pciSlotNumber = "22"
softPowerOff = "FALSE"
toolsInstallManager.updateCounter = "2"
tools.remindInstall = "FALSE"
toolsInstallManager.lastInstallError = "0"
disk.AllowDupUUID = "TRUE"
chipset.onlineStandby = "FALSE"
sched.cpu.min = "0"
sched.cpu.shares = "normal"
sched.mem.min = "0"
sched.mem.minSize = "0"
sched.mem.shares = "normal"
sched.swap.derivedName = "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-9b56d12d.vswp"
uuid.location = "56 4d 1b 41 cd 8e 6d 3c-03 6d 3c e8 22 71 91 96"
replay.filename = ""
scsi0:0.redo = ""
vmci0.id = "451579472"
cleanShutdown = "FALSE"
scsi0:2.deviceType = "scsi-hardDisk"
scsi0:2.fileName = "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/sab00/sab00.vmdk"
scsi0:2.mode = "independent-nonpersistent"
sched.scsi0:2.shares = "normal"
sched.scsi0:2.throughputCap = "off"
sched.scsi0:2.vFlash.enabled = "FALSE"
scsi0:2.present = "FALSE"
scsi0:2.redo = ""
scsi0:1.deviceType = "scsi-hardDisk"
scsi0:1.fileName = "/vmfs/volumes/55587300-4c7bce48-45da-b083fee37ed1/TS1/TS1.vmdk"
scsi0:1.mode = "independent-nonpersistent"
sched.scsi0:1.shares = "normal"
sched.scsi0:1.throughputCap = "off"
sched.scsi0:1.vFlash.enabled = "FALSE"
scsi0:1.present = "FALSE"
scsi0:1.redo = ""

Verfasst: 01.09.2015, 12:27
von Dayworker
Das du keine kleinen vmdk-Deskriptordateien hast, halte ich für ein Gerücht. Du hast zur Anzeige garantiert den Datastore-Browser verwendet und der lügt bekanntlich. Schalte dich mal per WinSCP oder Putty auf deinen ESXi und hangel dich dann zum Gast-Ordner durch.

Das du keine Log-Dateien hast, dürftest du dem Eintrag logging = "FALSE" zu verdanken haben. Weshalb wurde dieser bei euch gesetzt?

Verfasst: 01.09.2015, 12:32
von JustMe
a) NICHT im DatastoreBrowser nach einzelnen (.vmdk-)Dateien schauen! :)
Dafuer verwendet man IMMER die ESXi-Konsole (z.B. per ssh)
b) Bei

Code: Alles auswählen

logging = "FALSE"
wundert es mich nicht, dass keine vmware.log Dateien angelegt werden...

Ich vermute jetzt mal einfach so in's Blaue hinein, dass da mal ein Snapshot angelegt wurde, als die beiden independent-nonpersistent Platten noch dranhingen.

Noch immer wuerden die kleinen vmdk-Dateien (die ohne -flat und -delta, die der DS-Browser dummerweise versteckt) weiteren Aufschluss bringen, und dann auch gleich noch die .vmsd (Snapshot-Descriptor).

Verfasst: 01.09.2015, 13:17
von Odi
Dayworker hat geschrieben:Du hast zur Anzeige garantiert den Datastore-Browser verwendet und der lügt bekanntlich.


So ein pöcher Purche!!

Alles klar, mit WinScp gibt das schon ein ganz anderes Bild.

Code: Alles auswählen

logging = False

ist mir mittlerweile auch aufgefallen. Keine Ahnung wer das abgeschaltet hat.
Werd ich in der Nacht umstellen wenn ich rebooten kann.

Code: Alles auswählen

present = false

ich nehme an da wurden nur die disken entfernt und nicht gleich mit dem wizzard gelöscht und damit bleiben die einträge stehen. stimmt das?
verwaiste Snapshotdateien kann ich keine finden (aber das muss ja nichts bedeuten).

Code: Alles auswählen

ctkEnabled = true

Was mir noch aufgefallen ist: ich hab keine ctk-Dateien und auch keinen
ctkEnabled= True eintrag.
ist der standardwert true oder false?

na heut lern ich mal wieder was dazu!! Danke ;-)

hier die vmdk:

#######################
# Disk DescriptorFile
version=1
encoding="UTF-8"
CID=38c6b482
parentCID=ffffffff
isNativeSnapshot="no"
createType="vmfs"

# Extent description
RW 94371840 VMFS "SAB16 (Printsrv)-flat.vmdk"

# The Disk Data Base
#DDB

ddb.adapterType = "lsilogic"
ddb.deletable = "true"
ddb.geometry.cylinders = "5874"
ddb.geometry.heads = "255"
ddb.geometry.sectors = "63"
ddb.longContentID = "6de879eeb8915eefd6f700d338c6b482"
ddb.thinProvisioned = "1"
ddb.toolsVersion = "9349"
ddb.uuid = "60 00 C2 9c 74 9b 24 66-37 cb 55 2e 55 a0 68 42"
ddb.virtualHWVersion = "7"

Verfasst: 01.09.2015, 13:47
von JustMe

Code: Alles auswählen

logging = "FALSE"
wird z.B. von VMware empfohlen bei Terminalserver VMs, weil ab dem 3. Connect oft die vmware.log geflutet wird mit der Information, dass mehr als 2 Sitzungen bestehen. Das ist aber bei einem Print-Server eher unwahrscheinlich, stelle ich mir vor.

Code: Alles auswählen

scsix:y.present = "FALSE"
ist der normale Vorgang, wenn eine Festplatte von der VM entfernt wird. Die restlichen Eintraege in der .vmx bleiben einfach, bis sie ueberschrieben werden; sie sind wegen des "present=false" ja als ungueltig markiert.

Laut der Info aus der kleinen .vmdk sieht es danach aus, als waere dies auch der Hinweis auf die Basis. Dann waere der einfachste Weg, um das Problem zu beseitigen, das Loeschen der .vmsd; danach ist auch die Anzeige im vSphere-Client wieder ok.

Um ganz sicher zu gehen, koennen (bzw. sollten) ja alle Dateien erst noch gesichert werden.

Mit noch viel mehr Entdeckergeist koennte dann halt in die .vmsd geschaut werden, und ein Dateilisting des Datastores ausgewertet werden, usw.usf.

Verfasst: 01.09.2015, 13:51
von kastlr
Hallo zusammen,

es gab mal einen guten Grund für das Abschalten der VMware Logs.
Virtual machine with multiple user login session fails with the error: GuestRpc: Channel X, conflict: guest application toolbox-dnd tried to register, but it is still registered on channel Y (2078823)

Wenn man von diesem Problem betroffen war, belegten die VMware Logs der VM's gerne mal mehrere GB.

Neben dem verbrauchen Plattenplatz war das auch immer eine ganz ordentliche Belastung für das VMFS und das Storage Device.

Gruß,
Ralf[

Verfasst: 01.09.2015, 15:31
von Odi
JustMe hat geschrieben:Laut der Info aus der kleinen .vmdk sieht es danach aus, als waere dies auch der Hinweis auf die Basis. Dann waere der einfachste Weg, um das Problem zu beseitigen, das Loeschen der .vmsd; danach ist auch die Anzeige im vSphere-Client wieder ok.


das bedeutet du denkst, das es nur ein Anzeigefehler ist?

Ohne dem jetzt genauer nachgegangen zu sein habe ich allerdings das Gefühl das bei solchen Snapshots die Snapshot-datei nicht wächst und sehr klein bleibt.

in der .vmsd steht nur

.encoding = "UTF-8"
snapshot.lastUID = "17"

diese also einfach löschen (oder umbenennen)?

Verfasst: 01.09.2015, 16:00
von ~thc
Ist denn die Basis-VMDK, die du gepostet hast, die einzige VMDK-Datei in dem Verzeichnis der VM?

Verfasst: 01.09.2015, 16:09
von JustMe
Wenn in der .vmsd nicht mehr als diese beiden Zeilen stehen, dann kann das Anzeigeproblem auch aus einem vCenter heraus bestehen...

Verwendest Du ein solches?

Muesstest Du eigentlich, denn sonst haette ich echt keine Ahnung, wo genau bei an sich leerer vmsd-Datei die Information zum Snapshot vom 23.8. herruehren sollte.

Dann koenntest Du mal den vsphere-Client direkt zum Host der VM verbinden, und die VM dort kontrollieren. Und dann ggfs. mal das vCenter neu starten.

Mit nur den beiden Zeilen in der .vmsd braucht die nicht geloescht zu werden.

Von welchem Snapshot sprichst/schreibst Du nun? In der .vmx findet sich kein Hinweis auf einen bestehenden Snapshot, und, vorausgesetzt, dass die frueher abgebildete vmdk-Datei von der "SAB16 (Printsrv).vmdk" stammt, handelt es sich bei dieser auch nicht um eine Snapshot-Datei.

Wenn Du von "solchen Snapshots" schreibst: Handelt es sich bei dem ersten Bild um den momentanen Zustand der VM, oder "kommt das immer mal wieder vor, nur momentan grad' nicht"? Wenn zweiteres, bei welchen Situationen?

Grundsaetzlich handelt es sich bei einer "Snapshot-Datei" (bezogen auf die vmdk) um eine Differenz-Datei, die saemtliche Aenderungen gegenueber dem eingefrorenen Zustand (der Parent- bzw. Basis-Datei) aufnimmt. Wird nichts geaendert (z.B. wenn die VM ausgeschaltet ist), dann muss/wird auch diese Datei nicht wachsen.

Verfasst: 01.09.2015, 16:23
von Odi
oh...

da hab ich wohl was falsch verstanden.

der snapshot ist ja schon längst wieder gelöscht!!

werde morgen das prozedere nochmal durchgehen und das ergebnis posten.

sorry!! Diesmal bin wohl ICH der DAU..peinlich... :-(

Verfasst: 01.09.2015, 17:04
von JustMe
:lol: :lol: :lol:
Kein Problem. Hauptsache, wir bekommen das Problem irgendwie zufriedenstellend geloest (oder zumindest erklaert).

Dann sind wir mal auf das Ergebnis des Prozedere gespannt.

Verfasst: 01.09.2015, 20:54
von Odi
Aber jetzt ;-)

####################################
SAB16 (Printsrv)-000001.vmdk

# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=6a4e71dc
parentCID=11cd9fab
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="SAB16 (Printsrv).vmdk"
# Extent description
RW 94371840 VMFSSPARSE "SAB16 (Printsrv)-000001-delta.vmdk"

# Change Tracking File
changeTrackPath="SAB16 (Printsrv)-000001-ctk.vmdk"

# The Disk Data Base
#DDB

ddb.longContentID = "a984e7a3d1047ddf4674a6e16a4e71dc"


#######################################
SAB16 (Printsrv)-000002.vmdk

# Disk DescriptorFile
version=3
encoding="UTF-8"
CID=255d7a91
parentCID=11cd9fab
isNativeSnapshot="no"
createType="vmfsSparse"
parentFileNameHint="SAB16 (Printsrv).vmdk"
# Extent description
RW 94371840 VMFSSPARSE "SAB16 (Printsrv)-000002-delta.vmdk"

# Change Tracking File
changeTrackPath="SAB16 (Printsrv)-000002-ctk.vmdk"

# The Disk Data Base
#DDB

ddb.longContentID = "287c9b02ea6154a2db7f447a255d7a91"


#################################
SAB16 (Printsrv).vmsd

.encoding = "UTF-8"
snapshot.lastUID = "18"
snapshot0.uid = "18"
snapshot0.filename = "SAB16 (Printsrv)-Snapshot18.vmsn"
snapshot0.displayName = "01.09 testsnapshot"
snapshot0.backupManifest = "SAB16 (Printsrv)-vss_manifests18.zip"
snapshot0.createTimeHigh = "335539"
snapshot0.createTimeLow = "-33764683"
snapshot0.numDisks = "1"
snapshot0.disk0.fileName = "SAB16 (Printsrv)-000002.vmdk"
snapshot0.disk0.node = "scsi0:0"
snapshot.numSnapshots = "1"


###############################
vmware.log

2015-09-01T18:47:56.988Z| vmx| I120: SnapshotVMX_TakeSnapshot start: '01.09 testsnapshot', deviceState=0, lazy=0, logging=0, quiesced=1, forceNative=0, tryNative=0, sibling=0 saveAllocMaps=0 cb=13AD1C80, cbData=325B4450
2015-09-01T18:47:57.057Z| vcpu-0| I120: ToolsBackup: changing quiesce state: IDLE -> STARTED
2015-09-01T18:48:12.522Z| vcpu-1| I120: ToolsBackup: changing quiesce state: STARTED -> COMMITTED
2015-09-01T18:48:12.522Z| vcpu-0| I120: Destroying virtual dev for scsi0:0 vscsi=16241
2015-09-01T18:48:12.522Z| vcpu-0| I120: VMMon_VSCSIStopVports: No such target on adapter
2015-09-01T18:48:12.562Z| vcpu-0| I120: SnapshotVMXTakeSnapshotWork: Transition to mode 0.
2015-09-01T18:48:12.562Z| vcpu-0| I120: Closing all the disks of the VM.
2015-09-01T18:48:12.562Z| vcpu-0| I120: Closing disk scsi0:0
2015-09-01T18:48:12.564Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 389778409.
2015-09-01T18:48:12.564Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2015-09-01T18:48:12.636Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : closed.
2015-09-01T18:48:12.637Z| vcpu-0| I120: SNAPSHOT: SnapshotConfigInfoReadEx: Creating new snapshot dictionary, '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv).vmsd.usd'.
2015-09-01T18:48:12.657Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : open successful (65557) size = 48318382080, hd = 0. Type 3
2015-09-01T18:48:12.657Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : closed.
2015-09-01T18:48:12.724Z| vcpu-0| A115: ConfigDB: Setting displayName = "SAB16 (Printsrv)"
2015-09-01T18:48:12.759Z| vcpu-0| I120: SNAPSHOT: SnapshotDumperOpenFromInfo: Creating checkpoint file /vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-Snapshot18.vmsn
2015-09-01T18:48:12.771Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : open successful (29) size = 48318382080, hd = 0. Type 3
2015-09-01T18:48:12.773Z| vcpu-0| I120: DISKLIB-LIB : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2015-09-01T18:48:12.773Z| vcpu-0| I120: DISKLIB-LIB : CREATE CHILD: "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk" -- vmfsSparse cowGran=1 allocType=0 policy=''
2015-09-01T18:48:12.774Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:12.774Z| vcpu-0| I120: DISKLIB-LIB : CREATE-CHILD: Creating disk backed by 'default'
2015-09-01T18:48:12.780Z| vcpu-0| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001-delta.vmdk" : success
2015-09-01T18:48:12.783Z| vcpu-0| I120: DISKLIB-DSCPTR: "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk" : creation successful.
2015-09-01T18:48:12.798Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001-delta.vmdk" : open successful (17) size = 94208, hd = 0. Type 8
2015-09-01T18:48:12.913Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001-delta.vmdk" : closed.
2015-09-01T18:48:12.915Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001-delta.vmdk" : open successful (24) size = 94208, hd = 360156141. Type 8
2015-09-01T18:48:12.915Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-000001-delta.vmdk" (0x18)
2015-09-01T18:48:12.915Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk' (0x18): vmfsSparse, 94371840 sectors / 45 GB.
2015-09-01T18:48:12.915Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2015-09-01T18:48:12.915Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 360156141, extentType = 0
2015-09-01T18:48:12.915Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:12.916Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 360156141.
2015-09-01T18:48:12.916Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 170b8bee-cbt.
2015-09-01T18:48:12.916Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/170b8bee-cbt
2015-09-01T18:48:12.916Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk" (flags 0x18, type vmfsSparse).
2015-09-01T18:48:12.918Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 360156141.
2015-09-01T18:48:12.918Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2015-09-01T18:48:12.925Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001-delta.vmdk" : closed.
2015-09-01T18:48:12.925Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : closed.
2015-09-01T18:48:12.926Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : open successful (29) size = 48318382080, hd = 0. Type 3
2015-09-01T18:48:12.927Z| vcpu-0| I120: DISKLIB-LIB : DiskLibCreateCreateParam: vmfssparse grain size set to : 1
2015-09-01T18:48:12.928Z| vcpu-0| I120: DISKLIB-LIB : CREATE CHILD: "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk" -- vmfsSparse cowGran=1 allocType=0 policy=''
2015-09-01T18:48:12.928Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:12.928Z| vcpu-0| I120: DISKLIB-LIB : CREATE-CHILD: Creating disk backed by 'default'
2015-09-01T18:48:12.936Z| vcpu-0| I120: DISKLIB-VMFS_SPARSE : VmfsSparseExtentCreate: "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : success
2015-09-01T18:48:12.939Z| vcpu-0| I120: DISKLIB-DSCPTR: "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk" : creation successful.
2015-09-01T18:48:12.948Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : open successful (17) size = 94208, hd = 0. Type 8
2015-09-01T18:48:13.039Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : closed.
2015-09-01T18:48:13.040Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : closed.
2015-09-01T18:48:13.041Z| vcpu-0| A115: ConfigDB: Setting displayName = "SAB16 (Printsrv)"
2015-09-01T18:48:13.041Z| vcpu-0| A115: ConfigDB: Setting scsi0:0.fileName = "SAB16 (Printsrv)-000001.vmdk"
2015-09-01T18:48:13.089Z| vcpu-0| I120: Checkpoint_Unstun: vm stopped for 566747 us
2015-09-01T18:48:13.089Z| vcpu-0| I120: SCSI: switching scsi0 to push completion mode
2015-09-01T18:48:13.091Z| vcpu-0| A115: ConfigDB: Setting scsi0:0.redo = ""
2015-09-01T18:48:13.091Z| vcpu-0| I120: DISK: OPEN scsi0:0 '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk' persistent R[]
2015-09-01T18:48:13.093Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001-delta.vmdk" : open successful (10) size = 94208, hd = 396987371. Type 8
2015-09-01T18:48:13.093Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-000001-delta.vmdk" (0xa)
2015-09-01T18:48:13.093Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk' (0xa): vmfsSparse, 94371840 sectors / 45 GB.
2015-09-01T18:48:13.094Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : open successful (14) size = 48318382080, hd = 348359660. Type 3
2015-09-01T18:48:13.094Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-flat.vmdk" (0xe)
2015-09-01T18:48:13.094Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv).vmdk' (0xe): vmfs, 94371840 sectors / 45 GB.
2015-09-01T18:48:13.094Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2015-09-01T18:48:13.094Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 348359660, extentType = 2
2015-09-01T18:48:13.094Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 396987371, extentType = 0
2015-09-01T18:48:13.095Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:13.096Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 396987371.
2015-09-01T18:48:13.096Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 15868bed-cbt.
2015-09-01T18:48:13.096Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/15868bed-cbt
2015-09-01T18:48:13.096Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk" (flags 0xa, type vmfs).
2015-09-01T18:48:13.096Z| vcpu-0| I120: DISK: Disk '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk' has UUID '60 00 c2 9c 74 9b 24 66-37 cb 55 2e 55 a0 68 42'
2015-09-01T18:48:13.096Z| vcpu-0| I120: DISK: OPEN '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk' Geo (5874/255/63) BIOS Geo (0/0/0)
2015-09-01T18:48:13.096Z| vcpu-0| I120: Creating virtual dev for scsi0:0
2015-09-01T18:48:13.096Z| vcpu-0| I120: DumpDiskInfo: scsi0:0 createType=11, capacity = 94371840, numLinks = 2, allocationType = 0
2015-09-01T18:48:13.097Z| vcpu-0| I120: SCSIDiskESXPopulateVDevDesc: Using FS backend
2015-09-01T18:48:13.097Z| vcpu-0| I120: DISKUTIL: scsi0:0 : geometry=5874/255/63
2015-09-01T18:48:13.097Z| vcpu-0| I120: VMXNET3 user: Ethernet0 Driver Info: version = 1345333 gosBits = 2 gosType = 2, gosVer = 24848, gosMisc = 212
2015-09-01T18:48:13.101Z| vcpu-0| I120: SnapshotVMXTakeSnapshotWork: Transition to mode 1.
2015-09-01T18:48:13.106Z| vcpu-0| I120: ToolsBackup: hot adding disk SAB16 (Printsrv)-000002.vmdk to node scsi0:1 (oldnode scsi0:0).
2015-09-01T18:48:13.107Z| vcpu-0| I120: DISKLIB-VMFS : "./SAB16 (Printsrv)-000002-delta.vmdk" : open successful (8) size = 94208, hd = 393841651. Type 8
2015-09-01T18:48:13.107Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-000002-delta.vmdk" (0x8)
2015-09-01T18:48:13.107Z| vcpu-0| I120: DISKLIB-LINK : Opened 'SAB16 (Printsrv)-000002.vmdk' (0x8): vmfsSparse, 94371840 sectors / 45 GB.
2015-09-01T18:48:13.108Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2015-09-01T18:48:13.108Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 393841651, extentType = 0
2015-09-01T18:48:13.108Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:13.109Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 393841651.
2015-09-01T18:48:13.109Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 15e18bf4-cbt.
2015-09-01T18:48:13.109Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/15e18bf4-cbt
2015-09-01T18:48:13.109Z| vcpu-0| I120: DISKLIB-LIB : Opened "SAB16 (Printsrv)-000002.vmdk" (flags 0x8, type vmfsSparse).
2015-09-01T18:48:13.111Z| vcpu-0| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 393841651.
2015-09-01T18:48:13.111Z| vcpu-0| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2015-09-01T18:48:13.118Z| vcpu-0| I120: DISKLIB-VMFS : "./SAB16 (Printsrv)-000002-delta.vmdk" : closed.
2015-09-01T18:48:13.118Z| vcpu-0| I120: DISKLIB-LIB : DiskLib_DigestDisable: no digest disk associated.
2015-09-01T18:48:13.118Z| vcpu-0| A115: ConfigDB: Unsetting all entries with prefix "scsi0:1."
2015-09-01T18:48:13.118Z| vcpu-0| A115: ConfigDB: Unsetting all entries with prefix "sched.scsi0:1."
2015-09-01T18:48:13.137Z| vcpu-0| I120: HotAdd: Adding disk with mode 'persistent' to scsi0:1
2015-09-01T18:48:13.138Z| vcpu-0| I120: DISK: OPEN scsi0:1 '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk' persistent R[]
2015-09-01T18:48:13.139Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : open successful (10) size = 94208, hd = 394038259. Type 8
2015-09-01T18:48:13.139Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-000002-delta.vmdk" (0xa)
2015-09-01T18:48:13.139Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk' (0xa): vmfsSparse, 94371840 sectors / 45 GB.
2015-09-01T18:48:13.140Z| vcpu-0| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : open successful (14) size = 48318382080, hd = 367299572. Type 3
2015-09-01T18:48:13.140Z| vcpu-0| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-flat.vmdk" (0xe)
2015-09-01T18:48:13.140Z| vcpu-0| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv).vmdk' (0xe): vmfs, 94371840 sectors / 45 GB.
2015-09-01T18:48:13.140Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 2, numSubChains = 1
2015-09-01T18:48:13.140Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 367299572, extentType = 2
2015-09-01T18:48:13.140Z| vcpu-0| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(1) fid = 394038259, extentType = 0
2015-09-01T18:48:13.141Z| vcpu-0| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:13.141Z| vcpu-0| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 394038259.
2015-09-01T18:48:13.141Z| vcpu-0| I120: DISKLIB-CBT : Successfuly created cbt node 16968bf5-cbt.
2015-09-01T18:48:13.141Z| vcpu-0| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/16968bf5-cbt
2015-09-01T18:48:13.142Z| vcpu-0| I120: DISKLIB-LIB : Opened "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk" (flags 0xa, type vmfs).
2015-09-01T18:48:13.142Z| vcpu-0| I120: DISK: Disk '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk' has UUID '60 00 c2 9e 7d bc 65 93-75 83 cf 58 3d 2e 10 68'
2015-09-01T18:48:13.142Z| vcpu-0| I120: DISK: OPEN '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk' Geo (5874/255/63) BIOS Geo (0/0/0)
2015-09-01T18:48:13.142Z| vcpu-0| I120: SCSI DEVICE (scsi0:1): Computed value of scsi0:1.useBounceBuffers: default
2015-09-01T18:48:13.142Z| vcpu-0| I120: Creating virtual dev for scsi0:1
2015-09-01T18:48:13.142Z| vcpu-0| I120: DumpDiskInfo: scsi0:1 createType=11, capacity = 94371840, numLinks = 2, allocationType = 0
2015-09-01T18:48:13.142Z| vcpu-0| I120: SCSIDiskESXPopulateVDevDesc: Using FS backend
2015-09-01T18:48:13.142Z| vcpu-0| I120: DISKUTIL: scsi0:1 : geometry=5874/255/63
2015-09-01T18:48:13.174Z| vcpu-0| I120: ToolsBackup: notification message is "vmbackup.snapshotDone 6000c29e-7dbc-6593-7583-cf583d2e1068".
2015-09-01T18:48:13.174Z| vcpu-0| I120: ToolsBackup: successfully mounted writable snapshot in guest.
2015-09-01T18:48:13.175Z| vmx| A115: ConfigDB: Setting scsi0:1.deviceType = "scsi-hardDisk"
2015-09-01T18:48:13.226Z| vcpu-0| I120: LSI:Event notification sent for SAS device scsi0:1...
2015-09-01T18:48:13.259Z| vcpu-1| I120: ToolsBackup: changing quiesce state: COMMITTED -> FINISHING
2015-09-01T18:48:13.261Z| vcpu-0| I120: HBACommon: First write on scsi0:0.fileName='/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000001.vmdk'
2015-09-01T18:48:13.261Z| vcpu-0| I120: DDB: "longContentID" = "a984e7a3d1047ddf4674a6e16a4e71dc" (was "98609cc7fe1b91a0638461e811cd9fab")
2015-09-01T18:48:13.281Z| vcpu-0| I120: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x11cd9fab, new=0x6a4e71dc (a984e7a3d1047ddf4674a6e16a4e71dc)
2015-09-01T18:48:13.599Z| vcpu-0| I120: HBACommon: First write on scsi0:1.fileName='/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk'
2015-09-01T18:48:13.599Z| vcpu-0| I120: DDB: "longContentID" = "6ad74ed28f03b9e8c864797c9ae214ec" (was "98609cc7fe1b91a0638461e811cd9fab")
2015-09-01T18:48:13.606Z| vcpu-0| I120: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x11cd9fab, new=0x9ae214ec (6ad74ed28f03b9e8c864797c9ae214ec)
2015-09-01T18:48:34.788Z| vcpu-1| I120: ToolsBackup: changing quiesce state: FINISHING -> DONE_WAIT
2015-09-01T18:48:35.804Z| vcpu-0| I120: ToolsBackup: changing quiesce state: DONE_WAIT -> GET_MANIFEST
2015-09-01T18:48:35.835Z| vcpu-1| I120: HGFileCopyCreateSessionCB: Successfully created the session.
2015-09-01T18:48:35.893Z| vcpu-1| A115: ConfigDB: Setting displayName = "SAB16 (Printsrv)"
2015-09-01T18:48:35.902Z| vcpu-1| I120: ToolsBackup: changing quiesce state: GET_MANIFEST -> IDLE
2015-09-01T18:48:35.902Z| vcpu-1| I120: ToolsBackup: hot removing disk SAB16 (Printsrv)-000002.vmdk from node scsi0:1.
2015-09-01T18:48:35.902Z| vcpu-1| I120: LSI:Event notification sent for SAS device scsi0:1...
2015-09-01T18:48:35.902Z| vcpu-1| I120: Destroying virtual dev for scsi0:1 vscsi=16244
2015-09-01T18:48:35.902Z| vcpu-1| I120: VMMon_VSCSIStopVports: No such target on adapter
2015-09-01T18:48:35.903Z| vcpu-1| I120: scsi0:1: numIOs = 0 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
2015-09-01T18:48:35.903Z| vcpu-1| I120: Closing disk scsi0:1
2015-09-01T18:48:35.905Z| vcpu-1| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 394038259.
2015-09-01T18:48:35.905Z| vcpu-1| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2015-09-01T18:48:35.912Z| vcpu-1| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : closed.
2015-09-01T18:48:35.912Z| vcpu-1| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : closed.
2015-09-01T18:48:35.931Z| vcpu-1| I120: ToolsBackup: Post-processing writable snapshot disk '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk'.
2015-09-01T18:48:35.932Z| vcpu-1| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : open successful (8) size = 16871424, hd = 367430644. Type 8
2015-09-01T18:48:35.932Z| vcpu-1| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-000002-delta.vmdk" (0x8)
2015-09-01T18:48:35.932Z| vcpu-1| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk' (0x8): vmfsSparse, 94371840 sectors / 45 GB.
2015-09-01T18:48:35.932Z| vcpu-1| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain: numLinks = 1, numSubChains = 1
2015-09-01T18:48:35.932Z| vcpu-1| I120: DISKLIB-CHAINESX : ChainESXOpenSubChain:(0) fid = 367430644, extentType = 0
2015-09-01T18:48:35.933Z| vcpu-1| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:35.934Z| vcpu-1| I120: DISKLIB-CBT : Initializing ESX kernel change tracking for fid 367430644.
2015-09-01T18:48:35.934Z| vcpu-1| I120: DISKLIB-CBT : Successfuly created cbt node 16988bf5-cbt.
2015-09-01T18:48:35.934Z| vcpu-1| I120: DISKLIB-CBT : Opening cbt node /vmfs/devices/cbt/16988bf5-cbt
2015-09-01T18:48:35.934Z| vcpu-1| I120: DISKLIB-LIB : Opened "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002.vmdk" (flags 0x8, type vmfsSparse).
2015-09-01T18:48:35.935Z| vcpu-1| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : open successful (30) size = 48318382080, hd = 395676664. Type 3
2015-09-01T18:48:35.935Z| vcpu-1| I120: DISKLIB-DSCPTR: Opened [0]: "SAB16 (Printsrv)-flat.vmdk" (0x1e)
2015-09-01T18:48:35.935Z| vcpu-1| I120: DISKLIB-LINK : Opened '/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv).vmdk' (0x1e): vmfs, 94371840 sectors / 45 GB.
2015-09-01T18:48:35.935Z| vcpu-1| I120: DISKLIB-LIB : Resuming change tracking.
2015-09-01T18:48:36.036Z| vcpu-1| I120: DISKLIB-LIB : Opened "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv).vmdk" (flags 0x1e, type vmfs).
2015-09-01T18:48:36.043Z| vcpu-1| I120: ToolsBackup: Fixing MBR partitioned writable disk 'SAB16 (Printsrv)-000002.vmdk'.
2015-09-01T18:48:36.043Z| vcpu-1| I120: DDB: "longContentID" = "287c9b02ea6154a2db7f447a255d7a91" (was "6ad74ed28f03b9e8c864797c9ae214ec")
2015-09-01T18:48:36.080Z| vcpu-1| I120: DISKLIB-CTK : ChangeTracker_Merge: Merging 52 changes.
2015-09-01T18:48:36.081Z| vcpu-1| I120: ToolsBackup: Merged change tracking information from writable snapshot disk 'SAB16 (Printsrv)-000002.vmdk' since epoch 1.
2015-09-01T18:48:36.081Z| vcpu-1| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-flat.vmdk" : closed.
2015-09-01T18:48:36.083Z| vcpu-1| I120: DISKLIB-CBT : Shutting down change tracking for untracked fid 367430644.
2015-09-01T18:48:36.083Z| vcpu-1| I120: DISKLIB-CBT : Successfully disconnected CBT node.
2015-09-01T18:48:36.091Z| vcpu-1| I120: DISKLIB-VMFS : "/vmfs/volumes/555872a9-ac7a1ca0-d0ec-b083fee37ed1/SAB16 (Printsrv)/SAB16 (Printsrv)-000002-delta.vmdk" : closed.
2015-09-01T18:48:36.091Z| vcpu-1| I120: ToolsBackup: changing quiesce state: IDLE -> DONE
2015-09-01T18:48:36.096Z| vcpu-1| A115: ConfigDB: Setting displayName = "SAB16 (Printsrv)"
2015-09-01T18:48:36.105Z| vcpu-1| I120: SnapshotVMXTakeSnapshotComplete: Done with snapshot '01.09 testsnapshot': 18
2015-09-01T18:49:13.174Z| vmx| I120: GuestRpcSendTimedOut: message to toolbox-dnd timed out.
2015-09-01T18:49:13.247Z| vmx| I120: GuestRpcSendTimedOut: message to toolbox-dnd timed out.
2015-09-01T18:49:36.113Z| vmx| I120: GuestRpcSendTimedOut: message to toolbox-dnd timed out.

Verfasst: 02.09.2015, 14:46
von JustMe
Hmm, einerseits klar, aber andererseits...

Also, grundsaetzlich geht's wohl in die Richtung, die ~thc und ich angedeutet haben. Du hast da zwei Snapshots SAB16 (Printsrv)-000001.vmdk und SAB16 (Printsrv)-000002.vmdk, die beide auf dieselbe Basis Datei SAB16 (Printsrv).vmdk verweisen. Sogar auf denselben Stand dieser Datei (parentCID=11cd9fab). Sie werden anscheinend auch im Abstand weniger Millisekunden angelegt...

Was ich jetzt nicht verstehe, wieso der -000002-Snapshot als zusaetzliche Disk an diese VM selber, device scsi0:1, per HotAdd angehaengt wird...

Da waere vielleicht wieder 'ne Frage bei Veeam hilfreich, was da genau passiert, denn ich nehme mal an, dass die dargestellten Snapshot-Operationen davon getriggert werden.

Sorry...

Verfasst: 02.09.2015, 15:21
von Odi
wirklich seltsam.

nein, den snapshot hab ich gemacht.

veeam kommt da eigentlich gar nicht vor....

...bis auf die Tatsache das dieser Server auch als Veeam Proxy dient.

ich werd diesen Dienst mal deinstallieren.

Verfasst: 02.09.2015, 15:49
von JustMe
Odi hat geschrieben:...bis auf die Tatsache das dieser Server auch als Veeam Proxy dient.


Ich hatte mich nicht getraut, das zu vermuten; beim Namen "Printsrv".

Dann wuerde ich jetzt mal vermuten, dass da ein Job laeuft, in dem Du versuchst, Dich selbst (bzw. diese VM) per Veaam Proxy zu sichern.

Das wuerde erklaeren
- weswegen der erste Snapshot kommt
- weswegen per HotAdd was angefuegt wird

Was genau bedeutet denn "Den Snapshot hab' ich gemacht"? Im vSphere-Client, oder in der Veeam-Oberflaeche?

Der Begriff kam nur in Deinem ersten Posting vor; deshalb hatte ich ich diese Richtung weitergedacht.
Odi hat geschrieben:Hatte schon einen spezialisten hier und auch ein Veeam-Ticket.

Verfasst: 02.09.2015, 17:02
von Odi
Den snapshot hab ich im vsphereclient übers vcenter gemacht.

Bei diesen seltsamen snapshots siht man auch ein anderes verhalten beim erzeugen.
es geht relativ rasch bis 95% und bleibt dann für ca 20 sekunden stecken.

wenn das so ist weiß ich schon das es wieder zu so einem seltsamen snapshot gekommen ist.

Veeam-Ticket war ein Typo. sollte natürlich vmware-Ticket heißen.

Die Maschine sichert sich nicht selbst.
Die stellt nur ihre ressourcen als Proxy zur Verfügung um mit hotadd schneller sichern zu können

Verfasst: 03.09.2015, 10:27
von Odi
so, VeeamProxy deinstalliert, same shit as bevore :-(

Wieder sind zwei Snapshots sichtbar.
:?: :?: :?:

Verfasst: 03.09.2015, 10:43
von Dayworker
Verlinke doch bitte mal ein komplettes "vmware.log". Dann wissen wir vielleicht mehr.

Verfasst: 03.09.2015, 11:11
von Odi

Verfasst: 03.09.2015, 11:15
von Dayworker
Ich komme erst heute Abend/Nacht zum Analysieren, wenn überhaupt. Falls da jemand vorher drangehen will, immer ran. :D