RedoLog Corrupt Error and "Failed to clone disk : Bad file descriptor (589833)." when trying to clone

[XavierH]

Hello Every one,

I have a big problem on a esxi 3.5 host; the only vm guest freezes during boot with error:

"The RedoLog for "SERVERNAME" has been detected to be corrupt. The virtual machine needs to be powered off. If this problem persists, you need to discard the RedoLog."

So I tried to follow this procedureto recover

but then the cloning fails with this message:

/vmfs/volumes/48e02344-a1437a55-d1ac-00237d5669f4/Exchange Server 1 # vmkfstools -i "Exchange Server 1-00000 .vmdk" "Exchange Server 1-000001-repair.vmdk"

Destination disk format: VMFS thick

Cloning disk 'Exchange Server 1-000001.vmdk'...

Clone: 36% done.Failed to clone disk : Bad file descriptor (589833).

Attached you'll find some screenshots of informations I collected about the CID chain and logs.

I hope someone can help.

Thanks in advance

[MauroBonder]

maybe helpful http://communities.vmware.com/message/1529153

if not helps, call with continuum http://communities.vmware.com/people/continuum

*If you found this information useful, please consider awarding points for "Correct" or "Helpful"*

[XavierH]

Hello thank you but I don't seem to find an answer there...

I'm wondering how to "discard the redolog".

