Powering down Linux guest taking a long time

[MatsBoekelund]

Hi fth0. (and anyone else reading, of course;-)
An update on the issue with slow powering down:
1. A colleague reported he no longer sees the issue after IT reinstalled Win10 on his laptop. Personally I suspect it will come back with time, I have had this not happen to me until after several reboots of the VM.
2. Earlier in the week IT here helped me temporarily turn off the Cortex XDR virus scanner, that did not prevent my VM from taking about 2:40 to power down.
3. Just now, installing the GAs on a VM, I noticed it also took a very long time to "Insert the GuestAdditions CD-image", the VBox.log seems to suggest that it's the same issue. In addition to the standard logfiles, the archive I just attached also contains selectorwindow.log from the session where I booted the VM, inserted the GA CD-image, installed the GAs and shut it down again. (that file lives in <myWindowsHomeDir>\.VirtualBox\ )
4. Not sure why I hadn't done so before but searching for "PDMR3PowerOff: Driver 'VD'/0 on LUN#0 of device" on the web and found a couple of discussions where similar issues seem to have been encountered, these seem fairly old though:
viewtopic.php?f=40&t=81826
and
https://forums.freebsd.org/threads/virt ... ngs.59316/

I can still not tell if the issue of delayed powerdown is "the same issue" as my VMs running the user software sluggishly or not, I'm still trying to experiment to find out. I have seen sluggish running on a VM that did not show the slow powerdown issue and watching the TaskManager, nothing extraordinary seems to show up (like the excessive disk reading while powering down) when using the VM, also ksysguard inside the CentOS VM looks normal. At this point I believe these to be separate issues.

On a side-note, a third issue, an error message related to compilation of X-stuff when installing the GAs, seems to have gone away with VBox 6.1.14. I had not paid much attention to that issue since my GAs in 6.1.12 seemed operational and I could find nothing to point to any of the issues being related to graphics. (I'll make a separate post about the GA install error once I've had a chance to re-try in 6.1.12)

thx + BR / Mats

[fth0]

The VBoxHardening.log file shows an unknown adversary that has modified Windows system files. Whatever software that is, it will also influence functionalities of the VirtualBox Manager. I cannot say if it has anything to do with your problems, though.

Regarding your web search, you're ignoring the fact that the delays in those cases are shorter than 2 seconds.

To investigate more about the disk accesses inside the Windows host OS, you could use Sysinternals DiskMon or Process Monitor.

[MatsBoekelund]

Hi fth0, thanks.
Can you point to a reference in the hardening-log that could allow me (or more likely IT actually) to figure out what piece of software may be causing problems?
I looked at one of the files where "lacks WinVerifyTrust" was shown, bcryptprimitives.dll. Right-click -> Properties on that file seemed to suggest that it's the original file and it belongs to the Win10 O/S.
Is it such messages you're referring to or am I missing the obvious?
(I see many entries of "lacks WinVerifyTrust")

On a side note, something found today suggests more strongly that my other issue, sluggish performance inside the Linux Guest when running a particular piece of software, is indeed a different issue to the problem of delayed powerdown. That other issue appears to be related to the Guest setup or possibly something to do with the network or the Guest's interaction with it. A reliable workaround for that issue is to manually enter the hostname in /etc/hosts on the Guest. This could explain why other operations inside the Guest did not seem to run slowly. Having or not having the hostname in /etc/hosts does not change the behavior of the powerdown.

I'll check with our IT for possible ways of checking Windows logs or what they can use to look more closely at what's happening with the disk access.
thx:-)

[fth0]

Can you point to a reference in the hardening-log that could allow me (or more likely IT actually) to figure out what piece of software may be causing problems?

18d8.24bc: supR3HardenedWinFindAdversaries: 0x0

As I indicated, VirtualBox doesn't know the adversary.

18d8.24bc: apphelp.dll: Differences in section #2 (.rdata) between file and memory:
18d8.24bc:   00007ffcf2ccfe98 / 0x004fe98: f0 != e0

Here you can see that some software has patched apphelp.dll in memory. This doesn't have to be an adversary, though. For example, it could also be an accessibility helper program that tries to invade the memory of all other processes. But adversaries are more prevalent.

[hamishmb]

I may have had something similar on a Linux host with Linux guests - they sometimes wait for several seconds in the "Powered Off" state before fully stopping, instead of being instant as before. However, I'm currently debugging other problems including a potentially-display-driver-related kernel memory leak, and quite a bad one at that, so it might not be VBox's fault in my case.

[MatsBoekelund]

Hi All, sorry I have not been able to revisit this until recently.

About three weeks ago I had my Windows 10 (host) updated to 20H2, encouraged by the fact that a colleague had no longer seen the same issue after getting a new laptop set up with a newer Win 10. No success, still had the same issue.

