Win7 guest sporadically won't start

[ras]

I have a couple guests running Win7 (32-bit) on a Windows 10 (64-bit) host. Occasionally a guest won't start all the way up - it gets to the "Starting Windows" screen and logo, and then just hangs there. The host shows high CPU usage while this is happening (I think one core saturated). I've let it go for 20 minutes or more; it never makes any progress, and the CPU load stays high.

The solution has been to power off the VM and restart it. The Windows guest will come up with the "did not shut down properly" screen; rather than Repair, I tell it to just boot normally. (I've tried Repair in the past and it doesn't find anything wrong.) After this the system usually reboots normally, although on rare occasions it takes more than one cycle of powering off and restarting.

When I look at the logs I sometimes see several lines that say

Code: Select all

VMMDev: vmmDevHeartbeatFlatlinedTimer: Guest seems to be unresponsive. Last heartbeat received 4 seconds ago

but not always.

I'm on 5.1.8 r111374, but this has happened sporadically on many versions since 5.0.

Today it happened on two VMs. Both VMs experienced exactly the same symptoms, but the logs don't look very similar to me, so I'm posting both.

Any help appreciated - thanks!

[socratis]

Are you running those two VMs in parallel? I have a feeling that you do, because that would most certainly show the signs that you're describing. Here's what I gathered from a quick look of the logs.

Color code: Host, VM1, VM2.

00:00:02.313243 Host RAM: 7879MB (7.6GB) total, 3401MB (3.3GB) available
00:00:02.519040 Host RAM: 7879MB (7.6GB) total, 3520MB (3.4GB) available
00:00:02.721253   RamSize           <integer> = 0x0000000080000000 (2 147 483 648, 2 048 MB)
00:00:02.900388   RamSize           <integer> = 0x0000000080000000 (2 147 483 648, 2 048 MB)

You have at the time of the VM(s) launch about 3500MB available. You allocate 2048+2048=4096MB (plus vRAM, plus overhead). You are assigning memory to your guests that you do not have available. Either close some applications on the host, buy more RAM for the host, or reduce the amount of RAM assigned to the guests.

00:00:03.350279 CPUM: Logical host processors: 4 present, 4 max, 4 online, online mask: 000000000000000f
00:00:03.350281 CPUM: Physical host cores: 2
00:00:02.721246   NumCPUs           <integer> = 0x0000000000000002 (2)
00:00:02.900383   NumCPUs           <integer> = 0x0000000000000001 (1)

You have assigned all your CPUs to a single VM. Imagine if you launch two of them at the same time. The host is going to run low on resources, since VirtualBox cares about physical processors, not logical ones. See: CPU Cores versus threads.

So, my advice would be: lower RAM to 1024 or 1536 MB, max. Lower the vCPUs to 1. Try again. If you have a failure, please try with one VM only and post that log.

[ras]

I do normally run them in concurrently, but it also happens sometimes with only one. My normal procedure is to start one, let it fully boot, and then start the other. (There is enough RAM; each log happened to be taken when the other VM was running fine, so that may be why it looks like that. It's an 8 GB machine with 2 2-GB VMs. After overhead, etc. the host normally has 1.5 - 2 GB free.)

Neither VM runs CPU-intensive tasks. I don't normally have VM1 configured for 2 CPUs; I had a specific test I wanted to try with 2 CPUs the other day and forgot to put it back. In any case I've seen the problem when booting only one VM, using only 1 CPU, and nothing else running on the host.

It may be my imagination, but it feels like the problem is more likely to happen after Windows installs updates. I couldn't swear to that though.

I can grab the logs sometime when the problem happens with only 1 VM running. (Might take a while - it often goes days or weeks with no trouble.)

[BillG]

The situation is simply that you are over-committing the resources of your host. You have enough CPU and memory to run the host efficiently. Expecting it to run one (and sometimes two) vms is a big ask. I can well believe that, after Windows installs updates, things are very slow. A dual core physical machine with 4G sometimes grinds to a halt running updates on Windows 7.

[socratis]

@BillG, I couldn't agree with you more.

@ras, I have an 2006 PC with a Pentium D CPUs running Win7-32 (among other things, it's n-booting) and 4GB RAM (it only sees 3GB). With Windows updates, I've seen it get stuck at the "Getting ready... ##%. Do not turn off your computer.", or something similar. It might very well be what you're seeing as well.

But, if you see it again, leave it as long as you can (hour plus?) and post a log so that we can have a clearer picture. Unfortunately there is no monitoring of the guest during the boot phase. It's not that I think I'm going to see something different in the logs, it's more to satisfy our common curiosity...

[ras]

But, if you see it again, leave it as long as you can (hour plus?) and post a log so that we can have a clearer picture. Unfortunately there is no monitoring of the guest during the boot phase. It's not that I think I'm going to see something different in the logs, it's more to satisfy our common curiosity...

Will do. I really don't think it's caused by updating (it doesn't even get that far, and happens plenty of times w/o updates) but there's something going on that causes the guest to spin.

In the meantime, I should really shop for a new motherboard and more RAM

[ras]

Got some interesting info ...

One of the VMs hung up while booting again. I intended to let it run for an hour or so but forgot about it, and it ran for nearly 9 hours with the same symptoms - frozen at the Starting Windows screen, host running at ~25% CPU load even when nothing's going on. I powered down the VM and restarted it, and the VM booted normally in under a minute. There were no Windows Updates going on at the time.

Here's the interesting part - after the VM booted up, I browsed through the Windows event log. At the time of the failed boot, I have an Application Event 1530, User Profile Service:

Code: Select all

Windows detected your registry file is still in use by other applications or services. The file will be unloaded now. The applications or services that hold your registry file may not function properly afterwards.  

 DETAIL - 
 1 user registry handles leaked from \Registry\User\S-1-5-21-3826956073-1835861262-3267445798-1000:
Process 836 (\Device\HarddiskVolume2\Windows\System32\svchost.exe) has opened key \REGISTRY\USER\S-1-5-21-3826956073-1835861262-3267445798-1000\Printers\DevModePerUser

This event is immediately followed by Event 1532, "The User Profile Service has stopped." Looking back though the event log, it looks like these two events show up every time it fails to boot.

I've Googled these events but haven't found anything that looks like it directly applies. For whatever it's worth, there aren't any printers installed in this VM, and the registry key HKEY_CURRENT_USER\Printers\DevModePerUser exists, but is empty.

Just throwing this out there in case Events 1530 and/or 1532 ring a bell with anyone regarding a VirtualBox driver conflict or something.