I can also tell you that the snapshot manager doesn't find any snapshot but I'm sure there are some (and the VM was working fine, with the latest snapshot even if it wasn't visible in the snapshot manager).

I also join a screen shot of the datastore content.

This is a production server... any help is welcome.

Thanks

EDIT: I just bought a per incident support to have this solved (using a different username)

[continuum]

Hi

checked the log ...that does not look good.

You told me you called support ?

I guess support will tell you that the snapshot is lost ...

Hmm - what is the size of Exchange Server 1-000001-delta.vmdk ?

If you want me to look into it would be best to work on a copy - so that we do not touch any evidence for VMware support.

What I can tell you right away is that this VM will not run in the next few hours - so if you need to start plan B do it.

I need :

check with winscp - datastorebrowser does not make it

all vmdk files smaller than 10 kb

all vmware.logs

the vmsd

the vmx

a directory-listing including size and date - best done via putty

and all that zipped into one archive - attach to next post

Ulli

_________________________

VMX-parameters- WS FAQ -[ MOAcd|http://sanbarrow.com/moa241.html] - VMDK-Handbook

[continuum]

do not discard the snapshot yet - looks like you would lose about 2 Gb of data




_________________________

VMX-parameters- WS FAQ -[ MOAcd|http://sanbarrow.com/moa241.html] - VMDK-Handbook

[ionnick]

Hi, did anything ever come of this issue?  We had some kind of hang on our iSCSI SAN, and now we are seeing the same problem.  We're running ESXi v4.1.1.  I noticed that the latest .vmdk for the data disk (the system has two disks installed) was missing info such as geometry and adapterType.  I added them in based on the values in the previous snapshot, but it's still failing to load or clone.

I can go back to a previous snapshot, but this data disk held some data which will be very painful for me to recreate, and our backup is about two weeks old.  I'm really hoping I can salvage the data (it's an NTFS-formatted virtual disk we use as the data drive for an MS SQL server).

thanks!

[continuum]

> I added them in based on the values in the previous snapshot, but it's still failing to load or clone.

Bad idea - if you are not absolutely sure what to do dont mess with vmdks - it is to easy to damage the content.

Please attach vmware.logs and the small descriptor vmdks and the current vmx-file if you want our help

[ionnick]

Thanks very much for your offer to help!

MAIN VMDK

mssql-01-000004.vmdk

# Disk DescriptorFile

version=1

encoding="UTF-8"

CID=0413cb75

parentCID=c41de2ed

isNativeSnapshot="no"

createType="vmfsSparse"

parentFileNameHint="mssql-01-000002.vmdk"

# Extent description

RW 83886080 VMFSSPARSE "mssql-01-000004-delta.vmdk"

# The Disk Data Base

#DDB

ddb.longContentID = "0349e0bf2eca5c2613edf2f50413cb75"

mssql-01-000003.vmdk

# Disk DescriptorFile

version=1

encoding="UTF-8"

CID=32120274

parentCID=0267ff2f

isNativeSnapshot="no"

createType="vmfsSparse"

parentFileNameHint="mssql-01-000001.vmdk"

# Extent description

RW 83886080 VMFSSPARSE "mssql-01-000003-delta.vmdk"

# The Disk Data Base

#DDB

ddb.longContentID = "864dc0ba5cbf24e12ef7951332120274"

mssql-01-000002.vmdk

# Disk DescriptorFile

version=1

encoding="UTF-8"

CID=c41de2ed

parentCID=32120274

isNativeSnapshot="no"

createType="vmfsSparse"

parentFileNameHint="mssql-01-000003.vmdk"

# Extent description

RW 83886080 VMFSSPARSE "mssql-01-000002-delta.vmdk"

# The Disk Data Base

#DDB

ddb.longContentID = "c606ad30b465ed4e3123bfdec41de2ed"

mssql-01-000001.vmdk

# Disk DescriptorFile

version=1

encoding="UTF-8"

CID=0267ff2f

parentCID=1be4abf8

isNativeSnapshot="no"

createType="vmfsSparse"

parentFileNameHint="mssql-01.vmdk"

# Extent description

RW 83886080 VMFSSPARSE "mssql-01-000001-delta.vmdk"

# The Disk Data Base

#DDB

ddb.longContentID = "0fdcdfebfc46b3b51e42e88f0267ff2f"

DATA DISK VMDK

mssql-01_1-000002.vmdk

# Disk DescriptorFile

version=1

encoding="UTF-8"

CID=1bd50a75

parentCID=67117efc

isNativeSnapshot="no"

createType="vmfsSparse"

parentFileNameHint="mssql-01_1-000001.vmdk"

# Extent description

RW 335544320 VMFSSPARSE "mssql-01_1-000002-delta.vmdk"

# The Disk Data Base

#DDB

ddb.longContentID = "db960315306847be32cd327a1bd50a75"

mssql-01_1.vmdk

# Disk DescriptorFile

version=1

encoding="UTF-8"

CID=1bd50a75

parentCID=67117efc

isNativeSnapshot="no"

createType="vmfsSparse"

parentFileNameHint="mssql-01_1-000001.vmdk"

# Extent description

RW 335544320 VMFSSPARSE "mssql-01_1-000002-delta.vmdk"

# The Disk Data Base

#DDB

ddb.longContentID = "db960315306847be32cd327a1bd50a75"

VMX FILE mssql-01.vmx

.encoding = "UTF-8"

config.version = "8"

virtualHW.version = "7"

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"

vmci0.present = "TRUE"

nvram = "mssql-01.nvram"

virtualHW.productCompatibility = "hosted"

powerType.powerOff = "soft"

powerType.powerOn = "hard"

powerType.suspend = "hard"

powerType.reset = "soft"

displayName = "mssql-01"

extendedConfigFile = "mssql-01.vmxf"

floppy0.present = "TRUE"

numvcpus = "2"

scsi0.present = "TRUE"

scsi0.sharedBus = "none"

scsi0.virtualDev = "lsisas1068"

memsize = "4096"

scsi0:0.present = "TRUE"

scsi0:0.fileName = "mssql-01-000004.vmdk"

scsi0:0.deviceType = "scsi-hardDisk"

ide1:0.present = "TRUE"

ide1:0.clientDevice = "FALSE"

ide1:0.deviceType = "cdrom-image"

ide1:0.startConnected = "TRUE"

floppy0.startConnected = "FALSE"

floppy0.fileName = ""

floppy0.clientDevice = "TRUE"

ethernet0.present = "TRUE"

ethernet0.virtualDev = "e1000"

ethernet0.networkName = "VM Network"

ethernet0.addressType = "generated"

disk.EnableUUID = "TRUE"

guestOS = "windows7srv-64"

uuid.location = "56 4d 86 01 38 f3 f0 41-44 3b fb ac b8 8e e5 89"

uuid.bios = "56 4d 86 01 38 f3 f0 41-44 3b fb ac b8 8e e5 89"

vc.uuid = "52 60 1b ef 59 6e 98 95-84 7e 93 3a 8a 58 ef 53"

ide1:0.fileName = "/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/ISOs/en_sql_server_2008_r2_standard_x86_x64_ia64_dvd_521546.iso"

ethernet0.generatedAddress = "00:0c:29:8e:e5:89"

svga.vramSize = "8388608"

vmci0.id = "-1198594679"

cleanShutdown = "FALSE"

replay.supported = "FALSE"

sched.swap.derivedName = "/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01-1075a9fc.vswp"

replay.filename = ""

scsi0:0.redo = ""

pciBridge0.pciSlotNumber = "17"

pciBridge4.pciSlotNumber = "21"

pciBridge5.pciSlotNumber = "22"

pciBridge6.pciSlotNumber = "23"

pciBridge7.pciSlotNumber = "24"

scsi0.pciSlotNumber = "160"

ethernet0.pciSlotNumber = "32"

vmci0.pciSlotNumber = "33"

scsi0.sasWWID = "50 05 05 61 38 f3 f0 40"

vmotion.checkpointFBSize = "8388608"

ethernet0.generatedAddressOffset = "0"

tools.remindInstall = "FALSE"

hostCPUID.0 = "0000000668747541444d416369746e65"

hostCPUID.1 = "00100fa00006080000802009178bfbff"

hostCPUID.80000001 = "00100fa0100000a1000037ffefd3fbff"

guestCPUID.0 = "0000000668747541444d416369746e65"

guestCPUID.1 = "00100fa00000080080802001078bfbff"

guestCPUID.80000001 = "00100fa0100000a1000001e9ebd3fbff"

userCPUID.0 = "0000000668747541444d416369746e65"

userCPUID.1 = "00100fa00006080080802001078bfbff"

userCPUID.80000001 = "00100fa0100000a1000001e9ebd3fbff"

evcCompatibilityMode = "FALSE"

tools.syncTime = "FALSE"

unity.wasCapable = "FALSE"

sched.scsi0:1.shares = "normal"

sched.scsi0:1.throughputCap = "none"

scsi0:1.present = "TRUE"

scsi0:1.fileName = "mssql-01_1-000002.vmdk"

scsi0:1.deviceType = "scsi-hardDisk"

scsi0:1.redo = ""

ESXi message.log

(My message log also contained numerous messages about "HostCtl exception Unable to complete Sysinfo operation.  Please see the VMkernel log     file for more details", and several about "sfcb-vmware_base[6357]: LsaFindUserByName: 40008" but I trimmed them to save space.  Please let me know if they're relevant.

Nov 29 14:33:26 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:33:26 Hostd: Stack Trace:

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.644 3CAF4B90 info 'TaskManager' opID=F41442AF-00000265] Task Created : haTask-432-vim.VirtualMachine.powerOn-151444

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.645 3D3C2B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] Power on request recieved

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.645 3D3C2B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] Reconfigure ethernet backing if required

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.645 3D3C2B90 info 'ha-eventmgr' opID=F41442AF-00000265] Event 149314 : mssql-01 on host silicon.corp.iongrid.com in ha-datacenter is starting

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.645 3D3C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] State Transition (VM_STATE_OFF -> VM_STATE_POWERING_ON)

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.645 3D3C2B90 verbose 'ha-host' opID=F41442AF-00000265] ModeMgr::Begin: op = normal, current = normal, count = 4

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.656 3D3C2B90 info 'Libs' opID=F41442AF-00000265] Vix: [6638 foundryHandleProperties.c:3330]: Error VIX_E_NOT_FOUND in Vix_GetPropertiesImpl(): Unable to get bool property 107.

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.656 3D3C2B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] PowerOn request queued

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.657 3D3C2B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Retrieved current VM state from foundry 7, 6

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.657 3C8C2B90 info 'Libs'] /vm/#5838f4858efa0608/: VMHSVMCbPower: Setting state of VM to powerOn with option soft

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.658 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] VMHS: Exec()'ing /bin/vmx

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.658 3C8C2B90 info 'Libs'] VMHS: VMKernel_ForkExec(/bin/vmx, detached=1): rc=0 pid=9053725

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.710 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Established a connection.

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.710 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] VMHSOnHostExecVMXSuccess: vmPath=/vm/#5838f4858efa0608/

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.710 3C8C2B90 info 'Libs'] VmdbAddConnection: cnxPath=/db/connection/#235362/, cnxIx=28

