[Bug]: start-on-windows-boot fills disk with logs

[jamesianberry]

Describe the bug

Perhaps just on my system, but I had enabled Distrod on Windows startup as a new distribution with the following command:
sudo /opt/distrod/bin/distrod enable --start-on-windows-boot
My Windows system drive was being filled up with thousands of 8MB files in the following directory:
C:\Users\username\AppData\Local\Temp\DiagOutputDir\RdClientAutoTrace
The rapid creation of files stopped once I disabled Distrod on Windows startup with the following commands and then restarted Windows (afterwards, only a few files are created, at least one for each distro started):
sudo /opt/distrod/bin/distrod disable
sudo /opt/distrod/bin/distrod enable

Steps to reproduce

1. In Windows Terminal, from the drop down select Distrod
2. Enter the following command: sudo /opt/distrod/bin/distrod enable --start-on-windows-boot
3. Enter your Distrod password

[Distrod] Distrod has been enabled. Now your shell will start under systemd.
[Distrod] Enabling atuomatic startup of Distrod. UAC dialog will appear because scheduling
a task requires the admin privilege. Please hit enter to proceed.

4. Press Enter to start the UAC dialog entry
5. Press Yes on the Task Scheduler UAC dialog
6. Enter your Windows password
7. Restart your Windows PC
8. Check the following directory for log files with the type of ETL being created at a rapid rate
   C:\Users\username\AppData\Local\Temp\DiagOutputDir\RdClientAutoTrace

Expected behavior

Distrod starts on Windows startup without thousands of files being created in C:\Users\username\AppData\Local\Temp\DiagOutputDir\RdClientAutoTrace

Windows version

Microsoft Windows [Version 10.0.22000.348]

Linux kernel version

Linux RAZER 5.10.74.3-microsoft-standard-WSL2 #1 SMP Mon Oct 18 19:27:44 UTC 2021 x86_64 GNU/Linux

Distro

Debian

Logs

[Distrod][DEBUG] Executing a command in the distro.
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][DEBUG] Distro::exec_command.
[Distrod][DEBUG] Container::exec_command.
[Distrod][DEBUG] Triple fork done.
[Distrod][DEBUG] dropping privilege. kmsg logging in the child ends here.
[Distrod][DEBUG] The parent of the second of three forks exits.
[Distrod][DEBUG] Spawning the command or the waiter.
[Distrod][DEBUG] Spawning the waiter.
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)

-- Journal begins at Fri 2021-11-19 18:58:10 AEDT, ends at Mon 2021-11-29 23:01:18 AEDT. --
-- No entries --

additional comment

It looks like the files still get created for every distro started from Windows Terminal but this is at a much lower rate.
I am seeing more than one 8MB file being created per second when Distrod starts on Windows startup

[jamesianberry]

Logs when Distrod is started within Windows Terminal but not auto-started with Windows Startup:

[Distrod][DEBUG] starting /init from distrod-exec
[Distrod][DEBUG] WSL envs: "WSL_INTEROP" = "/run/WSL/8_interop"
[Distrod][DEBUG] WSL envs: "WSLENV" = "WT_SESSION::WT_PROFILE_ID"
[Distrod][DEBUG] WSL envs: "WSL_DISTRO_NAME" = "Distrod"
[Distrod][DEBUG] Container::with_mount source: Some(HostPath("/run/distrod/cmdline")), target: ContainerPath("/proc/cmdline"), fstype: None, flags: MS_BIND, is_file: true
[Distrod][TRACE] mount_distrod_run_files: path: "/opt/distrod/run/systemd"
[Distrod][TRACE] mount_distrod_run_files: path: "/opt/distrod/run/systemd/system"
[Distrod][TRACE] mount_distrod_run_files: path: "/opt/distrod/run/systemd/system/portproxy.service"
[Distrod][DEBUG] Container::with_mount source: Some(HostPath("/opt/distrod/run/systemd/system/portproxy.service")), target: ContainerPath("/run/systemd/system/portproxy.service"), fstype: None, flags: MS_BIND, is_file: true
[Distrod][TRACE] mount_distrod_run_files: path: "/opt/distrod/run/tmpfiles.d"
[Distrod][TRACE] mount_distrod_run_files: path: "/opt/distrod/run/tmpfiles.d/x11.conf"
[Distrod][DEBUG] Container::with_mount source: Some(HostPath("/opt/distrod/run/tmpfiles.d/x11.conf")), target: ContainerPath("/run/tmpfiles.d/x11.conf"), fstype: None, flags: MS_BIND, is_file: true
[Distrod][DEBUG] DistroLauncher::launch
[Distrod][DEBUG] Container::with_mount source: Some(HostPath("/run/distrod/distrod_wsl_env-uid1000")), target: ContainerPath("/run/distrod/distrod_wsl_env-uid1000"), fstype: None, flags: MS_BIND, is_file: true
[Distrod][DEBUG] Spawning the command or the waiter.
[Distrod][DEBUG] Executing a command in the distro.
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][DEBUG] Distro::exec_command.
[Distrod][DEBUG] Container::exec_command.
[Distrod][DEBUG] Triple fork done.
[Distrod][DEBUG] dropping privilege. kmsg logging in the child ends here.
[Distrod][DEBUG] The parent of the second of three forks exits.
[Distrod][DEBUG] Spawning the command or the waiter.
[Distrod][DEBUG] Spawning the waiter.
[Distrod][TRACE] mounting source: Some(
    ContainerPath(
        "/run/distrod/cmdline",
    ),
), mount: ContainerMount { source: Some(HostPath("/run/distrod/cmdline")), target: ContainerPath("/proc/cmdline"), fstype: None, flags: MS_BIND, data: None, is_file: true }
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][TRACE] mounting source: Some(
    ContainerPath(
        "/opt/distrod/run/systemd/system/portproxy.service",
    ),
), mount: ContainerMount { source: Some(HostPath("/opt/distrod/run/systemd/system/portproxy.service")), target: ContainerPath("/run/systemd/system/portproxy.service"), fstype: None, flags: MS_BIND, data: None, is_file: true }
[Distrod][DEBUG] Failed to ignore signal Sys(EINVAL)
[Distrod][TRACE] mounting source: Some(
    ContainerPath(
        "/opt/distrod/run/tmpfiles.d/x11.conf",
    ),
), mount: ContainerMount { source: Some(HostPath("/opt/distrod/run/tmpfiles.d/x11.conf")), target: ContainerPath("/run/tmpfiles.d/x11.conf"), fstype: None, flags: MS_BIND, data: None, is_file: true }
[Distrod][TRACE] skipping an identical mount: Some(
    ContainerPath(
        "/run/distrod/distrod_wsl_env-uid1000",
    ),
), ContainerMount {
    source: Some(
        HostPath(
            "/run/distrod/distrod_wsl_env-uid1000",
        ),
    ),
    target: ContainerPath(
        "/run/distrod/distrod_wsl_env-uid1000",
    ),
    fstype: None,
    flags: MS_BIND,
    data: None,
    is_file: true,
}

[nullpo-head]

Hi, thanks for trying Distrod.

1. I wasn't able to reproduce this problem. One thing I noticed is that your kernel is newer than mine, though Windows version is the same. My kernel version is 5.10.60.1. Are you on preview build?

2. also, could you provide the journalctl output, please? I guess wslg or something is writing some error / warnings, because RdClientAutoTrace looks related to WSLg. You already provided a log, but it's empty. Empty log is impossible, because at least there should be kernel boot message. Please share the recent parts of sudo journalctl.

3. lastly,

   the files still get created for every distro started from Windows Terminal

   Does this mean that your non-Distrod distro is causing the same issue?

[jamesianberry]

Hi Takaya, thanks for your help on Distrod.

1. I am now installing and updating WSL from the Microsoft Store, and yes, it is the preview build: https://www.microsoft.com/store/productId/9P9TQF7MRM4R

2. The journalctl output seems to show a lot of errors before I made the changes to stop the excessive logging:
   journalctl.txt

