VMWare Virtual Machines won't start after upgrade

Hello Everyone,

   I just upgraded from VMWare server 2 build 116503 to build 122956. After starting all of the necessary services and logging into the WebUI, I start my virtual machines. I have two of them on this machine, and both are Windows. The host machine runs CentOS. When starting either machine, I'm able to go into the console and watch them start to boot, but then they shut off before fully starting the guest OS. I'm not entirely sure what information would be helpful to troubleshoot this problem, so here's a sample of the output of my hostd log:

 

[2009-02-08 13:11:42.891 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: latestEvent, ha-eventmgr
[2009-02-08 13:11:42.891 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: disabledMethod, 32
[2009-02-08 13:11:42.892 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: capability, 32
[2009-02-08 13:11:42.892 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: summary, 32
[2009-02-08 13:11:43.043 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: config.changeVersion, 32
[2009-02-08 13:11:43.044 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: config.hardware.memoryMB, 32
[2009-02-08 13:11:43.044 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: summary, 32
[2009-02-08 13:11:43.470 'PropertyProvider' 1103911232 verbose] RecordOp ASSIGN: info, haTask-32-vim.EnvironmentBrowser.queryConfigOption-499903449
[2009-02-08 13:11:43.674 'PropertyProvider' 1102276928 verbose] RecordOp ASSIGN: info, haTask-32-vim.EnvironmentBrowser.queryConfigTarget-499903450
[2009-02-08 13:11:48.394 'TaskManager' 1107646784 info] Task Created : haTask-32-vim.VirtualMachine.powerOn-499903451
[2009-02-08 13:11:48.394 'PropertyProvider' 1107646784 verbose] RecordOp ADD: recentTask["haTask-32-vim.VirtualMachine.powerOn-499903451"], 32
[2009-02-08 13:11:48.394 'PropertyProvider' 1107646784 verbose] RecordOp ADD: recentTask["haTask-32-vim.VirtualMachine.powerOn-499903451"], ha-taskmgr
[2009-02-08 13:11:48.396 'ha-eventmgr' 1107646784 info] Event 50 : Red on host Leopard.xxx.com in ha-datacenter is starting
[2009-02-08 13:11:48.396 'PropertyProvider' 1107646784 verbose] RecordOp ASSIGN: latestEvent, ha-eventmgr
[2009-02-08 13:11:48.396 'vm:/backup/DS/Red/Red.vmx' 1107646784 info] State Transition (VM_STATE_OFF -> VM_STATE_POWERING_ON)
[2009-02-08 13:11:48.396 'PropertyProvider' 1107646784 verbose] RecordOp ASSIGN: disabledMethod, 32
[2009-02-08 13:11:48.396 'ha-license-manager' 1107646784 info] CheckLicenses: skipped on this platform
[2009-02-08 13:11:48.411 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: info, haTask-32-vim.VirtualMachine.powerOn-499903451
[2009-02-08 13:11:48.430 'Libs' 1101166912 info] connect to /var/run/vmware/root_0/1234120210257910_1933/testAutomation-fd: Connection refused
[2009-02-08 13:11:48.430 'Libs' 1089972544 info] VMHSVMCbPower: Setting state of VM /vm/#c8d244237d936657/ to powerOn with option soft
[2009-02-08 13:11:48.431 'Libs' 1089972544 info] VMHS: Exec()'ing /usr/lib/vmware/bin/vmware-vmx, /backup/DS/Red/Red.vmx
[2009-02-08 13:11:48.440 'App' 1089972544 error] IsOurChild: read IsOurChild failed /proc/1968/stat/3
[2009-02-08 13:11:48.544 'Libs' 1089972544 info] Mounting virtual machine paths on connection: /db/connection/#3f/, /backup/DS/Red/Red.vmx
[2009-02-08 13:11:48.620 'Libs' 1089972544 info] Mount VM completion for vm: /backup/DS/Red/Red.vmx
[2009-02-08 13:11:48.621 'Libs' 1089972544 info] Mount VM Complete: /backup/DS/Red/Red.vmx, Return code: OK
[2009-02-08 13:11:48.959 'Libs' 1101166912 info] Connected to /backup/DS/Red/Red.vmx:testAutomation-fd, remote end sent pid: 1969
[2009-02-08 13:11:49.032 'Libs' 1089972544 info] Disconnect check in progress: /backup/DS/Red/Red.vmx
[2009-02-08 13:11:49.032 'vm:/backup/DS/Red/Red.vmx' 1101748544 info] Question info: File "/home/vmware/Virtual Machines/en_windows_server_2008_datacenter_enterprise_standard_x64_dvd_X14-26714.iso" does not exist and therefore cannot be connected as a CD-ROM image.
Virtual device ide1:0 will start disconnected.
, Id: 10 : Type : 2, Default: 0, Number of options: 1
[2009-02-08 13:11:49.141 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: config.extraConfig["mainMem.useNamedFile"].value, 32
[2009-02-08 13:11:49.142 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: summary, 32
[2009-02-08 13:11:49.143 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: guest, 32
[2009-02-08 13:11:49.143 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: summary.guest, 32
[2009-02-08 13:11:49.144 'Libs' 1089972544 info] Disconnect check in progress: /backup/DS/Red/Red.vmx
[2009-02-08 13:11:49.194 'Libs' 1089972544 info] VMX status has been set for vm: /backup/DS/Red/Red.vmx
[2009-02-08 13:11:49.194 'Libs' 1089972544 info] Disconnect check in progress: /backup/DS/Red/Red.vmx
[2009-02-08 13:11:49.194 'Libs' 1089972544 info] Disconnect check in progress: /backup/DS/Red/Red.vmx
[2009-02-08 13:11:49.300 'ha-eventmgr' 1079429440 info] Event 51 : Red on  Leopard.xxx.com in ha-datacenter is powered on
[2009-02-08 13:11:49.300 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: latestEvent, ha-eventmgr
[2009-02-08 13:11:49.300 'vm:/backup/DS/Red/Red.vmx' 1079429440 info] State Transition (VM_STATE_POWERING_ON -> VM_STATE_ON)
[2009-02-08 13:11:49.300 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: summary.runtime.bootTime, 32
[2009-02-08 13:11:49.300 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: runtime.bootTime, 32
[2009-02-08 13:11:49.301 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: disabledMethod, 32
[2009-02-08 13:11:49.301 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: runtime.powerState, 32
[2009-02-08 13:11:49.301 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: summary.runtime.powerState, 32
[2009-02-08 13:11:49.301 'TaskManager' 1079429440 info] Task Completed : haTask-32-vim.VirtualMachine.powerOn-499903451
[2009-02-08 13:11:49.301 'PropertyProvider' 1079429440 verbose] RecordOp ASSIGN: info, haTask-32-vim.VirtualMachine.powerOn-499903451
[2009-02-08 13:11:49.304 'vm:/backup/DS/Red/Red.vmx' 47407055489216 info] Found USB devices with no controllers.
[2009-02-08 13:11:49.312 'vm:/backup/DS/Red/Red.vmx' 1101748544 warning] Failed to find activation record, event user unknown.
[2009-02-08 13:11:49.314 'ha-eventmgr' 1101748544 info] Event 52 : Message on Red on Leopard.xxx.com in ha-datacenter: File "/home/vmware/Virtual Machines/en_windows_server_2008_datacenter_enterprise_standard_x64_dvd_X14-26714.iso" does not exist and therefore cannot be connected as a CD-ROM image.
Virtual device ide1:0 will start disconnected.

[2009-02-08 13:11:49.314 'PropertyProvider' 1101748544 verbose] RecordOp ASSIGN: latestEvent, ha-eventmgr
[2009-02-08 13:11:49.315 'vm:/backup/DS/Red/Red.vmx' 1103911232 warning] Received a duplicate transition from foundry: 1
[2009-02-08 13:11:49.315 'vm:/backup/DS/Red/Red.vmx' 1107646784 warning] Received a duplicate transition from foundry: 1
[2009-02-08 13:11:49.470 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: config.hardware.device[3002].connectable.connected, 32
[2009-02-08 13:11:49.470 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: config.hotPlugMemoryLimit, 32
[2009-02-08 13:11:49.470 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: config.hotPlugMemoryIncrementSize, 32
[2009-02-08 13:11:49.471 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: summary, 32
[2009-02-08 13:11:49.471 'vm:/backup/DS/Red/Red.vmx' 1080400192 warning] Received a duplicate transition from foundry: 1
[2009-02-08 13:11:49.784 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: disabledMethod, 32
[2009-02-08 13:11:49.784 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: guest, 32
[2009-02-08 13:11:49.784 'PropertyProvider' 1086781760 verbose] RecordOp ASSIGN: summary.guest, 32
[2009-02-08 13:12:33.958 'Libs' 1089972544 info] Disconnect check in progress: /backup/DS/Red/Red.vmx
[2009-02-08 13:12:33.958 'vm:/backup/DS/Red/Red.vmx' 1101482304 info] Question info: VMware Server unrecoverable error: (Worker#3)
Unrecoverable memory allocation failure at /build/mts/release/bora-122956/bora/lib/file/fileIOPosix.c:1297
A log file is available in "/backup/DS/Red/vmware.log".  Please request support and include the contents of the log file.
To collect data to submit to VMware support, select Help > About and click "Collect Support Data". You can also run the "vm-support" script in the Workstation folder directly.
We will respond on the basis of your support entitlement.
, Id: 11 : Type : 3, Default: 0, Number of options: 1
[2009-02-08 13:12:33.958 'vm:/backup/DS/Red/Red.vmx' 1104177472 warning] Received a duplicate transition from foundry: 1
[2009-02-08 13:12:33.959 'vm:/backup/DS/Red/Red.vmx' 1101482304 warning] Failed to find activation record, event user unknown.
[2009-02-08 13:12:33.959 'Libs' 1089972544 info] Disconnect check in progress: /backup/DS/Red/Red.vmx
[2009-02-08 13:12:33.960 'ha-eventmgr' 1101482304 info] Event 53 : Message on Red on Leopard.xxx.com in ha-datacenter: VMware Server unrecoverable error: (Worker#3)
Unrecoverable memory allocation failure at /build/mts/release/bora-122956/bora/lib/file/fileIOPosix.c:1297
A log file is available in "/backup/DS/Red/vmware.log".  Please request support and include the contents of the log file.
To collect data to submit to VMware support, select Help > About and click "Collect Support Data". You can also run the "vm-support" script in the Workstation folder directly.
We will respond on the basis of your support entitlement.

[2009-02-08 13:12:33.960 'PropertyProvider' 1101482304 verbose] RecordOp ASSIGN: latestEvent, ha-eventmgr
[2009-02-08 13:12:33.960 'vm:/backup/DS/Red/Red.vmx' 47407055489216 warning] Received a duplicate transition from foundry: 1
[2009-02-08 13:12:35.180 'Libs' 1089972544 info] vmdbPipe_Streams Couldn't read: OVL_STATUS_EOF
[2009-02-08 13:12:35.181 'Libs' 1089972544 warning] VMHS: Connection to VM broken: cfg: /backup/DS/Red/Red.vmx; error: Pipe: Read failed; state: 3
[2009-02-08 13:12:35.181 'Libs' 1089972544 info] Unmounting the vm: /backup/DS/Red/Red.vmx
[2009-02-08 13:12:35.182 'Libs' 1089972544 info] Unmounting VM complete: /backup/DS/Red/Red.vmx
[2009-02-08 13:12:35.186 'Libs' 1089972544 info] Mount state values have changed: /backup/DS/Red/Red.vmx
[2009-02-08 13:12:35.187 'Libs' 1089972544 info] Reloading config state: /backup/DS/Red/Red.vmx
[2009-02-08 13:12:35.260 'Libs' 1089972544 info] VMHS: Transitioned vmx/execState/val to poweredOff
[2009-02-08 13:12:35.349 'Libs' 1089972544 info] SOCKET 7 (43)
[2009-02-08 13:12:35.349 'Libs' 1089972544 info] recv error 104: Connection reset by peer
[2009-02-08 13:12:35.693 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config.hardware.device[4000].connectable.connected, 32
[2009-02-08 13:12:35.694 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config.extraConfig["mainMem.useNamedFile"].value, 32
[2009-02-08 13:12:35.694 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: summary, 32
[2009-02-08 13:12:35.695 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: guest, 32
[2009-02-08 13:12:35.695 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: summary.guest, 32
[2009-02-08 13:12:35.696 'vm:/backup/DS/Red/Red.vmx' 1107380544 info] State Transition (VM_STATE_ON -> VM_STATE_OFF)
[2009-02-08 13:12:35.696 'PropertyProvider' 1107380544 verbose] RecordOp ASSIGN: disabledMethod, 32
[2009-02-08 13:12:35.696 'PropertyProvider' 1107380544 verbose] RecordOp ASSIGN: runtime.powerState, 32
[2009-02-08 13:12:35.697 'PropertyProvider' 1107380544 verbose] RecordOp ASSIGN: summary.runtime.powerState, 32
[2009-02-08 13:12:35.697 'vm:/backup/DS/Red/Red.vmx' 1107380544 warning] Failed to find activation record, event user unknown.
[2009-02-08 13:12:35.699 'ha-eventmgr' 1107380544 info] Event 54 : Red on  Leopard.xxx.com in ha-datacenter is powered off
[2009-02-08 13:12:35.699 'PropertyProvider' 1107380544 verbose] RecordOp ASSIGN: latestEvent, ha-eventmgr
[2009-02-08 13:12:35.699 'vm:/backup/DS/Red/Red.vmx' 1079429440 warning] Received a duplicate transition from foundry: 0
[2009-02-08 13:12:35.852 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config.hardware.device[3002].connectable.connected, 32
[2009-02-08 13:12:35.852 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config.hardware.device[4000].connectable.connected, 32
[2009-02-08 13:12:35.853 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config.hotPlugMemoryLimit, 32
[2009-02-08 13:12:35.853 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config.hotPlugMemoryIncrementSize, 32
[2009-02-08 13:12:35.853 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: summary, 32
[2009-02-08 13:12:36.167 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: config, 32
[2009-02-08 13:12:36.169 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: disabledMethod, 32
[2009-02-08 13:12:36.169 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: guest, 32
[2009-02-08 13:12:36.169 'PropertyProvider' 1100638528 verbose] RecordOp ASSIGN: summary.guest, 32

 

Any help would be greatly appreciated. I have some important services on these machines, so I'd like to get them back up and running as soon as I can. Thanks in advance!

 

Best Regards,
Martin Schultz