Nov 29 14:33:33 Hostd: [2011-11-29 14:33:33.710 3C8C2B90 info 'Libs'] Vmdb_AddConnectionAsync_Secure: registered VERSION completion callback, cnx = /db/connection/#235362/

Nov 29 14:33:34 Hostd: [2011-11-29 14:33:34.017 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Mounting virtual machine paths on connection: /db/connection/#235362/.

Nov 29 14:33:34 Hostd: [2011-11-29 14:33:34.019 3C8C2B90 info 'Libs'] VmdbCnxControlCb: registered SUBSCRIBE completion callback, cnx = /db/connection/#235362/

Nov 29 14:33:34 Hostd: [2011-11-29 14:33:34.066 3CAB3B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] No Upgrade required

Nov 29 14:33:34 Hostd: [2011-11-29 14:33:34.078 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Mount VM completion for vm.

Nov 29 14:33:34 Hostd: [2011-11-29 14:33:34.080 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Mount VM Complete: OK

Nov 29 14:33:34 vmkernel: 62:13:52:46.652 cpu0:9053725)World: vm 9045534: 1534: Starting world vmm0:mssql-01 with flags 4008

Nov 29 14:33:34 vmkernel: 62:13:52:46.653 cpu0:9053725)Sched: vm 9045534: 6047: Adding world 'vmm0:mssql-01', group 'host/user', cpu: shares=-1 min=-1 minLimit=-1 max=-1, mem: shares=-1 min=-1 minLimit=-1 max=-1

Nov 29 14:33:34 vmkernel: 62:13:52:46.653 cpu0:9053725)Sched: vm 9045534: 6066: renamed group 2868890 to vm.9053725

