Investigating VM Configuration Changes

Tracking resource configuration is a common struggle for an enterprise level environment. Even SMBs can have trouble keeping track of how their memory is provisioned and when it changes. What’s worse, VMware’s vSphere Client doesn’t provide any insight as to what changes when someone edits the virtual machine settings. An event named"Reconfigure virtual machine" hits the task log but this isn’t a lot of information. If you open Edit Settings and click OK vCenter registers this event even if you didn’t change anything. This does, however give you a timestamp (and username) for our investigation. Someone opened Edit Settings, but what did they edit?

The Events log doesn’t tell you much either. It may return “Resource allocation changed” but you will also see those events if you vMotion a virtual machine or DRS moves it. This still isn’t a smoking gun to say “The memory was changed to X GB at this time”.

VMware.log to the rescue

Thankfully there is a way to get a timestamp that tells you exactly when a VM had its memory changed and how much it was set to… time to SSH into a host to find vmware.log

VMware.log is a file located in the datastore that stores your machine’s vmx file. It’s a running log of everything happening to the machine. By default VMware keeps 10 rotations so you could see up to 10 files. If you want to change the location, maximum size, or rotations to keep check out KB 8182749.

There are many paths we can take at this point. We could browse the datastore and download the vmware.log file or files with the timestamp we want to investigate. My personal preference is to turn to the command line to investigate. I’ll run through each of the commands individually.

Open putty or your SSH client of choice and connect to the host. Remember to start the SSH service on the host if you haven’t already!

Browse to the datastore. If you aren’t familiar with navigating a non-Windows file system, use ls to list the contents of your current directory, the same as dir in Windows.

We are trying to get to the datastore that your virtual machine is sitting on. to get there you can cd into directory like a windows command prompt.

~# cd /vmfs/volumes/DATASTORE/VIRTUALMACHINE/

This would take you into the directory for the vm VIRTUALMACHINE in the DATASTORE datastore. ESXi’s file system is case sensitive so you have to be careful when typing. It does support tab completion. If you start typing a command or directory name the TAB key will autocomplete the word for you. It’s a handy trick.

Now we’re in the offending virtual machine’s directory. At this point, type ls -l to return the contents of the directory with a timestamp. Remember, you’re looking for one of possibly ten vmware.log files.

Let’s say you have decided vmware-3.log has a timestamp that would correspond with one of the earlier identified reconfigure log entries. use a grep to search the log file for the term memsize. If you want to see about a number of vCPU the term is numVCP. Lastly if you suspect someone of growing a hard drive the search term is ‘Growing disk’

# grep memsize vmware-3.log

As you can see there’s an entry that says ConfigDB: Setting memsize = “4096”. Whomever edited the virtual machine at this time was the culprit!

Summary

To sum it all up:

1. Check the virtual machine’s Tasks log to get a timestamp for the change (search for reconfigure if you have a very busy task list!)
2. SSH into the host and navigate to the virtual machine’s folder
3. Identify the vmware.log file that should have the resource change (ls -l to list the folder details)
4. run grep memsize vmware-X.log where X = the appropriate log file

Reddit user /u/ajz (@ajz on twitter) wrote some commands to investigate these changes in PowerCLI

Connect-VIServer "vcenterserver"
$vm = "vmname"
$changeevents = Get-VM $vm | Get-VIEvent | Where { $_.FullFormattedMessage -like "Reconfigured*"}
$changeevents[0].UserName
$changeevents[0].ConfigSpec

Thanks again to AJZ.

When I worked with the commands they worked perfectly but they give a lot of information and I needed to experiment to figure out exactly how they work. The [0] refers to the most recent event that matches the filter. One of my test VMs was edited multiple times so I wanted to return all the changes. Here is my modification:

Connect-VIServer "vcenterserver"
$vm = "vmname"
$changeevents = Get-VM $vm | Get-VIEvent | Where { $_.FullFormattedMessage -like "Reconfigured*"}
$changeevents[0,1,2].UserName
$changeevents[0,1,2].ConfigSpec |Select-Object NumCPUs, MemoryMB, DeviceChange

This returns the usernames of the three most recent reconfiguration events on one line and then returns a table of the changes for each of those events:

Notice in row two it returns {VMware.Vim.VirtualDeviceConfigSpec}. This change was me adding 10 GB to the hard drive. I’m not sure how to pull that information more specifically, however I now know to look for that command in the logs if I really need to know exactly how much they added. It’s fantastic to pull memory and cpus. if the lines showed up blank I would remove the filters and look at all the configuration items to see if the user changed something a little more obscure.