VM zombie issue on ESXi 4.1

R

RiDDLeRThC

2[H]4U
2FA
Joined
Jun 13, 2002
Messages
3,963
So here is an odd issue that we have only seen happen 3-4 times within our network.

Every now and then we will get a server that we cannot log into via RDP. We can ping it but that's it.

Opening the console I can log into the server (usually its logged in and locked) but the start bar won't come up nor can I open My Computer or anything else.

Looking at the performance graphs show that all CPU and Disk activity has dropped off. The machine is just a zombie.

We thought this may had been related to the slow disks we have down here in our office but we just had our first case on our Production SAN and it has me a little worried.

Anyone else seen this before?
 
Very odd. Anything in the logs? (/var/log/vmkernel.log for 5, /var/log/vmkernel for 4/classic, /var/log/messages for i)

Might want to open an SR - they'll have you core the VM at that point, to look at what's going on inside of it.

What's the guest? Storage platform?
 
Guest is Windows 2003 Server STD Edition

Storage is iSCSI EMC CX4

Working to pull the logs now.
 
Here is a part of the log, looks like it was checking the vmware tools status when it locked up.... Not too sure.

Code: 
Jan  5 21:24:20 Hostd: [2012-01-05 21:24:20.296 4D740B90 verbose 'vm:/vmfs/volumes/4d7fb87b-2dfb95eb-6af6-002219b36776/KMVZWEB2/KMVZWEB2.vmx'] Tools guest daemon status changed to: 2
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.786 18B80B90 verbose 'SoapAdapter.HTTPService'] User agent is 'VMware-client/4.1.0'
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.786 18B80B90 verbose 'SoapAdapter.HTTPService'] HTTP Response: Client: NeedsContentLength: false UnderstandsChunking: true CanKeepAlive: true (PresetContentLength 129)
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.786 18B80B90 verbose 'SoapAdapter.HTTPService'] HTTP Response: Auto-completing at 129/129 bytes
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.786 18C02B90 verbose 'SoapAdapter.HTTPService'] User agent is 'VMware-client/4.1.0'
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.787 18C02B90 verbose 'SoapAdapter.HTTPService'] HTTP Response: Client: NeedsContentLength: false UnderstandsChunking: true CanKeepAlive: true (PresetContentLength -1)
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.788 18B80B90 info 'App' opID=task-internal-1370076-2d02833b] [VpxLRO] -- BEGIN task-internal-1370076 --  -- vpxapi.VpxaService.fetchQuickStats -- 52d9deed-6ca4-1048-e26a-7fd22f59eca3
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.788 18B80B90 verbose 'SoapAdapter.HTTPService' opID=task-internal-1370076-2d02833b] HTTP Response: Complete (processed 8827 bytes)
Jan  5 21:24:20 Vpxa: [2012-01-05 21:24:20.788 18B80B90 info 'App' opID=task-internal-1370076-2d02833b] [VpxLRO] -- FINISH task-internal-1370076 --  -- vpxapi.VpxaService.fetchQuickStats -- 52d9deed-6ca4-1048-e26a-7fd22f59eca3
Jan  5 21:24:26 Vpxa: [2012-01-05 21:24:26.298 18D47B90 verbose 'App'] [VpxaMoVm::CheckMoVm] did not find a VM with ID 13 in the vmList
Jan  5 21:24:26 Vpxa: [2012-01-05 21:24:26.298 18D47B90 verbose 'App'] [VpxaAlarm] VM with vmid = 13 not found
Jan  5 21:24:27 Vpxa: [2012-01-05 21:24:27.256 18ABEB90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
Jan  5 21:24:27 Vpxa: [2012-01-05 21:24:27.256 18ABEB90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 2727939 to 2727940 (at 2727939)
Jan  5 21:24:27 Vpxa: [2012-01-05 21:24:27.256 18ABEB90 verbose 'App'] [VpxaHalVmHostagent] 288: GuestInfo changed 'guest.disk'
Jan  5 21:24:27 Vpxa: [2012-01-05 21:24:27.257 18ABEB90 verbose 'App'] [VpxaHalServices] VmGuestDiskChange Event for vm(18) 288
Jan  5 21:24:27 Vpxa: [2012-01-05 21:24:27.257 18ABEB90 verbose 'App'] [VpxaInvtVmChangeListener] Guest DiskInfo Changed
Jan  5 21:24:30 Vpxa: [2012-01-05 21:24:30.200 18ABEB90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
Jan  5 21:24:30 Vpxa: [2012-01-05 21:24:30.200 18ABEB90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 2727940 to 2727941 (at 2727940)
Jan  5 21:24:30 Vpxa: [2012-01-05 21:24:30.200 18ABEB90 verbose 'App'] [VpxaHalVmHostagent] 128: GuestInfo changed 'guest.disk'
Jan  5 21:24:30 Vpxa: [2012-01-05 21:24:30.200 18ABEB90 verbose 'App'] [VpxaHalServices] VmGuestDiskChange Event for vm(9) 128
Jan  5 21:24:30 Vpxa: [2012-01-05 21:24:30.200 18ABEB90 verbose 'App'] [VpxaInvtVmChangeListener] Guest DiskInfo Changed
Jan  5 21:24:33 Vpxa: [2012-01-05 21:24:33.607 18B80B90 verbose 'VpxaHalCnxHostagent'] Received callback in WaitForUpdatesDone
Jan  5 21:24:33 Vpxa: [2012-01-05 21:24:33.607 18B80B90 verbose 'VpxaHalCnxHostagent'] [VpxaHalCnxHostagent::ProcessUpdate] Applying updates from 2727941 to 2727942 (at 2727941)
Jan  5 21:24:33 Vpxa: [2012-01-05 21:24:33.607 18B80B90 verbose 'App'] [VpxaHalVmHostagent] 352: GuestInfo changed 'guest.disk'
Jan  5 21:24:33 Vpxa: [2012-01-05 21:24:33.607 18B80B90 verbose 'App'] [VpxaHalServices] VmGuestDiskChange Event for vm(21) 352
Jan  5 21:24:33 Vpxa: [2012-01-05 21:24:33.607 18B80B90 verbose 'App'] [VpxaInvtVmChangeListener] Guest DiskInfo Changed
Jan  5 21:24:35 Hostd: [2012-01-05 21:24:35.297 4D7C2B90 verbose 'vm:/vmfs/volumes/4d7fb87b-2dfb95eb-6af6-002219b36776/KMVZWEB2/KMVZWEB2.vmx'] Tools are auto-upgrade capable
Jan  5 21:24:35 Hostd: [2012-01-05 21:24:35.297 4D7C2B90 verbose 'vm:/vmfs/volumes/4d7fb87b-2dfb95eb-6af6-002219b36776/KMVZWEB2/KMVZWEB2.vmx'] Tools guest daemon status changed to: 0

I might just open an SR. We have only seen this issue happen 3-4 times in the past year or so. This is the first time it has happen at our production site.
 
gack. That's all just vpxa and hostd being overly chatty bitches. 4.1i, I'm guessing? Worst. Logging. Ever.
 
I've seen this once or twice on one Server 2003 std host.
 
Had a crazy thing like this once happen with a Server 2008 R2 guest. It crashed multiple times over the course of a month. One time I got (un)lucky and was logged into it over RDP when it seized up. Turned out the rest of the guests had seized up too. We took it out of service and found the primary disk had some sort of problem (later discovered to be caused by running WD GreenPower drives at 7200RPM instead of their intended 5900RPM). I don't know if the original crashes were related to the disk failure or if that was just a coincidence. Either way, the problem went away when we migrated that guest to a new host.
 
I thought at first it was disk related, we have a lot of latency issues on our office san (100vm's on 20 7200rpm sata drives).

So usually I just thought it was disk related, rebooted the vm and went on my way.

This time it happend on a VM hosted within on our production san (40vm's on 60 15k FC drives).

Now I have to write an incident report for the production outage. Wish I would of worried about those other outages more now because I would have a lot more data to work with.
 
Yeah, definitely file an SR.

Do yourself a favor, set up a syslog server now rather than later, as 4.1i logs about 30 seconds worth most of the time (totally useless) to the ring buffer. In addition, I'll give you some syslog modifications when I get in tomorrow that will make it less suckage for logs, and make it so we can actually figure out what's going on.

What's the array?
 
Office is an AX4-5i with latest flare code

Production is a CX4-120 with latest flare code

We run a Spunk servers in both sites but no one in the office has much knowledge on it. I will see what it will take to get the ESXi host data into them.

I might just throw up a Kiwi syslog server for our esx hosts.
 
That works - the vMA can also do it, as can syslogng...

vMA is the easiest most of the time. but a bit limited at times.
 
I had a Server 2008 R2 Hyper-V HOST that had this issue, RDP and console access didn't work but could ping and all the VMs still worked, turns out the server was running completely out of memory due to a monitoring service I was trying out. Might you guest be running out of RAM? I couldn't log in even if I had a disconnected session already open, I had to keep RDP running for a few days with taskman up to watch what was happening.
 
-Dragon- said:
I had a Server 2008 R2 Hyper-V HOST that had this issue, RDP and console access didn't work but could ping and all the VMs still worked, turns out the server was running completely out of memory due to a monitoring service I was trying out. Might you guest be running out of RAM? I couldn't log in even if I had a disconnected session already open, I had to keep RDP running for a few days with taskman up to watch what was happening.
Click to expand...

Shouldn't be possible on the architecture for ESXi.
 
See it quite often here. We have hundreds of VM's. They have to be reset. No one has spent the effort to get to root cause, as it doesn't happen often enough for people to bother with an investigation.
 
Monkey God said:
See it quite often here. We have hundreds of VM's. They have to be reset. No one has spent the effort to get to root cause, as it doesn't happen often enough for people to bother with an investigation.
Click to expand...

Pretty much what was happening here too. Most the time it was happening on VM's that hadn't been used in a while so we just reset them and went on our way.

This time it was a production VM, now this VM doesnt get too much traffic but our monitoring hits it at least once a minute.
 
They took syslog out of the vSphere 5 vMA
Click to expand...

Yup...but they included a Syslog app on the vCenter software package which works extremely well, I might add.
 
That shouldn't be happening unless it's an app in the guest crashing them out. Really. I've got windows and linux VMs both with uptimes that'd be in the year+ mark, if it hadn't been for an EPO 2 weeks ago (CRACs failed).
 
Talked to VMware, he requested some additional logs.

In the mean time we just found another locked VM with the same symptoms. We are leaving the VM the way it is to see if VMware wants to look at it.

Maybe we will actually get to root cause.
 
on the host running that vm, do the following:

vm-support -x
This will list running world IDs.

then:

vm-support -X WID
Answer yes to all questions. This will core the VM, gather the core, and save it in a vm-support. Upload that sucker. You'll have to start it after that, the VM will go down hard.
 
No performance issues, no latency, no cpu issues, no memory.

He is blaming it on the guest operating system.

still haven't done the core capture but getting ready to do that now.
 
Tech wasn't intrested in the core dump but i did it anyways and will be uploading it to the VMware FTP site under my support request number.
 
Looks like the capture failed, blamed it on disk space but thats not the problem....

Code: 
VsiTraverseFlattenTree():Failed to write vsicache file: Operation not permitted
Snapping 21: 37  seconds left.VsiTraverseFlattenGetCalls():Couldn't write GET call at 11581866: Operation not permitted
VsiTraverseFlattenTree():Failed to write vsicache file: Operation not permitted
Snapping 22: 25  seconds left.VsiTraverseFlattenGetCalls():Couldn't write GET call at 11523246: Operation not permitted
VsiTraverseFlattenTree():Failed to write vsicache file: Operation not permitted
Snapping 23: 13  seconds left.VsiTraverseFlattenGetCalls():Couldn't write GET data at 16342679: Operation not permitted

VsiTraverseFlattenTree():Failed to write vsicache file: Operation not permitted
Snapping 24: 0  seconds left.VsiTraverseFlattenGetCalls():Couldn't write GET call at 11522338: Operation not permitted
VsiTraverseFlattenTree():Failed to write vsicache file: Operation not permitted

Done.  25 snapshots created.

Stopping vscsiStats.

Collecting VM samples (this may take several minutes) ...

Turning VM samples on...
Grabbing screenshot...

Creating core files (this may take several minutes) ...

Dumping unsync cores...
Dumping sync cores...
Dumping vmx core...

Done with core dumps

Turning VM samples off...
Sending NMI to guest...

Adding all files in '/vmfs/volumes/4d5ee431-cb5d9b4f-5b5a-001ec949b840/KMVRDB01' to tar

Preparing files: \
Could not copy /vmfs/volumes/4d5ee431-cb5d9b4f-5b5a-001ec949b840/KMVRDB01/vmware64-core0.gz to tar area (/var/tmp/vm-support-stpogesx03-2012-01-06--22.09.45953936) (err 1).
Have you run out of disk space?

/vmfs/volumes/4d5ee431-cb5d9b4f-5b5a-001ec949b840/KMVRDB01 #
 
odd, not out of space I assume?

edit: remember, it tars from /var/tmp. you can tell it to do it elsewhere iirc.
 
558gb free on that datastore.

Maybe it was talking about the esx host? if so thats on a 2gb usb drive.
 
lopoetve said:
how much is in /var/tmp?
Click to expand...

/vmfs/volumes/4d5ee431-cb5d9b4f-5b5a-001ec949b840/KMVRDB01 # du /var/tmp/ -h
4.0k /var/tmp
/vmfs/volumes/4d5ee431-cb5d9b4f-5b5a-001ec949b840/KMVRDB01 #


Not sure if thats what you are looking for...
 
try df, we'll have to figure out the uuid for /var/tmp (or whatever the actual mount is).

Easier would be to define the working directory for vm-support and have it build on a vmfs volume though.
 
try vm-support -X WID -w /vmfs/volumes/BLAH/YOURDIRHERE

that'll make it build in that directory instead, if the vm is still alive.
 
VM was powered off after it failed so looks like the chance was lost to do a core dump....
 
@lopoetve

Mentioned that you had some syslog tweaks... Do these tweaks apply to ESXi 5? I'm in the process of upgrading our office ESXi hosts to 5.0. I'm now using the vCenter syslog server along with CoreDump (hopefully I don't need that anytime soon!).
 
You must log in or register to reply here.
Back
Top