Nov 29 14:33:34 vmkernel: 62:13:52:46.653 cpu0:9053725)Sched: vm 9045534: 6083: group 2868890 is located under group 4

Nov 29 14:33:34 vmkernel: 62:13:52:46.669 cpu1:9053725)Swap: vm 9045534: 2325: extending swap to 4194304 KB

Nov 29 14:33:34 vmkernel: 62:13:52:46.758 cpu2:9053725)World: vm 9045536: 1534: Starting world vmm1:mssql-01 with flags 4008

Nov 29 14:33:55 Hostd: [2011-11-29 14:33:55.653 3D540B90 verbose 'ResourcePool ha-root-pool'] Root pool capacity changed from 16901MHz/13097MB to 16901MHz/13096MB

Nov 29 14:34:26 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:34:26 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:34:26 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:34:26 Hostd: Stack Trace:

Nov 29 14:34:26 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:34:26 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:34:26 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:34:26 Hostd: Stack Trace:

Nov 29 14:34:29 vmkernel: 62:13:53:41.720 cpu3:9053725)Cow: 6404: Setting freeSector to 16929062.  bad root entries = 0, bad leaf entry = 0

Nov 29 14:34:32 Hostd: [2011-11-29 14:34:32.311 3C840B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root

Nov 29 14:34:39 vmkernel: 62:13:53:51.552 cpu2:9053725)WARNING: Cow: 6366: Bad leaf entry: leafEntry->sectorOffset[4] + sparseInfo->granularity (bytes = 676583864832) >= length (17683517440)

Nov 29 14:34:39 vmkernel: 62:13:53:51.552 cpu2:9053725)WARNING: Cow: 6366: Bad leaf entry: leafEntry->sectorOffset[7] + sparseInfo->granularity (bytes = 910575609856) >= length (17683517440)

Nov 29 14:34:39 vmkernel: 62:13:53:51.552 cpu2:9053725)WARNING: Cow: 6366: Bad leaf entry: leafEntry->sectorOffset[8] + sparseInfo->granularity (bytes = 561734754816) >= length (17683517440)

Nov 29 14:34:39 vmkernel: 62:13:53:51.552 cpu2:9053725)WARNING: Cow: 6366: Bad leaf entry: leafEntry->sectorOffset[9] + sparseInfo->granularity (bytes = 764576887296) >= length (17683517440)

Nov 29 14:34:55 Hostd: [2011-11-29 14:34:55.656 3D613B90 verbose 'ResourcePool ha-root-pool'] Root pool capacity changed from 16901MHz/13096MB to 16901MHz/13094MB

Nov 29 14:35:16 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.corp.iongrid.com' failed with errno 111, h_errno = 2

Nov 29 14:35:26 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:35:26 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:35:26 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:35:26 Hostd: Stack Trace:

Nov 29 14:35:26 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:35:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:35:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:35:27 Hostd: Stack Trace:

Nov 29 14:35:56 vmkernel: 62:13:55:08.964 cpu4:9053725)Cow: 6404: Setting freeSector to 34529357.  bad root entries = 0, bad leaf entry = 1583

Nov 29 14:35:56 vmkernel: 62:13:55:08.994 cpu5:9053725)VSCSI: 3482: handle 8227(vscsi0:0):Using sync mode due to sparse disks

Nov 29 14:35:56 vmkernel: 62:13:55:08.994 cpu5:9053725)VSCSI: 3523: handle 8227(vscsi0:0):Creating Virtual Device for world 9045534 (FSS handle 81596214)

Nov 29 14:35:56 vmkernel: 62:13:55:08.996 cpu5:9053725)VSCSI: 3482: handle 8228(vscsi0:1):Using sync mode due to sparse disks

Nov 29 14:35:56 vmkernel: 62:13:55:08.996 cpu5:9053725)VSCSI: 3523: handle 8228(vscsi0:1):Creating Virtual Device for world 9045534 (FSS handle 161222460)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.479 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] MKS ready for connections: true

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.490 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] No Upgrade required

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.491 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Disconnect check in progress.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.491 FFF0AB90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Question info: Insufficient video RAM. The maximum resolution of the virtual machine will be limited to 1672x1