Last Monday (Feb 1) I updated my VBox Client to 6.1.18 but ran into some issues with that on CentOS 6.2 guests so I downgraded again. My powerdown issue was still present all of last Monday. Last Wednesday I was using a VM and to my great surprise, the powerdown issue was gone. At this point it appears to stay away, I can power the guests down within seconds. Up to and including last Monday it was solidly there, irrespective of which VM I happened to use at the time.

The two things I had done on the host between the issue still being present and it being gone are:
1. The upgrading / downgrading of the VBox client version
and
2. Setting the default Audio device to be the computer speakers rather than the Jabra headset.

As for the VBox client version, since originally posting this I have gone up and down in versions that a few times with no change in behavior. (currently on 6.1.16)
The Audio setting has been toggled between the speakers and the headset a few times too but the issue has not come back.

It may be coincidence but looking at these lines from VBox.log:
00:41:56.511391 ************** End of Guest state at power off ***************
00:45:17.889261 PDMR3PowerOff: Driver 'VD'/0 on LUN#0 of device 'piix3ide'/0 took 201 377 717 260 ns to power off
00:45:17.922681 Audio: Disabling input for driver 'DSoundAudio'

just before it starts doing stuff with Audio, the line in the log file describing it took a long time to power something off shows up. (I've attached an archive with two logs from the same guest, one with the issue present and one from last week with the issue gone)

Btw, fth0, the complaints you found in the hardening log are also gone:-)

At this point I know of only one more laptop (host) where this issue is present and week after next some experiments are planned on that to see if this issue can be understood. As long as the cause is unknown it may come back...

Thanks for all the input, I'll try and update if I can figure out what it was.

[fth0]

00:45:17.889261 PDMR3PowerOff: Driver 'VD'/0 on LUN#0 of device 'piix3ide'/0 took 201 377 717 260 ns to power off

Powering off the virtual hard disk took over 200 seconds. This always was part of your previous problems, and this log message seems to be only displayed if it took too long. I don't see any connection to the audio changes.

[MatsBoekelund]

Hi fth0, thanks.
Also I find it far-fetched that it would have anything to do with the Audio devices.

It's probably coincidence but changing around audio devices was something that had happened between the two states "Problem present" and the current state, "Problem gone". If it was indeed caused by the Jabra headset being in there I would have expected the problem to come back when they were re-inserted but it did not, I have not seen the issue again since mid last week..

How's this for far-fetched:
In https://forums.virtualbox.org/viewtopic.php?f=6&t=101651 scottgus1 is suggesting to turn off audio on an old CentOS guest;-)
Also my log files show a fair amount of the Audio-related entries scottgus is referring to, I'm using CentOS 6.2 and CentOS 7.2 guests.

While I still believe it's coincidence, looking at Audio will be one of the actions on that one laptop that is still showing the slow powerdown issue when we get to that.

[MatsBoekelund]

I went back and looked at the beginnings of this:
1. Probably I was correct in thinking that I put this in the wrong forum, it's probably more to do with "Windows Host" than "Linux Guest" but I'm not going to move it now...
2. It seems I did not always have the issue and also back then I could not really point to something tangible I had done for the status to change.

The major problem I was facing back when this topic started was related to network / nameserver interaction that caused very sluggish operation of certain activities in the guests. At the time I did not know if the slow powerdown and the other issue were related, now I am confident they were not.

[fth0]

I did not say that there is no connection to the audio changes.

Everything looking unusual is a candidate for investigation. In the thread you linked to, the TM synchronization problems are the target IMHO, and the audio log messaged surrounding could be somehow related.

I'm curious what you'll find out.

[MatsBoekelund]

Hi fth0 and anyone else reading this, I hope the year has started OK for you.

