W2003R2+VMWare + SCSI
Verfasst: 25.10.2008, 15:47
Hallo,
ich habe hier eine VM in der die Plattenzugriffe langsam sind
Die Plattendateien selbst liegen auf einer 500er SAS Platte.
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.673 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.378 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.393 seconds (ok)
Diese Zeilen machen mir Sorge.
was kann ich dagegen tun ?
Oct 25 15:30:22: vcpu-1| CPU reset: soft
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering IOSpace at 0x1060 (0x1060)
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:27: vcpu-0| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:27: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:0): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:1): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
ist das ok ? oder läuft hier was falsch ???
mfg
Egbert
Oct 25 15:30:13: vmx| Log for VMware Server pid=6540 version=1.0.7 build=build-108231 option=Release
Oct 25 15:30:13: vmx| Command line: "C:\Programme (x86)\VMware\VMware Server\bin\vmware-vmx.exe" "-T" "querytoken" "d:\vm\drkwfs2\windows server 2003 standard edition.vmx"
Oct 25 15:30:13: vmx| vmxvmdb: Index name being generated from config file
Oct 25 15:30:13: vmx| VMXVmdbConnectServerd - Trying to discover serverd
Oct 25 15:30:13: vmx| MStat: Creating Stat system.cpuusage
Oct 25 15:30:13: vmx| MStat: Creating Stat system.ram
Oct 25 15:30:13: vmx| MStat: Creating Stat system.uptime
Oct 25 15:30:13: vmx| MStat: Creating Stat system.load
Oct 25 15:30:13: vmx| CPU #0 TSC = 24509348338657
Oct 25 15:30:13: vmx| CPU #1 TSC = 24509348339581
Oct 25 15:30:13: vmx| CPU #2 TSC = 24509348338391
Oct 25 15:30:13: vmx| CPU #3 TSC = 24509348338391
Oct 25 15:30:13: vmx| CPU #4 TSC = 24509348339028
Oct 25 15:30:13: vmx| CPU #5 TSC = 24509348338531
Oct 25 15:30:13: vmx| CPU #6 TSC = 24509348337922
Oct 25 15:30:13: vmx| CPU #7 TSC = 24509348338097
Oct 25 15:30:13: vmx| TSC delta 1659
Oct 25 15:30:13: vmx| VMMon_GetkHzEstimate: Calculated 2333000 kHz
Oct 25 15:30:13: vmx| cpuids[0].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[1].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[2].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[3].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[4].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[5].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[6].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[7].id81.ecx = 0x1
Oct 25 15:30:13: vmx| pcpu #0 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #0 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x40800
Oct 25 15:30:13: vmx| pcpu #0 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #1 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #1 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x1040800
Oct 25 15:30:13: vmx| pcpu #1 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #2 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #2 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x2040800
Oct 25 15:30:13: vmx| pcpu #2 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #3 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #3 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x3040800
Oct 25 15:30:13: vmx| pcpu #3 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #4 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #4 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x4040800
Oct 25 15:30:13: vmx| pcpu #4 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #5 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #5 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x5040800
Oct 25 15:30:13: vmx| pcpu #5 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #6 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #6 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x6040800
Oct 25 15:30:13: vmx| pcpu #6 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #7 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #7 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x7040800
Oct 25 15:30:13: vmx| pcpu #7 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| CPUID id1.edx: 0xbfebfbff id1.ecx: 0xce3bd id81.edx: 0x20100000 id81.ecx: 0x1
Oct 25 15:30:13: vmx| CPUID id88.ecx: 0 id88.edx: 0
Oct 25 15:30:13: vmx| ACL_InitCapabilities: here 1 (bug 63252)
Oct 25 15:30:13: vmx| changing directory to d:\vm\drkwfs2\.
Oct 25 15:30:13: vmx| Config file: d:\vm\drkwfs2\windows server 2003 standard edition.vmx
Oct 25 15:30:13: vmx| LOG failed to remove D:\vm\drkwfs2\vmware-2.log failed: Das System kann die angegebene Datei nicht finden
Oct 25 15:30:13: vmx| VMDB: Connected to serverd
Oct 25 15:30:13: vmx| IPCHandleConnection: ReadFile failed (code 109)
Oct 25 15:30:13: vmx| VMXVmdbCbVmVmxExecState: Exec state change requested to state poweredOn without reset
Oct 25 15:30:13: vmx| PowerOn
Oct 25 15:30:13: vmx| Host: WIN32 highest NUMA node 0
Oct 25 15:30:13: vmx| Host: WIN32 NUMA node 0, CPU mask 0x00000000000000ff
Oct 25 15:30:13: vmx| HOSTINFO: Seeing Intel CPU, numCoresPerCPU 1 numThreadsPerCore 1.
Oct 25 15:30:13: vmx| HOSTINFO: This machine has 8 physical CPUS, 8 total cores, and 8 logical CPUs.
Oct 25 15:30:13: vmx| HOST Windows version 5.2, build 3790, platform 2, "Service Pack 2", SMP
Oct 25 15:30:13: vmx| DICT --- USER PREFERENCES
Oct 25 15:30:13: vmx| DICT --- USER DEFAULTS
Oct 25 15:30:13: vmx| DICT --- HOST DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- SITE DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- COMMAND LINE
Oct 25 15:30:13: vmx| DICT --- CONFIGURATION
Oct 25 15:30:13: vmx| DICT config.version = 8
Oct 25 15:30:13: vmx| DICT virtualHW.version = 4
Oct 25 15:30:13: vmx| DICT numvcpus = 2
Oct 25 15:30:13: vmx| DICT scsi0.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0.virtualDev = lsilogic
Oct 25 15:30:13: vmx| DICT memsize = 2336
Oct 25 15:30:13: vmx| DICT scsi0:0.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:0.fileName = drkwfs2-c-21gb.vmdk
Oct 25 15:30:13: vmx| DICT ide1:0.present = FALSE
Oct 25 15:30:13: vmx| DICT ide1:0.fileName = auto detect
Oct 25 15:30:13: vmx| DICT ide1:0.deviceType = cdrom-raw
Oct 25 15:30:13: vmx| DICT floppy0.fileName = A:
Oct 25 15:30:13: vmx| DICT Ethernet0.present = TRUE
Oct 25 15:30:13: vmx| DICT displayName = drkwfs2-OK-081025
Oct 25 15:30:13: vmx| DICT guestOS = winnetstandard
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT scsi0:1.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:1.fileName = drkwfs2-r-40gb-daten.vmdk
Oct 25 15:30:13: vmx| DICT scsi0:2.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:2.fileName = drkwfs2-s-datensicherung.vmdk
Oct 25 15:30:13: vmx| DICT scsi0:2.mode = persistent
Oct 25 15:30:13: vmx| DICT ide1:0.autodetect = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:0.redo =
Oct 25 15:30:13: vmx| DICT scsi0:1.redo =
Oct 25 15:30:13: vmx| DICT scsi0:2.redo =
Oct 25 15:30:13: vmx| DICT ethernet0.addressType = generated
Oct 25 15:30:13: vmx| DICT uuid.location = 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| DICT uuid.bios = 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| DICT ethernet0.generatedAddress = 00:0c:29:e3:3d:aa
Oct 25 15:30:13: vmx| DICT ethernet0.generatedAddressOffset = 0
Oct 25 15:30:13: vmx| DICT scsi0:3.present = FALSE
Oct 25 15:30:13: vmx| DICT scsi0:3.fileName = G:\drkwfs2\drkwfs2.vmdk
Oct 25 15:30:13: vmx| DICT scsi0:4.present = FALSE
Oct 25 15:30:13: vmx| DICT scsi0:4.fileName = G:\drkwfs2\drkwfs2 (2).vmdk
Oct 25 15:30:13: vmx| DICT scsi0:3.redo =
Oct 25 15:30:13: vmx| DICT scsi0:4.redo =
Oct 25 15:30:13: vmx| DICT ide1:0.clientDevice = TRUE
Oct 25 15:30:13: vmx| DICT ide1:0.startConnected = FALSE
Oct 25 15:30:13: vmx| DICT tools.syncTime = FALSE
Oct 25 15:30:13: vmx| DICT floppy0.startConnected = FALSE
Oct 25 15:30:13: vmx| DICT autostart = poweron
Oct 25 15:30:13: vmx| DICT workingDir = .
Oct 25 15:30:13: vmx| DICT floppy0.present = FALSE
Oct 25 15:30:13: vmx| DICT --- USER DEFAULTS
Oct 25 15:30:13: vmx| DICT --- HOST DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- SITE DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- GLOBAL SETTINGS
Oct 25 15:30:13: vmx| WSSCAN: reserved mem (in MB) min=32 max=16256 recommended=16256
Oct 25 15:30:13: vmx| hostMem=16384 maxAllowedAll=-1 maxAllowedVM=3600
Oct 25 15:30:13: vmx| totOverhead=16
Oct 25 15:30:13: vmx| WSSCAN: reserved mem (in MB) 7797, min=32 max=16256
Oct 25 15:30:13: vmx| WSSCAN: Overhead 604403 paged 18863 nonpaged 4096 maxFBSize
Oct 25 15:30:13: vmx| WSSCAN 1 2 1996032 3937465 1996032 4192944 50 0
Oct 25 15:30:13: vmx| LICENSE using: 'HKEY_LOCAL_MACHINE\SOFTWARE\VMware, Inc.\VMware Server\License.vs.1.0-00'
Oct 25 15:30:13: vmx| STATDECLGROUP stats Root "" null
Oct 25 15:30:13: vmx| Host CPUID features: version 0x10678 id1.edx 0xbfebfbff id1.ecx 0xce3bd id81.edx 0x20100000 id81.ecx 0x1
Oct 25 15:30:13: vmx| CPU.cpuFeatures = 0xb971ff37
Oct 25 15:30:13: vmx| CPUID after masking: version 0x10678 id1.edx 0xfebbbff id1.ecx 0xc8215 id81.edx 0x100800 id81.ecx 0x0 id88.ecx 0x0
Oct 25 15:30:13: vmx| CPU.cpuFeatures = 0x9871fe03
Oct 25 15:30:13: vmx| APIC: Local APIC at 0xfee00000
Oct 25 15:30:13: vmx| KHZEstimate 2333000
Oct 25 15:30:13: vmx| MHZEstimate 2333
Oct 25 15:30:13: vmx| NumVCPUs 2
Oct 25 15:30:13: vmx| UUID: location-UUID is 56 4d 29 0a 1b 43 6e 4b-a6 5d 6c b2 f0 82 b1 75
Oct 25 15:30:13: vmx| UUID: canonical path is d:\vm\drkwfs2\windows server 2003 standard edition.vmx
Oct 25 15:30:13: vmx| UUID: location-UUID is 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| MM: Using partialmap, 598016 pages AC 0 CE 1 TM 0 DOHU 0
Oct 25 15:30:13: vmx| UUID: canonical path is d:\vm\drkwfs2\windows server 2003 standard edition.vmx
Oct 25 15:30:13: vmx| UUID: location-UUID is 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| MM: using fileName d:\vm\drkwfs2\564d26a6-cec8-54fd-b611-f6fa5be33daa.vmem for paging
Oct 25 15:30:13: vmx| Msg_Reset:
Oct 25 15:30:13: vmx| [msg.monitorInit.vmm64.initHost.VTDisabled] This CPU is VT-capable, but VT is not enabled (check your BIOS settings).
Oct 25 15:30:13: vmx| [msg.monitorInit.vmm64.initHost.VTDisabled] This CPU is VT-capable, but VT is not enabled (check your BIOS settings).
Oct 25 15:30:13: vmx| ----------------------------------------
Oct 25 15:30:13: vmx| Opened paging file d:\vm\drkwfs2\564d26a6-cec8-54fd-b611-f6fa5be33daa.vmem
Oct 25 15:30:13: vmx| Mapped mainmem as pageable
Oct 25 15:30:13: vmx| MStat: Creating Stat vm.cpuusage
Oct 25 15:30:13: vmx| MStat: Creating Stat vm.ram
Oct 25 15:30:13: vmx| MStat: Creating Stat vm.uptime
Oct 25 15:30:13: vmx| DISK: OPEN scsi0:0 'd:\vm\drkwfs2\drkwfs2-c-21gb.vmdk' persistent R[(null)]
Oct 25 15:30:13: vmx| DISKLIB-DSCPTR: Opened [0]: "drkwfs2-c-21gb-flat.vmdk" 0 (0xa)
Oct 25 15:30:13: vmx| DISKLIB-LINK : Opened 'd:\vm\drkwfs2\drkwfs2-c-21gb.vmdk' (0xa): monolithicFlat, 44040192 sectors / 21504 Mb.
Oct 25 15:30:13: vmx| DISKLIB-LIB : Opened "d:\vm\drkwfs2\drkwfs2-c-21gb.vmdk" (flags 0xa).
Oct 25 15:30:13: vmx| DISK: OPEN 'd:\vm\drkwfs2\drkwfs2-c-21gb.vmdk' Geo (2741/255/63) BIOS Geo (2741/255/63) freeSpace=245848Mb
Oct 25 15:30:13: vmx| DISK: OPEN scsi0:1 'd:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk' persistent R[(null)]
Oct 25 15:30:13: vmx| DISKLIB-DSCPTR: Opened [0]: "drkwfs2-r-40gb-daten-flat.vmdk" 0 (0xa)
Oct 25 15:30:13: vmx| DISKLIB-LINK : Opened 'd:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk' (0xa): monolithicFlat, 83886080 sectors / 40960 Mb.
Oct 25 15:30:13: vmx| DISKLIB-LIB : Opened "d:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk" (flags 0xa).
Oct 25 15:30:13: vmx| DISK: OPEN 'd:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk' Geo (5221/255/63) BIOS Geo (5221/255/63) freeSpace=245848Mb
Oct 25 15:30:13: vmx| DISK: OPEN scsi0:2 'd:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk' persistent R[(null)]
Oct 25 15:30:14: vmx| DISKLIB-DSCPTR: Opened [0]: "drkwfs2-s-datensicherung.vmdk" (0xa)
Oct 25 15:30:14: vmx| DISKLIB-LINK : Opened 'd:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk' (0xa): monolithicSparse, 73400320 sectors / 35840 Mb.
Oct 25 15:30:14: vmx| DISKLIB-LIB : Opened "d:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk" (flags 0xa).
Oct 25 15:30:14: vmx| DISK: OPEN 'd:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk' Geo (4568/255/63) BIOS Geo (4568/255/63) freeSpace=245848Mb
Oct 25 15:30:14: vmx| TimeTracker host to guest rate conversion 24511408494832 @ 2333000000Hz -> 24511408494832 @ 2333000000Hz
Oct 25 15:30:14: vmx| TimeTracker host to guest rate conversion ((x * 2147483648) >> 31) + 0
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:0.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:0.byteswritten
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:0 : capacity=44040192
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:0 : geometry=2741/255/63
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:1.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:1.byteswritten
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:1 : capacity=83886080
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:1 : geometry=5221/255/63
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:2.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:2.byteswritten
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:2 : capacity=73400320
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:2 : geometry=4568/255/63
Oct 25 15:30:14: vmx| SCSI0: UNTAGGED commands will be converted to ORDER tags.
Oct 25 15:30:14: vmx| MStat: Creating Stat vm.heartbeat
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:30:14: vmx| TOOLS INSTALL initializing state to IDLE on power on.
Oct 25 15:30:14: vmx| VLANCE: send cluster threshold is 80, size = 2 recalcInterval is 2 ticks
Oct 25 15:30:14: vmx| MStat: Creating Stat ethernet0.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat ethernet0.byteswritten
Oct 25 15:30:14: vmx| Ethernet0 MAC Address: 00:0c:29:e3:3d:aa
Oct 25 15:30:14: vmx| VMXNET: send cluster threshold is 80, size = 2 recalcInterval is 2 ticks, dontClusterSize is 128
Oct 25 15:30:14: vmx| E1000: checksum cycles/kB: C=1036 asm=678
Oct 25 15:30:14: vmx| VirtualProtect MapProtectMem(0x27b0000,0x1000) returns 0x1e7
Oct 25 15:30:14: vmx| Can't read-only monitor pages from 0x027B0000 to 0x027B1000
Oct 25 15:30:14: vmx| VirtualProtect MapProtectMem(0x27b2000,0x1000) returns 0x1e7
Oct 25 15:30:14: vmx| Can't read-only monitor pages from 0x027B2000 to 0x027B3000
Oct 25 15:30:14: vmx| VirtualProtect MapProtectMem(0x27b4000,0x0) returns 0x57
Oct 25 15:30:14: vmx| Can't read-only monitor pages from 0x027B4000 to 0x027B4000
Oct 25 15:30:14: vmx| VMX_PowerOn: ModuleTable_PowerOn = 1
Oct 25 15:30:14: vmx| VMX setting maximum IPC write buffers to 0 packets, 0 bytes
Oct 25 15:30:14: mks| Async MKS thread is alive
Oct 25 15:30:14: vcpu-0| APIC: version = 0x14, max LVT = 5
Oct 25 15:30:14: vcpu-0| APIC: LDR = 0x1000000, DFR = 0xffffffff
Oct 25 15:30:14: vmx| Create Memory BIO succeeded.
Oct 25 15:30:14: vmx| Create Memory BIO succeeded.
Oct 25 15:30:14: vmx| Accepted new connection at 1044 for thread servercontrol (0x933b18)
Oct 25 15:30:14: vmx| VUINewControlConnection: before slow ACL gunk (bug 63252).
Oct 25 15:30:14: vmx| ACL: Thread from (SYSTEM) gets full perms
Oct 25 15:30:14: vmx| VUINewControlConnection: after slow ACL gunk (bug 63252).
Oct 25 15:30:14: vmx| VUI: A new VMControl client connected.
Oct 25 15:30:14: vcpu-0| PShare: enabled 1, scanRate 32, checkRate 16
Oct 25 15:30:14: vcpu-0| guestCpuFeatures = 0x9871fe03
Oct 25 15:30:14: vcpu-0| Init modules.
Oct 25 15:30:14: vcpu-0| CPU reset: hard
Oct 25 15:30:14: vmx| VNET: Notification enabled for Ethernet0
Oct 25 15:30:14: vcpu-0| INTELRDMSR(0x8b) = 0x0000060b00000000
Oct 25 15:30:14: vcpu-0| INTELRDMSR(0x17) = 0x0018000088640720
Oct 25 15:30:14: vcpu-0| sz=3075424
Oct 25 15:30:14: vcpu-1| APIC: version = 0x14, max LVT = 5
Oct 25 15:30:14: vcpu-1| APIC: LDR = 0x4000000, DFR = 0xffffffff
Oct 25 15:30:14: vmx| IPC version negotiation version: VMX returning 2.1 to servercontrol
Oct 25 15:30:14: vmx| IPC vmcontrol-temp version: VMX returning 11.4 to servercontrol that tried 11.4
Oct 25 15:30:14: vcpu-1| guestCpuFeatures = 0x9871fe03
Oct 25 15:30:14: vcpu-1| Init modules.
Oct 25 15:30:14: vcpu-1| CPU reset: hard
Oct 25 15:30:14: vcpu-1| INTELRDMSR(0x8b) = 0x0000060b00000000
Oct 25 15:30:14: vcpu-1| INTELRDMSR(0x17) = 0x0018000088640720
Oct 25 15:30:14: vcpu-1| sz=3075424
Oct 25 15:30:14: vcpu-1| vmm32 initialized: Releasebuild-108231. cflags: 0x02000002.01803000.00000054
Oct 25 15:30:14: vcpu-0| vmm32 initialized: Releasebuild-108231. cflags: 0x02000002.01803000.00000054
Oct 25 15:30:14: vcpu-1| CPU reset: soft
Oct 25 15:30:14: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0x0) and 0xec000000(0x0)
Oct 25 15:30:14: mks| Ignoring update request in VGA_Expose (mode change pending).
Oct 25 15:30:14: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-0| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:14: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-1| CPU reset: soft
Oct 25 15:30:15: mks| VNCENCODE 1 encoding mode change: (640x480x16depth,16bpp)
Oct 25 15:30:15: vcpu-0| DISKUTIL: scsi0:0 : geometry=2741/255/63
Oct 25 15:30:15: vcpu-0| DISKUTIL: scsi0:1 : geometry=5221/255/63
Oct 25 15:30:15: vcpu-0| DISKUTIL: scsi0:2 : geometry=4568/255/63
Oct 25 15:30:15: vcpu-1| CPU reset: soft
Oct 25 15:30:16: vcpu-0| BIOS-UUID is 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:30:16: mks| VNCENCODE 1 encoding mode change: (720x400x16depth,16bpp)
Oct 25 15:30:16: vcpu-0| Unknown int 10h func 0x2000
Oct 25 15:30:16: mks| VNCENCODE 1 encoding mode change: (640x480x16depth,16bpp)
Oct 25 15:30:22: mks| VNCENCODE 1 encoding mode change: (720x400x16depth,16bpp)
Oct 25 15:30:22: mks| VNCENCODE 1 encoding mode change: (640x480x16depth,16bpp)
Oct 25 15:30:22: vcpu-1| CPU reset: soft
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering IOSpace at 0x1060 (0x1060)
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:27: vcpu-0| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:27: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:0): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:1): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:2): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:0): MODE SENSE(6) for unsupported page 0x1c
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:1): MODE SENSE(6) for unsupported page 0x1c
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:2): MODE SENSE(6) for unsupported page 0x1c
Oct 25 15:30:42: vcpu-0| POLL device deleted
Oct 25 15:30:42: vcpu-1| VNET: Notification enabled for Ethernet0
Oct 25 15:30:42: mks| SOCKET 1 new update req with non-empty pending: logical error on server/client?
Oct 25 15:30:42: vcpu-1| SVGA: Unregistering IOSpace at 0x1060 (0x1060)
Oct 25 15:30:42: vcpu-1| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:42: vcpu-1| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:42: vcpu-1| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:42: vcpu-0| Guest OS = 0x5016
Oct 25 15:30:47: mks| SVGA: Using extended FIFO: Caps 0x00000007, Flags 0x00000000
Oct 25 15:30:47: mks| VNCENCODE 1 encoding mode change: (912x656x24depth,32bpp)
Oct 25 15:30:47: mks| MKS remote display status changed, enabling remoteoptimizations
Oct 25 15:30:49: mks| HostOps hideCursor before defineCursor!
Oct 25 15:30:50: mks| SOCKET 1 new update req with non-empty pending: logical error on server/client?
Oct 25 15:31:12: vcpu-1| MKS Backdoor get pointer: first time, notify tools are running
Oct 25 15:31:12: vcpu-1| GuestRpc: Channel 0, registration number 1, guest application toolbox.
Oct 25 15:31:12: vcpu-1| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:31:12: vcpu-1| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:31:12: vcpu-1| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:31:12: vcpu-1| Guest: toolbox: Version: build-108231
Oct 25 15:31:12: vcpu-1| TOOLS setting the tools version to '6535'
Oct 25 15:31:12: vcpu-1| TOOLS unified loop capability requested by 'toolbox'; now sending options via TCLO
Oct 25 15:31:41: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:32:11: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:32:42: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:33:12: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:33:33: vcpu-0| VMMouse: CMD Read ID
Oct 25 15:33:33: vcpu-0| MKS switching absolute mouse on
Oct 25 15:33:43: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:33:53: vcpu-1| TOOLS unified loop capability requested by 'toolbox-dnd'; now sending options via TCLO
Oct 25 15:33:53: vcpu-1| GuestRpc: Channel 1, registration number 1, guest application toolbox-dnd.
Oct 25 15:33:53: vcpu-1| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:33:53: vcpu-1| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:33:53: vcpu-1| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:34:13: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:34:18: vmx| SCSI0:0: Command WRITE(10) took 1.671 seconds (ok)
Oct 25 15:34:18: vmx| SCSI0:0: Command WRITE(10) took 1.682 seconds (ok)
Oct 25 15:34:19: vmx| SCSI0:0: Command WRITE(10) took 1.527 seconds (ok)
Oct 25 15:34:44: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:34:54: vcpu-1| TOOLS unified loop capability requested by 'toolbox-dnd'; now sending options via TCLO
Oct 25 15:34:54: vcpu-1| GuestRpc: Channel 2, conflict: guest application toolbox-dnd tried to register, but it is still registered on channel 1
Oct 25 15:34:54: vcpu-1| GuestRpc: Channel 2 reinitialized.
Oct 25 15:34:54: vcpu-1| GuestRpc: Channel 2 reinitialized.
Oct 25 15:34:58: vmx| SCSI0:0: Command READ(10) took 1.512 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.001 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.702 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.702 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.333 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.156 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.155 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.155 seconds (ok)
Oct 25 15:35:14: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:35:44: vmx| SCSI0:0: Command WRITE(10) took 1.514 seconds (ok)
Oct 25 15:35:45: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:36:15: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:36:26: vmx| SCSI0:0: Command WRITE(10) took 1.447 seconds (ok)
Oct 25 15:36:46: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:37:16: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:37:46: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:38:17: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:38:45: vmx| SCSI0:0: Command WRITE(10) took 1.718 seconds (ok)
Oct 25 15:38:45: vmx| SCSI0:0: Command WRITE(10) took 1.718 seconds (ok)
Oct 25 15:38:47: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:39:18: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:39:35: vmx| SCSI0:0: Command WRITE(10) took 1.066 seconds (ok)
Oct 25 15:39:48: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:40:00: vmx| SCSI0:0: Command WRITE(10) took 1.281 seconds (ok)
Oct 25 15:40:11: vmx| SCSI0:0: Command WRITE(10) took 1.097 seconds (ok)
Oct 25 15:40:19: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:40:22: vmx| SCSI0:0: Command WRITE(10) took 1.675 seconds (ok)
Oct 25 15:40:49: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:40:58: vmx| SCSI0:0: Command WRITE(10) took 1.400 seconds (ok)
Oct 25 15:40:58: vmx| SCSI0:0: Command WRITE(10) took 1.441 seconds (ok)
Oct 25 15:41:20: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:41:42: vmx| SCSI0:0: Command WRITE(10) took 1.694 seconds (ok)
Oct 25 15:41:42: vmx| SCSI0:0: Command WRITE(10) took 1.670 seconds (ok)
Oct 25 15:41:50: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:41:52: vmx| SCSI0:0: Command WRITE(10) took 1.529 seconds (ok)
Oct 25 15:41:59: vmx| SCSI0:0: Command WRITE(10) took 1.296 seconds (ok)
Oct 25 15:42:01: vmx| SCSI0:0: Command WRITE(10) took 1.583 seconds (ok)
Oct 25 15:42:01: vmx| SCSI0:0: Command WRITE(10) took 1.819 seconds (ok)
Oct 25 15:42:03: vmx| SCSI0:0: Command WRITE(10) took 1.384 seconds (ok)
Oct 25 15:42:05: mks| MKS set guest selection request with invalid state 2
Oct 25 15:42:07: vcpu-0| Guest: toolbox: Got a logoff event.
Oct 25 15:42:07: vcpu-0| GuestRpc: Channel 1 reinitialized.
Oct 25 15:42:08: vcpu-0| Guest: toolbox: Got a logoff event.
Oct 25 15:42:13: vmx| SCSI0:0: Command READ(10) took 1.661 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.685 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.430 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.752 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.546 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.438 seconds (ok)
Oct 25 15:42:21: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.673 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.378 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.393 seconds (ok)
Oct 25 15:42:25: vcpu-0| Guest: toolbox: VMware Tools Service Shutdown.
Oct 25 15:42:25: vcpu-0| Guest: toolbox: VMware Tools Service Stopping.
Oct 25 15:42:25: vcpu-1| GuestRpc: Channel 0 reinitialized.
Oct 25 15:42:48: vmx| SCSI0:0: Command WRITE(10) took 1.590 seconds (ok)
Oct 25 15:42:50: vcpu-0| POLL device deleted
Oct 25 15:42:50: vcpu-1| VNET: Notification enabled for Ethernet0
Oct 25 15:42:50: vcpu-1| VMMouse: CMD Disable
Oct 25 15:42:50: vcpu-1| VMMouse: Disabling VMMouse mode
Oct 25 15:42:50: vcpu-1| MKS switching absolute mouse on
Oct 25 15:42:50: vcpu-0| PIIX4: PM Soft Off. Good-bye.
Oct 25 15:42:50: vmx| Stopping VCPU threads...
Oct 25 15:42:50: mks| Async MKS thread is exiting
Oct 25 15:42:50: vmx| DnD rpc already set to 0
Oct 25 15:42:50: vmx| TOOLS received request in VMX to set option 'enableDnD' -> '0'
Oct 25 15:42:50: vmx| SOCKET 1 close VNC socket on VNCBackendDestroy
Oct 25 15:42:50: vmx| MKS local poweroff
Oct 25 15:42:50: vmx| Lock before MKS lock created. Early poweroff?
Oct 25 15:42:50: vmx| Unlock before MKS lock created. Early poweroff?
Oct 25 15:42:50: vmx| scsi0:2: numIOs = 412 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
Oct 25 15:42:50: vmx| scsi0:1: numIOs = 6676 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
Oct 25 15:42:50: vmx| scsi0:0: numIOs = 27109 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
Oct 25 15:42:50: vmx| AIOWIN32: asyncOps=31858 syncOps=76 bufSize=344Kb delayed=2744 fixed=311 sgOp=29625 sgOn=1
Oct 25 15:42:50: vmx| VMX idle exit
Oct 25 15:42:50: vmx| VMX IPC closed the connection with thread servercontrol (00933B18)
Oct 25 15:42:50: vmx| VMX: Remote VMControl client servercontrol disconnected.
Oct 25 15:42:50: vmx| Flushing VMX VMDB connections
Oct 25 15:42:50: vmx| IPC_exit: disconnecting all threads
Oct 25 15:42:50: vmx| VMX exit.
Oct 25 15:42:50: vmx| AIOMGR-S : stat o=9 r=15 w=0 i=0 br=29604 bw=0
ich habe hier eine VM in der die Plattenzugriffe langsam sind
Die Plattendateien selbst liegen auf einer 500er SAS Platte.
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.673 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.378 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.393 seconds (ok)
Diese Zeilen machen mir Sorge.
was kann ich dagegen tun ?
Oct 25 15:30:22: vcpu-1| CPU reset: soft
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering IOSpace at 0x1060 (0x1060)
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:27: vcpu-0| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:27: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:0): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:1): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
ist das ok ? oder läuft hier was falsch ???
mfg
Egbert
Oct 25 15:30:13: vmx| Log for VMware Server pid=6540 version=1.0.7 build=build-108231 option=Release
Oct 25 15:30:13: vmx| Command line: "C:\Programme (x86)\VMware\VMware Server\bin\vmware-vmx.exe" "-T" "querytoken" "d:\vm\drkwfs2\windows server 2003 standard edition.vmx"
Oct 25 15:30:13: vmx| vmxvmdb: Index name being generated from config file
Oct 25 15:30:13: vmx| VMXVmdbConnectServerd - Trying to discover serverd
Oct 25 15:30:13: vmx| MStat: Creating Stat system.cpuusage
Oct 25 15:30:13: vmx| MStat: Creating Stat system.ram
Oct 25 15:30:13: vmx| MStat: Creating Stat system.uptime
Oct 25 15:30:13: vmx| MStat: Creating Stat system.load
Oct 25 15:30:13: vmx| CPU #0 TSC = 24509348338657
Oct 25 15:30:13: vmx| CPU #1 TSC = 24509348339581
Oct 25 15:30:13: vmx| CPU #2 TSC = 24509348338391
Oct 25 15:30:13: vmx| CPU #3 TSC = 24509348338391
Oct 25 15:30:13: vmx| CPU #4 TSC = 24509348339028
Oct 25 15:30:13: vmx| CPU #5 TSC = 24509348338531
Oct 25 15:30:13: vmx| CPU #6 TSC = 24509348337922
Oct 25 15:30:13: vmx| CPU #7 TSC = 24509348338097
Oct 25 15:30:13: vmx| TSC delta 1659
Oct 25 15:30:13: vmx| VMMon_GetkHzEstimate: Calculated 2333000 kHz
Oct 25 15:30:13: vmx| cpuids[0].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[1].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[2].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[3].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[4].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[5].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[6].id81.ecx = 0x1
Oct 25 15:30:13: vmx| cpuids[7].id81.ecx = 0x1
Oct 25 15:30:13: vmx| pcpu #0 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #0 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x40800
Oct 25 15:30:13: vmx| pcpu #0 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #1 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #1 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x1040800
Oct 25 15:30:13: vmx| pcpu #1 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #2 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #2 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x2040800
Oct 25 15:30:13: vmx| pcpu #2 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #3 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #3 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x3040800
Oct 25 15:30:13: vmx| pcpu #3 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #4 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #4 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x4040800
Oct 25 15:30:13: vmx| pcpu #4 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #5 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #5 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x5040800
Oct 25 15:30:13: vmx| pcpu #5 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #6 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #6 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x6040800
Oct 25 15:30:13: vmx| pcpu #6 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| pcpu #7 CPUID numEntries=10 GenuntelineI
Oct 25 15:30:13: vmx| pcpu #7 CPUID version=0x10676 id1.edx=0xbfebfbff id1.ecx=0xce3bd id1.ebx=0x7040800
Oct 25 15:30:13: vmx| pcpu #7 CPUID id80.eax=80000008 id81.edx=0x20100000 id81.ecx=0x1
Oct 25 15:30:13: vmx| CPUID id1.edx: 0xbfebfbff id1.ecx: 0xce3bd id81.edx: 0x20100000 id81.ecx: 0x1
Oct 25 15:30:13: vmx| CPUID id88.ecx: 0 id88.edx: 0
Oct 25 15:30:13: vmx| ACL_InitCapabilities: here 1 (bug 63252)
Oct 25 15:30:13: vmx| changing directory to d:\vm\drkwfs2\.
Oct 25 15:30:13: vmx| Config file: d:\vm\drkwfs2\windows server 2003 standard edition.vmx
Oct 25 15:30:13: vmx| LOG failed to remove D:\vm\drkwfs2\vmware-2.log failed: Das System kann die angegebene Datei nicht finden
Oct 25 15:30:13: vmx| VMDB: Connected to serverd
Oct 25 15:30:13: vmx| IPCHandleConnection: ReadFile failed (code 109)
Oct 25 15:30:13: vmx| VMXVmdbCbVmVmxExecState: Exec state change requested to state poweredOn without reset
Oct 25 15:30:13: vmx| PowerOn
Oct 25 15:30:13: vmx| Host: WIN32 highest NUMA node 0
Oct 25 15:30:13: vmx| Host: WIN32 NUMA node 0, CPU mask 0x00000000000000ff
Oct 25 15:30:13: vmx| HOSTINFO: Seeing Intel CPU, numCoresPerCPU 1 numThreadsPerCore 1.
Oct 25 15:30:13: vmx| HOSTINFO: This machine has 8 physical CPUS, 8 total cores, and 8 logical CPUs.
Oct 25 15:30:13: vmx| HOST Windows version 5.2, build 3790, platform 2, "Service Pack 2", SMP
Oct 25 15:30:13: vmx| DICT --- USER PREFERENCES
Oct 25 15:30:13: vmx| DICT --- USER DEFAULTS
Oct 25 15:30:13: vmx| DICT --- HOST DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- SITE DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- COMMAND LINE
Oct 25 15:30:13: vmx| DICT --- CONFIGURATION
Oct 25 15:30:13: vmx| DICT config.version = 8
Oct 25 15:30:13: vmx| DICT virtualHW.version = 4
Oct 25 15:30:13: vmx| DICT numvcpus = 2
Oct 25 15:30:13: vmx| DICT scsi0.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0.virtualDev = lsilogic
Oct 25 15:30:13: vmx| DICT memsize = 2336
Oct 25 15:30:13: vmx| DICT scsi0:0.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:0.fileName = drkwfs2-c-21gb.vmdk
Oct 25 15:30:13: vmx| DICT ide1:0.present = FALSE
Oct 25 15:30:13: vmx| DICT ide1:0.fileName = auto detect
Oct 25 15:30:13: vmx| DICT ide1:0.deviceType = cdrom-raw
Oct 25 15:30:13: vmx| DICT floppy0.fileName = A:
Oct 25 15:30:13: vmx| DICT Ethernet0.present = TRUE
Oct 25 15:30:13: vmx| DICT displayName = drkwfs2-OK-081025
Oct 25 15:30:13: vmx| DICT guestOS = winnetstandard
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT scsi0:1.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:1.fileName = drkwfs2-r-40gb-daten.vmdk
Oct 25 15:30:13: vmx| DICT scsi0:2.present = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:2.fileName = drkwfs2-s-datensicherung.vmdk
Oct 25 15:30:13: vmx| DICT scsi0:2.mode = persistent
Oct 25 15:30:13: vmx| DICT ide1:0.autodetect = TRUE
Oct 25 15:30:13: vmx| DICT scsi0:0.redo =
Oct 25 15:30:13: vmx| DICT scsi0:1.redo =
Oct 25 15:30:13: vmx| DICT scsi0:2.redo =
Oct 25 15:30:13: vmx| DICT ethernet0.addressType = generated
Oct 25 15:30:13: vmx| DICT uuid.location = 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| DICT uuid.bios = 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| DICT ethernet0.generatedAddress = 00:0c:29:e3:3d:aa
Oct 25 15:30:13: vmx| DICT ethernet0.generatedAddressOffset = 0
Oct 25 15:30:13: vmx| DICT scsi0:3.present = FALSE
Oct 25 15:30:13: vmx| DICT scsi0:3.fileName = G:\drkwfs2\drkwfs2.vmdk
Oct 25 15:30:13: vmx| DICT scsi0:4.present = FALSE
Oct 25 15:30:13: vmx| DICT scsi0:4.fileName = G:\drkwfs2\drkwfs2 (2).vmdk
Oct 25 15:30:13: vmx| DICT scsi0:3.redo =
Oct 25 15:30:13: vmx| DICT scsi0:4.redo =
Oct 25 15:30:13: vmx| DICT ide1:0.clientDevice = TRUE
Oct 25 15:30:13: vmx| DICT ide1:0.startConnected = FALSE
Oct 25 15:30:13: vmx| DICT tools.syncTime = FALSE
Oct 25 15:30:13: vmx| DICT floppy0.startConnected = FALSE
Oct 25 15:30:13: vmx| DICT autostart = poweron
Oct 25 15:30:13: vmx| DICT workingDir = .
Oct 25 15:30:13: vmx| DICT floppy0.present = FALSE
Oct 25 15:30:13: vmx| DICT --- USER DEFAULTS
Oct 25 15:30:13: vmx| DICT --- HOST DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- SITE DEFAULTS
Oct 25 15:30:13: vmx| DICT datastore.name = local
Oct 25 15:30:13: vmx| DICT datastore.localpath = C:\Virtual Machines\
Oct 25 15:30:13: vmx| DICT prefvmx.useRecommendedLockedMemSize = FALSE
Oct 25 15:30:13: vmx| DICT prefvmx.allVMMemoryLimit = 7797
Oct 25 15:30:13: vmx| DICT defaultVMPath = D:\vm
Oct 25 15:30:13: vmx| DICT priority.grabbed = normal
Oct 25 15:30:13: vmx| DICT priority.ungrabbed = normal
Oct 25 15:30:13: vmx| DICT --- GLOBAL SETTINGS
Oct 25 15:30:13: vmx| WSSCAN: reserved mem (in MB) min=32 max=16256 recommended=16256
Oct 25 15:30:13: vmx| hostMem=16384 maxAllowedAll=-1 maxAllowedVM=3600
Oct 25 15:30:13: vmx| totOverhead=16
Oct 25 15:30:13: vmx| WSSCAN: reserved mem (in MB) 7797, min=32 max=16256
Oct 25 15:30:13: vmx| WSSCAN: Overhead 604403 paged 18863 nonpaged 4096 maxFBSize
Oct 25 15:30:13: vmx| WSSCAN 1 2 1996032 3937465 1996032 4192944 50 0
Oct 25 15:30:13: vmx| LICENSE using: 'HKEY_LOCAL_MACHINE\SOFTWARE\VMware, Inc.\VMware Server\License.vs.1.0-00'
Oct 25 15:30:13: vmx| STATDECLGROUP stats Root "" null
Oct 25 15:30:13: vmx| Host CPUID features: version 0x10678 id1.edx 0xbfebfbff id1.ecx 0xce3bd id81.edx 0x20100000 id81.ecx 0x1
Oct 25 15:30:13: vmx| CPU.cpuFeatures = 0xb971ff37
Oct 25 15:30:13: vmx| CPUID after masking: version 0x10678 id1.edx 0xfebbbff id1.ecx 0xc8215 id81.edx 0x100800 id81.ecx 0x0 id88.ecx 0x0
Oct 25 15:30:13: vmx| CPU.cpuFeatures = 0x9871fe03
Oct 25 15:30:13: vmx| APIC: Local APIC at 0xfee00000
Oct 25 15:30:13: vmx| KHZEstimate 2333000
Oct 25 15:30:13: vmx| MHZEstimate 2333
Oct 25 15:30:13: vmx| NumVCPUs 2
Oct 25 15:30:13: vmx| UUID: location-UUID is 56 4d 29 0a 1b 43 6e 4b-a6 5d 6c b2 f0 82 b1 75
Oct 25 15:30:13: vmx| UUID: canonical path is d:\vm\drkwfs2\windows server 2003 standard edition.vmx
Oct 25 15:30:13: vmx| UUID: location-UUID is 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| MM: Using partialmap, 598016 pages AC 0 CE 1 TM 0 DOHU 0
Oct 25 15:30:13: vmx| UUID: canonical path is d:\vm\drkwfs2\windows server 2003 standard edition.vmx
Oct 25 15:30:13: vmx| UUID: location-UUID is 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:13: vmx| MM: using fileName d:\vm\drkwfs2\564d26a6-cec8-54fd-b611-f6fa5be33daa.vmem for paging
Oct 25 15:30:13: vmx| Msg_Reset:
Oct 25 15:30:13: vmx| [msg.monitorInit.vmm64.initHost.VTDisabled] This CPU is VT-capable, but VT is not enabled (check your BIOS settings).
Oct 25 15:30:13: vmx| [msg.monitorInit.vmm64.initHost.VTDisabled] This CPU is VT-capable, but VT is not enabled (check your BIOS settings).
Oct 25 15:30:13: vmx| ----------------------------------------
Oct 25 15:30:13: vmx| Opened paging file d:\vm\drkwfs2\564d26a6-cec8-54fd-b611-f6fa5be33daa.vmem
Oct 25 15:30:13: vmx| Mapped mainmem as pageable
Oct 25 15:30:13: vmx| MStat: Creating Stat vm.cpuusage
Oct 25 15:30:13: vmx| MStat: Creating Stat vm.ram
Oct 25 15:30:13: vmx| MStat: Creating Stat vm.uptime
Oct 25 15:30:13: vmx| DISK: OPEN scsi0:0 'd:\vm\drkwfs2\drkwfs2-c-21gb.vmdk' persistent R[(null)]
Oct 25 15:30:13: vmx| DISKLIB-DSCPTR: Opened [0]: "drkwfs2-c-21gb-flat.vmdk" 0 (0xa)
Oct 25 15:30:13: vmx| DISKLIB-LINK : Opened 'd:\vm\drkwfs2\drkwfs2-c-21gb.vmdk' (0xa): monolithicFlat, 44040192 sectors / 21504 Mb.
Oct 25 15:30:13: vmx| DISKLIB-LIB : Opened "d:\vm\drkwfs2\drkwfs2-c-21gb.vmdk" (flags 0xa).
Oct 25 15:30:13: vmx| DISK: OPEN 'd:\vm\drkwfs2\drkwfs2-c-21gb.vmdk' Geo (2741/255/63) BIOS Geo (2741/255/63) freeSpace=245848Mb
Oct 25 15:30:13: vmx| DISK: OPEN scsi0:1 'd:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk' persistent R[(null)]
Oct 25 15:30:13: vmx| DISKLIB-DSCPTR: Opened [0]: "drkwfs2-r-40gb-daten-flat.vmdk" 0 (0xa)
Oct 25 15:30:13: vmx| DISKLIB-LINK : Opened 'd:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk' (0xa): monolithicFlat, 83886080 sectors / 40960 Mb.
Oct 25 15:30:13: vmx| DISKLIB-LIB : Opened "d:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk" (flags 0xa).
Oct 25 15:30:13: vmx| DISK: OPEN 'd:\vm\drkwfs2\drkwfs2-r-40gb-daten.vmdk' Geo (5221/255/63) BIOS Geo (5221/255/63) freeSpace=245848Mb
Oct 25 15:30:13: vmx| DISK: OPEN scsi0:2 'd:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk' persistent R[(null)]
Oct 25 15:30:14: vmx| DISKLIB-DSCPTR: Opened [0]: "drkwfs2-s-datensicherung.vmdk" (0xa)
Oct 25 15:30:14: vmx| DISKLIB-LINK : Opened 'd:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk' (0xa): monolithicSparse, 73400320 sectors / 35840 Mb.
Oct 25 15:30:14: vmx| DISKLIB-LIB : Opened "d:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk" (flags 0xa).
Oct 25 15:30:14: vmx| DISK: OPEN 'd:\vm\drkwfs2\drkwfs2-s-datensicherung.vmdk' Geo (4568/255/63) BIOS Geo (4568/255/63) freeSpace=245848Mb
Oct 25 15:30:14: vmx| TimeTracker host to guest rate conversion 24511408494832 @ 2333000000Hz -> 24511408494832 @ 2333000000Hz
Oct 25 15:30:14: vmx| TimeTracker host to guest rate conversion ((x * 2147483648) >> 31) + 0
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:0.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:0.byteswritten
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:0 : capacity=44040192
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:0 : geometry=2741/255/63
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:1.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:1.byteswritten
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:1 : capacity=83886080
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:1 : geometry=5221/255/63
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:2.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat scsi0:2.byteswritten
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:2 : capacity=73400320
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:2 : geometry=4568/255/63
Oct 25 15:30:14: vmx| SCSI0: UNTAGGED commands will be converted to ORDER tags.
Oct 25 15:30:14: vmx| MStat: Creating Stat vm.heartbeat
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:30:14: vmx| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:30:14: vmx| TOOLS INSTALL initializing state to IDLE on power on.
Oct 25 15:30:14: vmx| VLANCE: send cluster threshold is 80, size = 2 recalcInterval is 2 ticks
Oct 25 15:30:14: vmx| MStat: Creating Stat ethernet0.bytesread
Oct 25 15:30:14: vmx| MStat: Creating Stat ethernet0.byteswritten
Oct 25 15:30:14: vmx| Ethernet0 MAC Address: 00:0c:29:e3:3d:aa
Oct 25 15:30:14: vmx| VMXNET: send cluster threshold is 80, size = 2 recalcInterval is 2 ticks, dontClusterSize is 128
Oct 25 15:30:14: vmx| E1000: checksum cycles/kB: C=1036 asm=678
Oct 25 15:30:14: vmx| VirtualProtect MapProtectMem(0x27b0000,0x1000) returns 0x1e7
Oct 25 15:30:14: vmx| Can't read-only monitor pages from 0x027B0000 to 0x027B1000
Oct 25 15:30:14: vmx| VirtualProtect MapProtectMem(0x27b2000,0x1000) returns 0x1e7
Oct 25 15:30:14: vmx| Can't read-only monitor pages from 0x027B2000 to 0x027B3000
Oct 25 15:30:14: vmx| VirtualProtect MapProtectMem(0x27b4000,0x0) returns 0x57
Oct 25 15:30:14: vmx| Can't read-only monitor pages from 0x027B4000 to 0x027B4000
Oct 25 15:30:14: vmx| VMX_PowerOn: ModuleTable_PowerOn = 1
Oct 25 15:30:14: vmx| VMX setting maximum IPC write buffers to 0 packets, 0 bytes
Oct 25 15:30:14: mks| Async MKS thread is alive
Oct 25 15:30:14: vcpu-0| APIC: version = 0x14, max LVT = 5
Oct 25 15:30:14: vcpu-0| APIC: LDR = 0x1000000, DFR = 0xffffffff
Oct 25 15:30:14: vmx| Create Memory BIO succeeded.
Oct 25 15:30:14: vmx| Create Memory BIO succeeded.
Oct 25 15:30:14: vmx| Accepted new connection at 1044 for thread servercontrol (0x933b18)
Oct 25 15:30:14: vmx| VUINewControlConnection: before slow ACL gunk (bug 63252).
Oct 25 15:30:14: vmx| ACL: Thread from (SYSTEM) gets full perms
Oct 25 15:30:14: vmx| VUINewControlConnection: after slow ACL gunk (bug 63252).
Oct 25 15:30:14: vmx| VUI: A new VMControl client connected.
Oct 25 15:30:14: vcpu-0| PShare: enabled 1, scanRate 32, checkRate 16
Oct 25 15:30:14: vcpu-0| guestCpuFeatures = 0x9871fe03
Oct 25 15:30:14: vcpu-0| Init modules.
Oct 25 15:30:14: vcpu-0| CPU reset: hard
Oct 25 15:30:14: vmx| VNET: Notification enabled for Ethernet0
Oct 25 15:30:14: vcpu-0| INTELRDMSR(0x8b) = 0x0000060b00000000
Oct 25 15:30:14: vcpu-0| INTELRDMSR(0x17) = 0x0018000088640720
Oct 25 15:30:14: vcpu-0| sz=3075424
Oct 25 15:30:14: vcpu-1| APIC: version = 0x14, max LVT = 5
Oct 25 15:30:14: vcpu-1| APIC: LDR = 0x4000000, DFR = 0xffffffff
Oct 25 15:30:14: vmx| IPC version negotiation version: VMX returning 2.1 to servercontrol
Oct 25 15:30:14: vmx| IPC vmcontrol-temp version: VMX returning 11.4 to servercontrol that tried 11.4
Oct 25 15:30:14: vcpu-1| guestCpuFeatures = 0x9871fe03
Oct 25 15:30:14: vcpu-1| Init modules.
Oct 25 15:30:14: vcpu-1| CPU reset: hard
Oct 25 15:30:14: vcpu-1| INTELRDMSR(0x8b) = 0x0000060b00000000
Oct 25 15:30:14: vcpu-1| INTELRDMSR(0x17) = 0x0018000088640720
Oct 25 15:30:14: vcpu-1| sz=3075424
Oct 25 15:30:14: vcpu-1| vmm32 initialized: Releasebuild-108231. cflags: 0x02000002.01803000.00000054
Oct 25 15:30:14: vcpu-0| vmm32 initialized: Releasebuild-108231. cflags: 0x02000002.01803000.00000054
Oct 25 15:30:14: vcpu-1| CPU reset: soft
Oct 25 15:30:14: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0x0) and 0xec000000(0x0)
Oct 25 15:30:14: mks| Ignoring update request in VGA_Expose (mode change pending).
Oct 25 15:30:14: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-0| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:14: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:14: vcpu-1| CPU reset: soft
Oct 25 15:30:15: mks| VNCENCODE 1 encoding mode change: (640x480x16depth,16bpp)
Oct 25 15:30:15: vcpu-0| DISKUTIL: scsi0:0 : geometry=2741/255/63
Oct 25 15:30:15: vcpu-0| DISKUTIL: scsi0:1 : geometry=5221/255/63
Oct 25 15:30:15: vcpu-0| DISKUTIL: scsi0:2 : geometry=4568/255/63
Oct 25 15:30:15: vcpu-1| CPU reset: soft
Oct 25 15:30:16: vcpu-0| BIOS-UUID is 56 4d 26 a6 ce c8 54 fd-b6 11 f6 fa 5b e3 3d aa
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:30:16: vcpu-0| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:30:16: mks| VNCENCODE 1 encoding mode change: (720x400x16depth,16bpp)
Oct 25 15:30:16: vcpu-0| Unknown int 10h func 0x2000
Oct 25 15:30:16: mks| VNCENCODE 1 encoding mode change: (640x480x16depth,16bpp)
Oct 25 15:30:22: mks| VNCENCODE 1 encoding mode change: (720x400x16depth,16bpp)
Oct 25 15:30:22: mks| VNCENCODE 1 encoding mode change: (640x480x16depth,16bpp)
Oct 25 15:30:22: vcpu-1| CPU reset: soft
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering IOSpace at 0x1060 (0x1060)
Oct 25 15:30:27: vcpu-0| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:27: vcpu-0| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:27: vcpu-0| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:0: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:0): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:1: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:1): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI-DEV0:2: Unsupported command READ BUFFER issued. --ok
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:2): INQUIRY request with EVDP set
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:0): MODE SENSE(6) for unsupported page 0x1c
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:1): MODE SENSE(6) for unsupported page 0x1c
Oct 25 15:30:28: vcpu-0| SCSI DEVICE (scsi0:2): MODE SENSE(6) for unsupported page 0x1c
Oct 25 15:30:42: vcpu-0| POLL device deleted
Oct 25 15:30:42: vcpu-1| VNET: Notification enabled for Ethernet0
Oct 25 15:30:42: mks| SOCKET 1 new update req with non-empty pending: logical error on server/client?
Oct 25 15:30:42: vcpu-1| SVGA: Unregistering IOSpace at 0x1060 (0x1060)
Oct 25 15:30:42: vcpu-1| SVGA: Unregistering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:42: vcpu-1| SVGA: Registering IOSpace at 0x1060 (0x0)
Oct 25 15:30:42: vcpu-1| SVGA: Registering MemSpace at 0xf0000000(0xf0000000) and 0xec000000(0xec000000)
Oct 25 15:30:42: vcpu-0| Guest OS = 0x5016
Oct 25 15:30:47: mks| SVGA: Using extended FIFO: Caps 0x00000007, Flags 0x00000000
Oct 25 15:30:47: mks| VNCENCODE 1 encoding mode change: (912x656x24depth,32bpp)
Oct 25 15:30:47: mks| MKS remote display status changed, enabling remoteoptimizations
Oct 25 15:30:49: mks| HostOps hideCursor before defineCursor!
Oct 25 15:30:50: mks| SOCKET 1 new update req with non-empty pending: logical error on server/client?
Oct 25 15:31:12: vcpu-1| MKS Backdoor get pointer: first time, notify tools are running
Oct 25 15:31:12: vcpu-1| GuestRpc: Channel 0, registration number 1, guest application toolbox.
Oct 25 15:31:12: vcpu-1| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:31:12: vcpu-1| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:31:12: vcpu-1| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:31:12: vcpu-1| Guest: toolbox: Version: build-108231
Oct 25 15:31:12: vcpu-1| TOOLS setting the tools version to '6535'
Oct 25 15:31:12: vcpu-1| TOOLS unified loop capability requested by 'toolbox'; now sending options via TCLO
Oct 25 15:31:41: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:32:11: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:32:42: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:33:12: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:33:33: vcpu-0| VMMouse: CMD Read ID
Oct 25 15:33:33: vcpu-0| MKS switching absolute mouse on
Oct 25 15:33:43: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:33:53: vcpu-1| TOOLS unified loop capability requested by 'toolbox-dnd'; now sending options via TCLO
Oct 25 15:33:53: vcpu-1| GuestRpc: Channel 1, registration number 1, guest application toolbox-dnd.
Oct 25 15:33:53: vcpu-1| DISKUTIL: scsi0:2 : toolsVersion = 6535
Oct 25 15:33:53: vcpu-1| DISKUTIL: scsi0:1 : toolsVersion = 6535
Oct 25 15:33:53: vcpu-1| DISKUTIL: scsi0:0 : toolsVersion = 6535
Oct 25 15:34:13: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:34:18: vmx| SCSI0:0: Command WRITE(10) took 1.671 seconds (ok)
Oct 25 15:34:18: vmx| SCSI0:0: Command WRITE(10) took 1.682 seconds (ok)
Oct 25 15:34:19: vmx| SCSI0:0: Command WRITE(10) took 1.527 seconds (ok)
Oct 25 15:34:44: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:34:54: vcpu-1| TOOLS unified loop capability requested by 'toolbox-dnd'; now sending options via TCLO
Oct 25 15:34:54: vcpu-1| GuestRpc: Channel 2, conflict: guest application toolbox-dnd tried to register, but it is still registered on channel 1
Oct 25 15:34:54: vcpu-1| GuestRpc: Channel 2 reinitialized.
Oct 25 15:34:54: vcpu-1| GuestRpc: Channel 2 reinitialized.
Oct 25 15:34:58: vmx| SCSI0:0: Command READ(10) took 1.512 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.001 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.702 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.702 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.333 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.156 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.155 seconds (ok)
Oct 25 15:34:58: vmx| SCSI0:0: Command WRITE(10) took 1.155 seconds (ok)
Oct 25 15:35:14: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:35:44: vmx| SCSI0:0: Command WRITE(10) took 1.514 seconds (ok)
Oct 25 15:35:45: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:36:15: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:36:26: vmx| SCSI0:0: Command WRITE(10) took 1.447 seconds (ok)
Oct 25 15:36:46: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:37:16: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:37:46: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:38:17: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:38:45: vmx| SCSI0:0: Command WRITE(10) took 1.718 seconds (ok)
Oct 25 15:38:45: vmx| SCSI0:0: Command WRITE(10) took 1.718 seconds (ok)
Oct 25 15:38:47: vcpu-0| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:39:18: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:39:35: vmx| SCSI0:0: Command WRITE(10) took 1.066 seconds (ok)
Oct 25 15:39:48: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:40:00: vmx| SCSI0:0: Command WRITE(10) took 1.281 seconds (ok)
Oct 25 15:40:11: vmx| SCSI0:0: Command WRITE(10) took 1.097 seconds (ok)
Oct 25 15:40:19: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:40:22: vmx| SCSI0:0: Command WRITE(10) took 1.675 seconds (ok)
Oct 25 15:40:49: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:40:58: vmx| SCSI0:0: Command WRITE(10) took 1.400 seconds (ok)
Oct 25 15:40:58: vmx| SCSI0:0: Command WRITE(10) took 1.441 seconds (ok)
Oct 25 15:41:20: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:41:42: vmx| SCSI0:0: Command WRITE(10) took 1.694 seconds (ok)
Oct 25 15:41:42: vmx| SCSI0:0: Command WRITE(10) took 1.670 seconds (ok)
Oct 25 15:41:50: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:41:52: vmx| SCSI0:0: Command WRITE(10) took 1.529 seconds (ok)
Oct 25 15:41:59: vmx| SCSI0:0: Command WRITE(10) took 1.296 seconds (ok)
Oct 25 15:42:01: vmx| SCSI0:0: Command WRITE(10) took 1.583 seconds (ok)
Oct 25 15:42:01: vmx| SCSI0:0: Command WRITE(10) took 1.819 seconds (ok)
Oct 25 15:42:03: vmx| SCSI0:0: Command WRITE(10) took 1.384 seconds (ok)
Oct 25 15:42:05: mks| MKS set guest selection request with invalid state 2
Oct 25 15:42:07: vcpu-0| Guest: toolbox: Got a logoff event.
Oct 25 15:42:07: vcpu-0| GuestRpc: Channel 1 reinitialized.
Oct 25 15:42:08: vcpu-0| Guest: toolbox: Got a logoff event.
Oct 25 15:42:13: vmx| SCSI0:0: Command READ(10) took 1.661 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.685 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.430 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.752 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.546 seconds (ok)
Oct 25 15:42:13: vmx| SCSI0:0: Command WRITE(10) took 1.438 seconds (ok)
Oct 25 15:42:21: vcpu-1| SIO: ignoring read access to non-existing config register 0xf1
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.673 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.378 seconds (ok)
Oct 25 15:42:24: vmx| SCSI0:0: Command WRITE(10) took 1.393 seconds (ok)
Oct 25 15:42:25: vcpu-0| Guest: toolbox: VMware Tools Service Shutdown.
Oct 25 15:42:25: vcpu-0| Guest: toolbox: VMware Tools Service Stopping.
Oct 25 15:42:25: vcpu-1| GuestRpc: Channel 0 reinitialized.
Oct 25 15:42:48: vmx| SCSI0:0: Command WRITE(10) took 1.590 seconds (ok)
Oct 25 15:42:50: vcpu-0| POLL device deleted
Oct 25 15:42:50: vcpu-1| VNET: Notification enabled for Ethernet0
Oct 25 15:42:50: vcpu-1| VMMouse: CMD Disable
Oct 25 15:42:50: vcpu-1| VMMouse: Disabling VMMouse mode
Oct 25 15:42:50: vcpu-1| MKS switching absolute mouse on
Oct 25 15:42:50: vcpu-0| PIIX4: PM Soft Off. Good-bye.
Oct 25 15:42:50: vmx| Stopping VCPU threads...
Oct 25 15:42:50: mks| Async MKS thread is exiting
Oct 25 15:42:50: vmx| DnD rpc already set to 0
Oct 25 15:42:50: vmx| TOOLS received request in VMX to set option 'enableDnD' -> '0'
Oct 25 15:42:50: vmx| SOCKET 1 close VNC socket on VNCBackendDestroy
Oct 25 15:42:50: vmx| MKS local poweroff
Oct 25 15:42:50: vmx| Lock before MKS lock created. Early poweroff?
Oct 25 15:42:50: vmx| Unlock before MKS lock created. Early poweroff?
Oct 25 15:42:50: vmx| scsi0:2: numIOs = 412 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
Oct 25 15:42:50: vmx| scsi0:1: numIOs = 6676 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
Oct 25 15:42:50: vmx| scsi0:0: numIOs = 27109 numMergedIOs = 0 numSplitIOs = 0 ( 0.0%)
Oct 25 15:42:50: vmx| AIOWIN32: asyncOps=31858 syncOps=76 bufSize=344Kb delayed=2744 fixed=311 sgOp=29625 sgOn=1
Oct 25 15:42:50: vmx| VMX idle exit
Oct 25 15:42:50: vmx| VMX IPC closed the connection with thread servercontrol (00933B18)
Oct 25 15:42:50: vmx| VMX: Remote VMControl client servercontrol disconnected.
Oct 25 15:42:50: vmx| Flushing VMX VMDB connections
Oct 25 15:42:50: vmx| IPC_exit: disconnecting all threads
Oct 25 15:42:50: vmx| VMX exit.
Oct 25 15:42:50: vmx| AIOMGR-S : stat o=9 r=15 w=0 i=0 br=29604 bw=0