Bug 259234 - emulators/virtualbox-ose proliferation of ~/⋯-VirtualBoxVM-⋯.log files
Summary: emulators/virtualbox-ose proliferation of ~/⋯-VirtualBoxVM-⋯.log files
Status: New
Alias: None
Product: Ports & Packages
Classification: Unclassified
Component: Individual Port(s) (show other bugs)
Version: Latest
Hardware: Any Any
: --- Affects Many People
Assignee: Virtualbox Team (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-10-17 18:49 UTC by Graham Perrin
Modified: 2021-10-23 20:27 UTC (History)
2 users (show)

See Also:
bugzilla: maintainer-feedback? (vbox)


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Graham Perrin 2021-10-17 18:49:11 UTC
<https://forums.freebsd.org/threads/82478/>

> VirtualBox creates small logs in the working directory

Confirmed, at least for ~

% ls ~/*.log | grep -i virtualbox
/home/grahamperrin/2021-10-10-18-14-31.079-VirtualBoxVM-74616.log
/home/grahamperrin/2021-10-11-17-31-03.009-VirtualBoxVM-40559.log
/home/grahamperrin/2021-10-11-17-31-18.067-VirtualBoxVM-40561.log
/home/grahamperrin/2021-10-11-17-37-25.039-VirtualBoxVM-40574.log
/home/grahamperrin/2021-10-11-17-57-23.022-VirtualBoxVM-40639.log
/home/grahamperrin/2021-10-11-17-58-35.045-VirtualBoxVM-40641.log
/home/grahamperrin/2021-10-11-19-13-43.029-VirtualBoxVM-40777.log
/home/grahamperrin/2021-10-11-19-26-03.006-VirtualBoxVM-40802.log
/home/grahamperrin/2021-10-11-19-27-00.004-VirtualBoxVM-40804.log
/home/grahamperrin/2021-10-11-19-53-00.033-VirtualBoxVM-40845.log
/home/grahamperrin/2021-10-11-20-02-48.025-VirtualBoxVM-40871.log
/home/grahamperrin/2021-10-11-20-09-06.046-VirtualBoxVM-40878.log
/home/grahamperrin/2021-10-11-20-10-34.012-VirtualBoxVM-40884.log
/home/grahamperrin/2021-10-12-05-50-48.024-VirtualBoxVM-85072.log
/home/grahamperrin/2021-10-13-05-26-17.090-VirtualBoxVM-4675.log
/home/grahamperrin/2021-10-13-05-33-42.007-VirtualBoxVM-4684.log
/home/grahamperrin/2021-10-16-00-04-21.092-VirtualBoxVM-50520.log
/home/grahamperrin/2021-10-16-00-12-02.013-VirtualBoxVM-50607.log
/home/grahamperrin/2021-10-16-01-54-55.083-VirtualBoxVM-51135.log
/home/grahamperrin/2021-10-16-04-20-32.007-VirtualBoxVM-51385.log
/home/grahamperrin/2021-10-16-04-31-46.059-VirtualBoxVM-51428.log
/home/grahamperrin/2021-10-16-05-43-43.011-VirtualBoxVM-4849.log
/home/grahamperrin/2021-10-16-06-37-46.015-VirtualBoxVM-5531.log
/home/grahamperrin/2021-10-16-07-31-12.017-VirtualBoxVM-5565.log
/home/grahamperrin/2021-10-16-08-01-42.011-VirtualBoxVM-5598.log
/home/grahamperrin/2021-10-16-08-10-28.064-VirtualBoxVM-5603.log
/home/grahamperrin/2021-10-16-14-28-31.068-VirtualBoxVM-6622.log
/home/grahamperrin/2021-10-16-16-30-11.037-VirtualBoxVM-6843.log
/home/grahamperrin/2021-10-16-16-39-49.076-VirtualBoxVM-6864.log
/home/grahamperrin/2021-10-16-17-01-36.092-VirtualBoxVM-6927.log
/home/grahamperrin/2021-10-16-18-34-25.048-VirtualBoxVM-7224.log
/home/grahamperrin/2021-10-16-20-50-30.046-VirtualBoxVM-7542.log
/home/grahamperrin/2021-10-17-02-38-28.084-VirtualBoxVM-8440.log
/home/grahamperrin/2021-10-17-03-12-01.077-VirtualBoxVM-8531.log
/home/grahamperrin/2021-10-17-03-20-26.098-VirtualBoxVM-8541.log
/home/grahamperrin/2021-10-17-04-21-47.032-VirtualBoxVM-50441.log
/home/grahamperrin/2021-10-17-04-28-22.030-VirtualBoxVM-50458.log
/home/grahamperrin/2021-10-17-04-51-46.094-VirtualBoxVM-50513.log
/home/grahamperrin/2021-10-17-09-38-29.080-VirtualBoxVM-3030.log
/home/grahamperrin/2021-10-17-09-44-30.016-VirtualBoxVM-3073.log
/home/grahamperrin/2021-10-17-12-11-30.021-VirtualBoxVM-2821.log
/home/grahamperrin/2021-10-17-12-59-15.001-VirtualBoxVM-2926.log
/home/grahamperrin/2021-10-17-15-51-17.000-VirtualBoxVM-3290.log
/home/grahamperrin/2021-10-17-16-17-05.018-VirtualBoxVM-3328.log
/home/grahamperrin/2021-10-17-16-29-22.013-VirtualBoxVM-3369.log
/home/grahamperrin/2021-10-17-16-47-30.028-VirtualBoxVM-3397.log
/home/grahamperrin/2021-10-17-17-53-28.066-VirtualBoxVM-3595.log
/home/grahamperrin/2021-10-17-18-00-07.084-VirtualBoxVM-3618.log
/home/grahamperrin/2021-10-17-18-36-19.056-VirtualBoxVM-3671.log
% pkg info -x virtualbox
virtualbox-ose-6.1.26_3
virtualbox-ose-kmod-6.1.26
% uname -aKU
FreeBSD mowa219-gjp4-8570p-freebsd 14.0-CURRENT FreeBSD 14.0-CURRENT #112 main-n249988-2c614481fd5: Sun Oct 10 21:42:16 BST 2021     root@mowa219-gjp4-8570p-freebsd:/usr/obj/usr/src/amd64.amd64/sys/GENERIC-NODEBUG  amd64 1400036 1400036
% freebsd-version -kru
14.0-CURRENT
14.0-CURRENT
14.0-CURRENT
%
Comment 1 Graham Perrin 2021-10-21 05:56:03 UTC
From opening post <https://forums.freebsd.org/posts/537276>: 

> … from virtualbox-ose-6.1.22_1 to virtualbox-ose-6.1.26_3. …

If it helps to understand the bug, as it is now: 

* I vaguely recall occasional manual removal of .log files from ~ with 
  _lesser_ versions of VirtualBox. 

There were, in the past, so few that I paid almost zero attention. I did wonder whether they were visible debris, from guest sessions that were abnormally killed. (So little attention, I never thought to browse my home directory _during_ a run of a guest, to tell whether a .log was normally visible during a run.)

----

As things are now: 

% pkg info -x virtualbox
virtualbox-ose-6.1.26_3
virtualbox-ose-kmod-6.1.26
% 

I see a log file appear immediately after starting, for example, a saved session. 

During the run: 

% date ; cat 2021-10-21-05-50-55.003-VirtualBoxVM-56324.log
Thu 21 Oct 2021 06:55:39 BST
Log created: 2021-10-21T05:50:55.038476000Z
Process ID:  56324 (0xdc04)
Parent PID:  56320 (0xdc00)
Executable:  /usr/local/lib/virtualbox/VirtualBoxVM
Arg[0]: /usr/local/lib/virtualbox/VirtualBoxVM
Arg[1]: --comment
Arg[2]: Windows
Arg[3]: --startvm
Arg[4]: 6bec4796-c6ff-4ebc-8c20-3e56093e1eca
Arg[5]: --no-startvm-errormsgbox
%
Comment 2 Graham Perrin 2021-10-21 06:43:38 UTC
(In reply to Graham Perrin from comment #1)

> … During the run: …

After graceful closure and save of the guest, followed by a graceful quit of the Oracle VM VirtualBox application: the same. 

(The file persists, nothing appended.)
Comment 3 Guido Falsi freebsd_committer 2021-10-21 07:50:46 UTC
This is a known issue since 6.1.x got in the tree. It was deemed not important enough to not update the port to 6.1.

They are left behind every time a virtual machine is started. Someone (can't remember who) observed they used to be created in the past too, but usually automatically removed if everything went fine with the launched VM.

One thing that could help with this is dig out in the source code where these files are being created.

When debugging such issues a lot of time needs to be spent on finding the involved part of the source code [1], especially when the involved people do not know the structure of the code by hearth. So if you have time to spend on this digging the source code would help more than describing the external behaviour of the software, which is already known.

Also understanding the original purpose of these log files could help.


[1] this is also the reason why good backtraces are so important when any bug arises in any mildly complex software
Comment 4 Graham Perrin 2021-10-21 21:39:08 UTC
Thanks, I'll do what I can (and draw attention in FreeBSD Forums).
Comment 5 Newton Terry 2021-10-23 16:38:22 UTC
(In reply to Guido Falsi from comment #3)
> One thing that could help with this is dig out in the source code where these
> files are being created.
It looks like the involved parts of the source code are to find in 
https://www.virtualbox.org/browser/vbox/trunk/src/VBox/Runtime/VBox/log-vbox.cpp

"Create the default logging instance."
https://www.virtualbox.org/browser/vbox/trunk/src/VBox/Runtime/VBox/log-vbox.cpp#L496

"Write a log header."
https://www.virtualbox.org/browser/vbox/trunk/src/VBox/Runtime/VBox/log-vbox.cpp#L519

I'm not sure how to proceed from here to find the purpose of their creation and the cause of the log files not being removed, assuming they are automatically removed.


Apropos, the creation of those log files can be suppressed by setting VirtualBox env variable "VBOX_LOG_DEST" to "nofile".

References: 
https://www.virtualbox.org/browser/vbox/trunk/src/VBox/Runtime/VBox/log-vbox.cpp#L38
https://www.virtualbox.org/wiki/VBoxLogging
Comment 6 Guido Falsi freebsd_committer 2021-10-23 20:27:08 UTC
(In reply to Newton Terry from comment #5)

Thanks for your findings.

So this is the default logging mechanism doing its work. If configured to log a lot of information would be logged to these files.

As far as I know these files have always been created by virtualbox but usually got deleted, maybe right away, depending on..."Something".

But I cannot see any code to remove these files in `src/VBox/Runtime/common/log/log.cpp` or `src/VBox/Runtime/VBox/log-vbox.cpp`. 

So at present I'm asking myself how these got deleted in version 5.2.x.

A quick look at the old distfile or the change history of these files is not helpful unluckily.