Coming back to this topic after pretty much a year, just having noticed that the long power-down issue comes back if I update the VBox client to the current 6.1.32. Back when 6.1.26 came out, I noticed the problem on that one. This had me going back to re-install 6.1.22, with which I can power down just fine and the guests close within seconds, not minutes. (so I'm now also back on 6.1.22)

As this is on a Windows 10 host and I don't have any reason to believe it's being caused by the guests themselves, it would seem to make more sense for this thread to be in Windows Hosts rather than in Linux Guests.

I've not tried out any other newer versions than 6.1.26 and 6.1.32. In general, staying on 6.1.22 as I have for about a year now, is not a large problem for me. However, I'd like to find a way of figuring out what's wrong though, since until the issue is understood and can be resolved, there's probably always a risk that it comes back.

Our IT have spent hours looking through Windows10-logs to see if they can find what may be causing this but to no avail. With one of the earlier versions of the client I could "control" whether or not the problem appeared by deciding to either reboot the laptop (host) as part of the client de-install/install process or not. Both versions 6.1.26 and 6.1.32 are unimpressed by properly rebooting after de-install and after install, whereas 6.1.22 is happy also when I just install it and start it right away without a reboot.

We had also tried turning off the Cortex Antivirus and the Windows Defender back when I had this issue permanently, that did not help.

Summary:
6.1.22 does not show the issue with a long time to power down.
6.1.26 and 6.1.32 both do.

The delay of a few minutes also shows up when I "insert a DVD", for example the GA image. It looks like what's happening is that the .vdi disk file is being read and that's what's taking the long time.

Any ideas would be much appreciated.
thx + regards / Mats

[fth0]

The delay of a few minutes also shows up when I "insert a DVD", for example the GA image. It looks like what's happening is that the .vdi disk file is being read and that's what's taking the long time.

This sounds like you've found a way to reliably reproduce the issue in short time. Did you ever try my following earlier advice:

To investigate more about the disk accesses inside the Windows host OS, you could use Sysinternals DiskMon or Process Monitor.

This could reveal what part of which files are being accessed ...

[MatsBoekelund]

The delay of a few minutes also shows up when I "insert a DVD", for example the GA image. It looks like what's happening is that the .vdi disk file is being read and that's what's taking the long time.

This sounds like you've found a way to reliably reproduce the issue in short time. Did you ever try my following earlier advice:
Hi fth0, thanks.
Yes, all I need to do is install either 6.1.26 or 6.1.32 and it reliably shows up again, either when powering off or when "inserting a DVD".
In 6.1.22 the problem is gone. (also that is reliable, I'm using 6.1.22 since about June last year and I've never seen the issue with that version of the client)

To investigate more about the disk accesses inside the Windows host OS, you could use Sysinternals DiskMon or Process Monitor.

This could reveal what part of which files are being accessed ...

Yes, IT did take close looks at ProcMon logs, creating specific filters to remove unrelated stuff etc, but did not find a smoking gun. It appears that the file that's being read is actually my .vdi VirtualDisk file, this originally prompted the idea that "Antivirus" would seem like good candidates but Cortex and WindowsDefender have been turned off back with an earlier version of VBox and that did not fix the issue at the time. One subtlety I did not notice earlier but am seeing now is the separate tool DiskMon, not sure if that was employed at the time or only ProcMon was used. I'll tie up with IT again and see if we can revisit some of the data collected back then.

One thing I had not thuoght about before but noticed in one of the old dataset from ProcMon is BitLocker, that would seem liek a candidate as well. It just so happens that my VMs are on a separate drive and not on C:\ so when time permits I will make a trial without BitLocker.

[MatsBoekelund]

OK, here's a summary of some trials that initially were centered around BitLocker vs no BitLocker but then took a turn.
In all different blocks below, no effort was made to reboot the host between installations and de-installations of the VBox client versions.
A:
1. de-install 6.1.22
2. install 6.1.32
3. run a guest from a non-BitLocker disk: OK.
4. run a guest from a BitLocker disk: OK
(in both cases here the guest was started from the VBox client)
--------
B:
1. de-install 6.1.32
2. install 6.1.32
3. run a guest from a BitLocker disk: BAD
4. run a guest from a non-BitLocker disk: BAD
---------
C:
1. de-install and re-install 6.1.32
2. run a guest from a non-BitLocker disk: BAD
-------
D:
1. de-install/re-install 6.1.32
2. remove the guest from the VBox client, leaving the files in place. (this is the guest on the non-BitLocker disk)
3. start the guest by double-clicking the .vbox file, not from the client: OK.
-------
E:
1, de-install/re-install 6.1.32
2. start the guest on the non-BitLocker disk from the client: BAD
3. start the same guest by double-click instead, it's still part of the list in the client: OK
4. start a guest from a BitLocker disk by double-click: OK

Looks like I can use 6.1.32 as long as I stay away from running the client.....
The 6.1.22 client does not give me the problem.
(and indeed, using the different disks I again clearly see that the reading happens on the disk where the guest lives)

The two guests, one on a disk with BitLocker and one on the disk without BitLocker are not identical but they are from the same source, just some small Linux changes in one of them. I've never had the impression that this issue has had anything to do with which guest I happen to be using.

Not sure what to make of this but I will now stay on 6.1.32 since it looks like it's "just" the client's interaction with something and when using the guest I don't do anything with the client anyway.

[fth0]

Ok. So I understand that the VirtualBox Manager (if that's what you call "VBox Client") accesses the VDI file for a long time under certain circumstances. When you inserted the GA ISO file, did it access the VDI file or the ISO file then?

If it accessed the VDI file also when inserting the ISO file, I'd suspect the "Medium-enumeration" process about which I do not know much. Perhaps you could (let the IT) check the VDI file access pattern: Is the whole VDI file read? Sequentially or randomly? Or are only a few areas of the file accessed over and over?

PS: I'm just curious and cannot promise that we'll find out the background reason (we = you and me).