Nov 29 14:35:56 254. To use the configured maximum resolution of 2560x1600, increase the amount of video RAM allocated to this virtual machine by setting svga.vramSize="16384000" in the virtual machine's configuration file.

Nov 29 14:35:56 Hostd: , Id: 16 : Type : 2, Default: 0, Number of options: 1

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.491 FFF0AB90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] HandleMessage: (vim.event.VmMessageWarningEvent) {

Nov 29 14:35:56 Hostd:    dynamicType = <unset>,

Nov 29 14:35:56 Hostd:    key = 1869833586,

Nov 29 14:35:56 Hostd:    chainId = 1701016181,

Nov 29 14:35:56 Hostd:    createdTime = "1970-01-01T00:00:00Z",

Nov 29 14:35:56 Hostd:    userName = "",

Nov 29 14:35:56 Hostd:    datacenter = (vim.event.DatacenterEventArgument) null,

Nov 29 14:35:56 Hostd:    computeResource = (vim.event.ComputeResourceEventArgument) null,

Nov 29 14:35:56 Hostd:    host = (vim.event.HostEventArgument) null,

Nov 29 14:35:56 Hostd:    vm = (vim.event.VmEventArgument) null,

Nov 29 14:35:56 Hostd:    ds = (vim.event.DatastoreEventArgument) null,

Nov 29 14:35:56 Hostd:    net = (vim.event.NetworkEventArgument) null,

Nov 29 14:35:56 Hostd:    dvs = (vim.event.DvsEventArgument) null,

Nov 29 14:35:56 Hostd:    fullFormattedMessage = <unset>,

Nov 29 14:35:56 Hostd:    changeTag = <unset>,

Nov 29 14:35:56 Hostd:    template = true,

Nov 29 14:35:56 Hostd:    message = "Insufficient video RAM. The maximum resolution of the virtual machine will be limited to 1672x1254. To use the configured maximum resolution of 2560x1600, increase the amount of video RAM allocated to this virtual

Nov 29 14:35:56  machine by setting svga.vramSize="16384000" in the virtual machine's configuration file.

Nov 29 14:35:56 Hostd: ",

Nov 29 14:35:56 Hostd:    messageInfo = (vim.vm.Message) [

Nov 29 14:35:56 Hostd:       (vim.vm.Message) {

Nov 29 14:35:56 Hostd:          dynamicType = <unset>,

Nov 29 14:35:56 Hostd:          id = "msg.svgaUI.badLimits",

Nov 29 14:35:56 Hostd:          argument = (anyType) [

Nov 29 14:35:56 Hostd:             "1672",

Nov 29 14:35:56 Hostd:             "1254",

Nov 29 14:35:56 Hostd:             "2560",

Nov 29 14:35:56 Hostd:             "1600",

Nov 29 14:35:56 Hostd:             "16384000"

Nov 29 14:35:56 Hostd:          ],

Nov 29 14:35:56 Hostd:          text = "Insufficient video RAM. The maximum resolution of the virtual machine will be limited to 1672x1254. To use the configured maximum resolution of 2560x1600, increase the amount of video RAM allocated to this virt

Nov 29 14:35:56 ual machine by setting svga.vramSize="16384000" in the virtual machine's configuration file.

Nov 29 14:35:56 Hostd: ",

Nov 29 14:35:56 Hostd:       }

Nov 29 14:35:56 Hostd:    ],

Nov 29 14:35:56 Hostd: }

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.492 3CAB3B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Retrieved current VM state from foundry 7, 6

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.492 FFF0AB90 verbose 'Vmsvc'] VixVM_AnswerMessage returned 0

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.492 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Disconnect check in progress.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.1)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.2)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.3)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.4)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.5)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.1)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.2)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.3)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.4)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.5)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 info 'ha-eventmgr'] Event 149315 : Warning message on mssql-01 on silicon.corp.iongrid.com in ha-datacenter: Insufficient video RAM. The maximum resolution of the virtual machine will be limite

Nov 29 14:35:56 d to 1672x1254. To use the configured maximum resolution of 2560x1600, increase the amount of video RAM allocated to this virtual machine by setting svga.vramSize="16384000" in the virtual machine's configuration file.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 FFF0AB90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Auto-answered question Insufficient video RAM. The maximum resolution of the virtual machine will be limite

Nov 29 14:35:56 d to 1672x1254. To use the configured maximum resolution of 2560x1600, increase the amount of video RAM allocated to this virtual machine by setting svga.vramSize="16384000" in the virtual machine's configuration file.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.493 3D340B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Retrieved current VM state from foundry 7, 6

Nov 29 14:35:56 vmkernel: 62:13:55:09.064 cpu3:9045534)VMMVMKCall: 255: Received INIT from world 9045534

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.543 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Hot Button update received