3. It seems that only non-Distrod distributions now have a log file created each time they are started.

[aki-k]

@jamesianberry Do you see weston crashing in dmesg of WSL? It's writing some kind of stack trace once per second for me. This with enabling auto-starting of WSL with the Windows task scheduler and enabling systemd in WSL.

[Thu Nov 11 16:01:23 2021] traps: weston[217761] trap divide error ip:7fec836cc20c sp:7fff0d34cc50 error:0 in rdp-backend.so[7fec836c3000+1b000]
[Thu Nov 11 16:01:23 2021] potentially unexpected fatal signal 8.

[jamesianberry]

@aki-k yes, this looks to be the same error my system was getting (see journalctl output above):

Nov 29 23:01:15 RAZER kernel: traps: weston[2055] trap divide error ip:7f2412cde37c sp:7ffe958efdd0 error:0 in rdp-backend.so[7f2412cd5000+1b000]
Nov 29 23:01:15 RAZER kernel: potentially unexpected fatal signal 8.
Nov 29 23:01:15 RAZER kernel: CPU: 13 PID: 2055 Comm: weston Not tainted 5.10.74.3-microsoft-standard-WSL2 #1
Nov 29 23:01:15 RAZER kernel: RIP: 0033:0x7f2412cde37c
Nov 29 23:01:15 RAZER kernel: Code: 79 34 99 44 01 d7 f7 fe 99 31 d0 89 41 38 29 51 38 45 85 c0 0f 88 ef 01 00 00 48 83 c1 44 4c 39 d9 74 63 8b 41 08 8b 71 2c 99 <f7> fe 89 41 3c 41 89 c2 8b 41 0c 99 f7 fe 89 41 40 41 89 c0 45 84
Nov 29 23:01:15 RAZER kernel: RSP: 002b:00007ffe958efdd0 EFLAGS: 00010246
Nov 29 23:01:15 RAZER kernel: RAX: 0000000000000400 RBX: 0000000000000000 RCX: 00007ffe958efe40
Nov 29 23:01:15 RAZER kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
Nov 29 23:01:15 RAZER kernel: RBP: 00007ffe958efe40 R08: 0000559c30dc0770 R09: 0000000000000001
Nov 29 23:01:15 RAZER kernel: R10: 0000559c30dc0740 R11: 00007ffe958efe84 R12: 0000000000000001
Nov 29 23:01:15 RAZER kernel: R13: 0000000000000000 R14: 0000559c30a8f5a0 R15: 0000000000000000
Nov 29 23:01:15 RAZER kernel: FS:  00007f2413202900 GS:  0000000000000000

I guess the questions are:

• does this happen for non-Distrod distributions? (I see similar log files being created by them when they start, I guess I can look for any related weston error)
• what happens if non-Distrod distros are auto-started on boot? (haven't tried this)
• is this a WSL2 problem rather than a Distrod problem? (in which case, it should be raised elsewhere)

[aki-k]

is this a WSL2 problem rather than a Distrod problem? (in which case, it should be raised elsewhere)

I don't know if this is the same problem I have but I opened an issue at microsoft/wslg#564 but got no replies. I didn't even think of checking that directory C:\Users\username\AppData\Local\Temp\DiagOutputDir\RdClientAutoTrace on Windows side.

[Karl-Larson]

It looks like this might be tied to the preview version of WSL2 from the store.
I had this same issue with the logs eating up almost 500GB. (Wish i checked dates on them before cleaning it up.)

I uninstalled the preview version of WSL2 from the store and no more logs were being created upon starting any WSL2 instance.
While previously any WSL2 instance starting from a shut downed state via "wsl --shutdown" would create a log and fill it once killed with the same command.

I am running windows 22000.493.
The preview kernel was the latest as of 2/12/2022, 5.10.93.2.
Once the preview was removed I was running 5.10.60.1.

[dev-seahouse]

i'm having this issue too and it is kill my ssd

[frixaco]

This solution fixed the problem for me: #50 (comment)

[techroy23]

I got it working
#50 (comment)