Nov 29 14:35:56 vmkernel: 62:13:55:09.068 cpu3:9045534)LSI: 1895: LSI: Initialized rings for scsi0 async=1, record=0 replay=0

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.555 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] sleepState value is 18446744073709551615

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.555 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Running status of app monitoring changed to : gray

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.555 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Version status of tools: ok

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.555 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] No Upgrade required

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.556 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Imgcust event values read from vmdb tree are state = 0, errorCode = 0, errorMsgSize = 0

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.556 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Running status of tools changed to: notRunning

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.598 3D695B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Hot Button update received

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.598 3D695B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] sleepState value is 0

Nov 29 14:35:56 vmkernel: 62:13:55:09.127 cpu2:9045536)VMMVMKCall: 255: Received INIT from world 9045536

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.711 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] VMX status has been set.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.712 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Disconnect check in progress.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.712 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Disconnect check in progress.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.712 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Power state request "done" without disconnect, checking for disconnect.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.712 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Disconnect check in progress.

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.713 3D3C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Connected to testAutomation-fd, remote end sent pid: 9053725

Nov 29 14:35:56 vmkernel: 62:13:55:09.263 cpu0:9045534)Net: 1421: connected mssql-01 eth0 to VM Network, portID 0x100001a

Nov 29 14:35:56 vmkernel: 62:13:55:09.263 cpu0:9045534)NetPort: 982: enabled port 0x100001a with mac 00:00:00:00:00:00

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.800 3D654B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Retrieved current VM state from foundry 4, 8

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.865 3D654B90 info 'ha-eventmgr' opID=F41442AF-00000265] Event 149316 : mssql-01 on  silicon.corp.iongrid.com in ha-datacenter is powered on

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.865 3D654B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] State Transition (VM_STATE_POWERING_ON -> VM_STATE_ON)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.865 3D613B90 verbose 'HostsvcPlugin'] Received state change for VM '432'

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.865 3D654B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] Actual VM overhead: 213102592 bytes

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.871 3D654B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx' opID=F41442AF-00000265] Time to gather config: 5 (msecs)

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.877 3D654B90 info 'TaskManager' opID=F41442AF-00000265] Task Completed : haTask-432-vim.VirtualMachine.powerOn-151444 Status success

Nov 29 14:35:56 Hostd: [2011-11-29 14:35:56.878 3D613B90 verbose 'Statssvc'] Adding vm 432 to poweredOnVms list

Nov 29 14:35:57 vmkernel: 62:13:55:10.002 cpu4:9045534)VSCSI: 2245: handle 8227(vscsi0:0):Reset request on FSS handle 81596214 (0 outstanding commands)

Nov 29 14:35:57 vmkernel: 62:13:55:10.002 cpu4:9045534)VSCSI: 2245: handle 8228(vscsi0:1):Reset request on FSS handle 161222460 (0 outstanding commands)

Nov 29 14:35:57 vmkernel: 62:13:55:10.002 cpu1:4175)VSCSI: 2519: handle 8227(vscsi0:0):Reset [Retries: 0/0]

Nov 29 14:35:57 vmkernel: 62:13:55:10.002 cpu1:4175)VSCSI: 2319: handle 8227(vscsi0:0):Completing reset (0 outstanding commands)

Nov 29 14:35:57 vmkernel: 62:13:55:10.002 cpu1:4175)VSCSI: 2519: handle 8228(vscsi0:1):Reset [Retries: 0/0]

Nov 29 14:35:57 vmkernel: 62:13:55:10.002 cpu1:4175)VSCSI: 2319: handle 8228(vscsi0:1):Completing reset (0 outstanding commands)

Nov 29 14:36:02 Hostd: [2011-11-29 14:36:02.405 FFF0AB90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root

Nov 29 14:36:13 vmkernel: 62:13:55:25.581 cpu2:9045534)VSCSI: 2245: handle 8227(vscsi0:0):Reset request on FSS handle 81596214 (0 outstanding commands)

Nov 29 14:36:13 vmkernel: 62:13:55:25.581 cpu2:9045534)VSCSI: 2245: handle 8228(vscsi0:1):Reset request on FSS handle 161222460 (0 outstanding commands)

Nov 29 14:36:13 vmkernel: 62:13:55:25.581 cpu1:4175)VSCSI: 2519: handle 8227(vscsi0:0):Reset [Retries: 0/0]

Nov 29 14:36:13 vmkernel: 62:13:55:25.582 cpu1:4175)VSCSI: 2319: handle 8227(vscsi0:0):Completing reset (0 outstanding commands)

Nov 29 14:36:13 vmkernel: 62:13:55:25.582 cpu1:4175)VSCSI: 2519: handle 8228(vscsi0:1):Reset [Retries: 0/0]

Nov 29 14:36:13 vmkernel: 62:13:55:25.582 cpu1:4175)VSCSI: 2319: handle 8228(vscsi0:1):Completing reset (0 outstanding commands)

Nov 29 14:36:19 vmkernel: 62:13:55:31.794 cpu4:9045534)WARNING: Cow: 5072: Real sector 43670143 exceeds free sector 34529357

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.671 3C8C2B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Disconnect check in progress.

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.671 3C881B90 info 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Question info: The redo log of mssql-01_1-000002.vmdk is corrupted. Power off the virtual machine. If the prob

Nov 29 14:36:19 lem still persists, discard the redo log.

Nov 29 14:36:19 Hostd: , Id: 17 : Type : 4, Default: 0, Number of options: 1

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.671 3C881B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] HandleMessage: (vim.event.VmMessageEvent) {

Nov 29 14:36:19 Hostd:    dynamicType = <unset>,

Nov 29 14:36:19 Hostd:    key = 808857697,

Nov 29 14:36:19 Hostd:    chainId = 1835216696,

Nov 29 14:36:19 Hostd:    createdTime = "1970-01-01T00:00:00Z",

Nov 29 14:36:19 Hostd:    userName = "",

Nov 29 14:36:19 Hostd:    datacenter = (vim.event.DatacenterEventArgument) null,

Nov 29 14:36:19 Hostd:    computeResource = (vim.event.ComputeResourceEventArgument) null,

Nov 29 14:36:19 Hostd:    host = (vim.event.HostEventArgument) null,

Nov 29 14:36:19 Hostd:    vm = (vim.event.VmEventArgument) null,

Nov 29 14:36:19 Hostd:    ds = (vim.event.DatastoreEventArgument) null,

Nov 29 14:36:19 Hostd:    net = (vim.event.NetworkEventArgument) null,

Nov 29 14:36:19 Hostd:    dvs = (vim.event.DvsEventArgument) null,

Nov 29 14:36:19 Hostd:    fullFormattedMessage = <unset>,

Nov 29 14:36:19 Hostd:    changeTag = <unset>,

Nov 29 14:36:19 Hostd:    template = true,

Nov 29 14:36:19 Hostd:    message = "The redo log of mssql-01_1-000002.vmdk is corrupted. Power off the virtual machine. If the problem still persists, discard the redo log.

Nov 29 14:36:19 Hostd: ",

Nov 29 14:36:19 Hostd:    messageInfo = (vim.vm.Message) [

Nov 29 14:36:19 Hostd:       (vim.vm.Message) {

Nov 29 14:36:19 Hostd:          dynamicType = <unset>,

Nov 29 14:36:19 Hostd:          id = "msg.hbacommon.corruptredo",

Nov 29 14:36:19 Hostd:          argument = (anyType) [

Nov 29 14:36:19 Hostd:             "mssql-01_1-000002.vmdk"

Nov 29 14:36:19 Hostd:          ],

Nov 29 14:36:19 Hostd:          text = "The redo log of mssql-01_1-000002.vmdk is corrupted. Power off the virtual machine. If the problem still persists, discard the redo log.

Nov 29 14:36:19 Hostd: ",

Nov 29 14:36:19 Hostd:       }

Nov 29 14:36:19 Hostd:    ],

Nov 29 14:36:19 Hostd: }

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.672 3C881B90 warning 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Failed to find activation record, event user unknown.

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.672 3C881B90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.1)

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.672 3C881B90 warning 'Locale'] FormatField: Invalid (vim.vm.Message.1)

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.672 3C881B90 info 'ha-eventmgr'] Event 149317 : Message on mssql-01 on silicon.corp.iongrid.com in ha-datacenter: The redo log of mssql-01_1-000002.vmdk is corrupted. Power off the virtual machine. If the p

Nov 29 14:36:19 roblem still persists, discard the redo log.

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.672 3C840B90 verbose 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Retrieved current VM state from foundry 4, 8

Nov 29 14:36:19 Hostd: [2011-11-29 14:36:19.672 3C840B90 warning 'vm:/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/mssql-01.vmx'] Received a duplicate transition from foundry: 8, 1

Nov 29 14:36:27 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:36:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:36:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:36:27 Hostd: Stack Trace:

Nov 29 14:36:27 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:36:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:36:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:36:27 Hostd: Stack Trace:

Nov 29 14:36:55 Hostd: [2011-11-29 14:36:55.657 3D3C2B90 verbose 'ResourcePool ha-root-pool'] Root pool capacity changed from 16901MHz/13094MB to 16901MHz/13095MB

Nov 29 14:37:27 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:37:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:37:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:37:27 Hostd: Stack Trace:

Nov 29 14:37:27 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:37:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:37:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:37:27 Hostd: Stack Trace:

Nov 29 14:37:32 Hostd: [2011-11-29 14:37:32.489 3D3C2B90 verbose 'Cimsvc'] Ticket issued for CIMOM version 1.0, user root

Nov 29 14:37:49 Hostd: [2011-11-29 14:37:49.841 3D381B90 verbose 'DvsManager'] PersistAllDvsInfo called

Nov 29 14:37:55 Hostd: [2011-11-29 14:37:55.659 3D6D6B90 verbose 'ResourcePool ha-root-pool'] Root pool capacity changed from 16901MHz/13095MB to 16901MHz/13094MB

Nov 29 14:38:22 Hostd: [2011-11-29 14:38:22.669 3D3C2B90 verbose 'Vmsvc'] RefreshVms updated overhead for 2 VMs

Nov 29 14:38:27 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:38:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:38:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:38:27 Hostd: Stack Trace:

Nov 29 14:38:27 netlogond[4919]: [LWNetSrvGetDCTimeFromDC() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/server/api/dcinfo.c:537] Failed ldap bind on ad-02.corp.iongrid.com error=40286

Nov 29 14:38:27 netlogond[4919]: [LWNetDnsQueryWithBuffer() /build/mts/release/bora-234910/likewise/esxi-esxi/src/linux/netlogon/utils/lwnet-dns.c:1185] DNS lookup for '_ldap._tcp.dc._msdcs.CORP.IONGRID.COM' failed with errno 111, h_errno = 2

Nov 29 14:38:27 Hostd: DJGetComputerDN: 0x80047: 0x251E - Unknown error

Nov 29 14:38:27 Hostd: Stack Trace:

[continuum]

this file is definetely bad:

mssql-01_1.vmdk

please zip all vmware.logs you have - then I maybe able to reconstruct it
I also need a filelisting

please next time attach the files - dont post them - thanks

[ionnick]

Thanks again.  Sorry about posting something so verbose before, I thought it would be helpful for others who later search for this same solution.  Anyway, the few logs that ESXi created are attached.

I'm curious how you knew that snapshot 000001 is bad, by the way.  That happened to be on a different logical volume on the same SAN (see the file-listing.txt), though it appears unmodified since July.

Anyway, the logs are zipped and attached.  Thanks so much for your help!

[continuum]

Hi
I just downloaded your archive - but it does not have the data I need.

Now that I have the filelisting I can give you a list of files I need:
all of them are in the directory
/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01/

mssql-01-000001.vmdk
mssql-01-000002.vmdk
mssql-01-000003.vmdk
mssql-01-000004.vmdk
mssql-01.vmdk
mssql-01.vmsd
mssql-01.vmx
mssql-01_1-000001.vmdk
mssql-01_1-000002.vmdk
vmware-19.log
vmware-20.log
vmware-21.log
vmware-22.log
vmware-23.log
vmware-24.log
vmware.log
mssql-01_1.vmdk

looks like someone manually edited
mssql-01_1.vmdk

[ionnick]

My apologies.  The files you've requested are in this archive.  Thanks again!

[continuum]

Sorry  - I was on the wrong track because you used the wrong filenames in the first post with the vmdks ...
Now what is the size of this file please ?
mssql-01_1-000002-delta.vmdk

[ionnick]

My apologies again.

/vmfs/volumes/4e014032-b3977cce-7a0c-001b21a32266/mssql-01 # ls -al mssql-01_1-000002-delta.vmdk

-rw-------    1 root     root        17683517440 Nov 27 09:04 mssql-01_1-000002-delta.vmdk

[continuum]

17Gb ?
not good - can you copy that file with datastorebrowser ?

[ionnick]

I can "Inflate" it (I think it was a thinly-provisioned disk, though I don't remember).  The datastore browser claims the file should be "167,772,200.00 KB".

Please let me know if you want me to inflate it, or to copy/paste it to a new location.

[continuum]

no - dont inflate it - I just want you to copy this file to a new directory.

[ionnick]

Ok.  It's claiming the copy will take approximately 15 hours.  I'll let you know if anything eventful happens before then.

[ionnick]

The copy failed.

Error caused by file /vmfs/volumes/.../test/mssql-01_1-000002.vmdk.

[continuum]

I just wanted to post that I expect failure during the process.

Ok - can you take the whole server offline and boot it into a Linux LiveCD ?
If that is no option than I am afraid you have to discard that file which means that you will lose a significant amount of data.