Add WSLg tracing guide and logging enhancements

.github/copilot-instructions.md

@@ -0,0 +1,52 @@
+## Quick orientation for AI coding agents
+
+This repo implements WSLg (Windows Subsystem for Linux GUI). The goal of these notes is to help an automated coding assistant become productive fast: what the major components are, where to look for behavior, how developers build/test locally, and project-specific conventions.
+
+### Big-picture architecture (high-level)
+- WSLGd (`WSLGd/`) — first userland process launched in the system distro. It configures env variables, mounts shared resources, launches `weston`, `PulseAudio` and manages the RDP connection. See `WSLGd/main.cpp` for env keys, mount points and startup flow.
+- Weston and related components — built from mirrors under `vendor/` (FreeRDP, weston, pulseaudio). See `config/BUILD.md` for vendor checkout and image build steps. The custom RDP backend and RAIL/VAIL logic live in the weston mirror.
+- WSLDVCPlugin (`WSLDVCPlugin/`) — Windows-side plugin that receives app lists via a virtual channel and creates Start Menu links. This is a Visual C++/MSBuild solution (sln/vcxproj) — Windows build targets live here.
+- Packaging and system distro — `container/` and `config/` contain Dockerfile, `tar2ext4` usage and instructions to produce `system.vhd` used as the system distro.
+
+### Key integration points & runtime data flows
+- RDP transport: Weston -> FreeRDP -> mstsc (Windows) (RAIL & VAIL modes). Look in `vendor/*-mirror` for the modified backends.
+- Shared memory/virtio-fs: WSLG mounts a shared memory virtiofs at `/mnt/shared_memory` and uses it for VAIL transfers. Environment variables: `WSL2_SHARED_MEMORY_MOUNT_POINT` and `WSL2_SHARED_MEMORY_OB_DIRECTORY` (see `WSLGd/main.cpp`).
+- Virtual channel: WSLDVCPlugin listens to the custom RDP virtual channel to enumerate GUI apps and create Windows shortcuts.
+
+### Concrete developer workflows (discovered from repo files)
+- Build Windows plugin: open `WSLDVCPlugin/WSLDVCPlugin.sln` in Visual Studio or run MSBuild on the `WSLDVCPlugin.vcxproj`. The repo workspace defines a build task for msbuild. On Windows (PowerShell), use `msbuild /t:build` or the provided VS solution.
+- Build system distro (Linux/WSL): follow `config/BUILD.md` — clone FreeRDP/Weston/PulseAudio mirrors on `working` branch into `vendor/`, then build inside Docker (see `container/build.sh` and `config/BUILD.md`). After docker export, use `tar2ext4` (from hcsshim) to create `system.vhd`.
+- Inspect runtime: run `wsl --system <DistroName>` and use `ps -ax | grep weston` or inspect logs under the shared mount: `/mnt/wslg/weston.log` and `/mnt/wslg/stderr.log` (see `WSLGd/main.cpp` for log path env overrides).
+
+### Important files to reference when making changes
+- `WSLGd/main.cpp` — daemon setup, env keys, mounts, logging, shared memory code paths.
+- `WSLDVCPlugin/` — Windows side plugin, msbuild solution, resource files used to create Start Menu shortcuts.
+- `config/BUILD.md` and `container/` — reproduce and debug the system distro build (Docker, tar->vhd steps).
+- `package/` — contains `wslg.rdp` and `wslg_desktop.rdp` templates used by the project.
+- `vendor/` mirrors — look here for modified upstream components (Weston, FreeRDP, PulseAudio).
+
+### Project-specific conventions and patterns
+- Mirror model: upstream projects are mirrored under `vendor/*-mirror`. The repo builds from the `working` branch of those mirrors. Search for `working` branch references when changing how an upstream component is built.
+- Env-driven runtime behavior: Many run-time decisions are controlled by environment variables (for example `WSLG_WESTON_LOG_PATH`, `WSL2_INSTALL_PATH`, `WSLG_ERR_LOG_PATH`, `WSL2_WESTON_SHELL_DESKTOP`). When proposing code changes, reference `WSLGd/main.cpp` to see which env vars are read and where to update docs/tests.
+- Logging and failure recovery: `WSLGd` intentionally restarts key subprocesses. Look for `ProcessMonitor` and `FontMonitor` in `WSLGd/` for patterns of supervising child processes.
+- C++ style: project uses `wil` helpers and `THROW_LAST_ERROR_IF` macros; prefer following existing error-handling idioms in `WSLGd` code when making changes.
+
+### Examples agents should use when editing or adding code
+- To add a new env-controlled feature, update `WSLGd/main.cpp` to read the new env key, add a documented default in `README.md`/`config/BUILD.md` and add tests or run instructions in `docs/`.
+- To change how the Windows plugin creates shortcuts, inspect `WSLDVCPlugin/*.cpp` and resources (.rc) in the same folder; prefer editing the VC++ project rather than hand-editing binaries.
+
+### Useful quick commands and checks (for dev workflow automation)
+- Inspect system distro processes and logs: `wsl --system <DistroName>` then `ps -ax | grep weston` and check `/mnt/wslg/weston.log` and `/mnt/wslg/stderr.log`.
+- Rebuild Windows plugin (PowerShell): open solution in Visual Studio or run msbuild on `WSLDVCPlugin/WSLDVCPlugin.sln` (workspace contains a build task for `msbuild`).
+- Recreate system.vhd: follow `config/BUILD.md` -> `docker build` of the image and `tar2ext4` from `hcsshim` to produce `system.vhd`.
+
+### Do NOT assume
+- Do not assume upstream components have identical APIs — the repo uses modified copies in `vendor/*-mirror`; changes often live in those forks.
+- Do not assume a single unified build system: Windows build uses MSBuild/Visual Studio, system-distro build uses Docker/Meson/Make (see `container/` and `config/BUILD.md`).
+
+### Quick checklist for PRs touching runtime
+1. Point to which mirror(s) are impacted (`vendor/*-mirror`) and whether patch will be upstreamed.
+2. Include how to validate change inside the system distro (which log to check, which `ps` entry to look for).
+3. If Windows side is touched, include MSBuild/solution edits and any resource (.rc) changes.
+
+If any part of this doc is unclear or you want more detail in a specific area (build scripts, debugging, or a component boundary), tell me which area and I will expand the instructions or add short examples and automation snippets.

WSLGd/common.h

@@ -5,8 +5,15 @@
 #define USER_DISTRO_MOUNT_PATH SHARE_PATH "/distro"
 
 void LogPrint(int level, const char *func, int line, const char *fmt, ...) noexcept;
+#define LOG_LEVEL_DEBUG      2
 #define LOG_LEVEL_EXCEPTION 3
 #define LOG_LEVEL_ERROR     4
 #define LOG_LEVEL_INFO      5
+#define LOG_LEVEL_TRACE     1
 #define LOG_ERROR(fmt, ...) LogPrint(LOG_LEVEL_ERROR, __FUNCTION__, __LINE__, fmt, ##__VA_ARGS__)
 #define LOG_INFO(fmt, ...) LogPrint(LOG_LEVEL_INFO, __FUNCTION__, __LINE__, fmt, ##__VA_ARGS__)
+#define LOG_DEBUG(fmt, ...) LogPrint(LOG_LEVEL_DEBUG, __FUNCTION__, __LINE__, fmt, ##__VA_ARGS__)
+#define LOG_TRACE(fmt, ...) LogPrint(LOG_LEVEL_TRACE, __FUNCTION__, __LINE__, fmt, ##__VA_ARGS__)
+#define TRACE_ENTRY() LOG_TRACE(">>> Entering")
+#define TRACE_EXIT() LOG_TRACE("<<< Exiting")
+#define TRACE_CALL(func) LOG_TRACE("Calling: %s", #func)

WSLGd/precomp.h

@@ -30,8 +30,10 @@
 #include <array>
 #include <filesystem>
 #include <map>
+#include <set>
 #include <new>
 #include <vector>
+#include <string>
 #include "config.h"
 #include "lxwil.h"
 #if HAVE_WINPR

WSLGd/trace.h

@@ -0,0 +1,95 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT license.
+#pragma once
+
+#include <cstdlib>
+#include <cstring>
+
+// Tracing control via environment variables:
+// WSLG_TRACE_LEVEL: 1=TRACE, 2=DEBUG, 3=EXCEPTION, 4=ERROR, 5=INFO
+// WSLG_TRACE_COMPONENTS: comma-separated component names to trace (e.g., "ProcessMonitor,FontMonitor")
+// WSLG_TRACE_FILE: if set, write traces to this file in addition to stderr
+
+class TraceConfig {
+public:
+    static TraceConfig& GetInstance() {
+        static TraceConfig instance;
+        return instance;
+    }
+
+    bool IsEnabled() const {
+        return m_enabled;
+    }
+
+    int GetTraceLevel() const {
+        return m_traceLevel;
+    }
+
+    bool IsComponentEnabled(const char* component) const {
+        if (!m_componentFilter || m_componentFilter[0] == '\0') {
+            return true;  // All components enabled if no filter
+        }
+        return m_enabledComponents.find(component) != m_enabledComponents.end();
+    }
+
+    const char* GetTraceFile() const {
+        return m_traceFile ? m_traceFile : nullptr;
+    }
+
+private:
+    TraceConfig() {
+        // Check if tracing is enabled
+        const char* enableEnv = std::getenv("WSLG_TRACE_ENABLED");
+        m_enabled = enableEnv && (std::strcmp(enableEnv, "1") == 0 || std::strcmp(enableEnv, "true") == 0);
+
+        // Get trace level
+        const char* levelEnv = std::getenv("WSLG_TRACE_LEVEL");
+        m_traceLevel = levelEnv ? std::atoi(levelEnv) : 5;  // Default to INFO level
+
+        // Get component filter
+        m_componentFilter = std::getenv("WSLG_TRACE_COMPONENTS");
+
+        // Parse enabled components
+        if (m_componentFilter) {
+            std::string components = m_componentFilter;
+            size_t pos = 0;
+            while (pos < components.length()) {
+                size_t comma = components.find(',', pos);
+                if (comma == std::string::npos) {
+                    m_enabledComponents.insert(components.substr(pos));
+                    break;
+                }
+                m_enabledComponents.insert(components.substr(pos, comma - pos));
+                pos = comma + 1;
+            }
+        }
+
+        // Get trace file
+        m_traceFile = std::getenv("WSLG_TRACE_FILE");
+    }
+
+    bool m_enabled;
+    int m_traceLevel;
+    const char* m_componentFilter;
+    const char* m_traceFile;
+    std::set<std::string> m_enabledComponents;
+};
+
+// Conditional tracing macros
+#define TRACE_ENABLED() (TraceConfig::GetInstance().IsEnabled())
+#define TRACE_COMPONENT_ENABLED(comp) (TraceConfig::GetInstance().IsComponentEnabled(comp))
+#define TRACE_LEVEL_ENABLED(level) (TraceConfig::GetInstance().GetTraceLevel() <= (level))
+
+#ifdef ENABLE_DETAILED_TRACING
+    #define TRACE_FUNC_ENTRY() TRACE_ENTRY()
+    #define TRACE_FUNC_EXIT() TRACE_EXIT()
+    #define TRACE_VALUE(name, value) LOG_TRACE("%s = %s", #name, value)
+    #define TRACE_INT(name, value) LOG_TRACE("%s = %d", #name, value)
+    #define TRACE_PTR(name, ptr) LOG_TRACE("%s = %p", #name, ptr)
+#else
+    #define TRACE_FUNC_ENTRY()
+    #define TRACE_FUNC_EXIT()
+    #define TRACE_VALUE(name, value)
+    #define TRACE_INT(name, value)
+    #define TRACE_PTR(name, ptr)
+#endif

docs/TRACING.md

@@ -0,0 +1,187 @@
+# WSLg Tracing Guide
+
+This document describes the tracing infrastructure available in WSLg for debugging and performance analysis.
+
+## Overview
+
+WSLg includes comprehensive tracing support via:
+1. Log levels (TRACE, DEBUG, ERROR, INFO, EXCEPTION)
+2. Component-based filtering
+3. Environment variable configuration
+4. Runtime call tracing
+
+## Log Levels
+
+The following log levels are defined (lower numbers = more verbose):
+
+| Level | Macro | Use Case |
+|-------|-------|----------|
+| 1 | `LOG_TRACE()` | Function entry/exit, variable values, detailed flow |
+| 2 | `LOG_DEBUG()` | Debugging information, intermediate values |
+| 3 | `LOG_EXCEPTION()` | Exception and error details |
+| 4 | `LOG_ERROR()` | Error conditions |
+| 5 | `LOG_INFO()` | General informational messages |
+
+## Macros
+
+### Basic Logging
+
+```c
+LOG_TRACE(fmt, ...)        // Trace level logging
+LOG_DEBUG(fmt, ...)        // Debug level logging
+LOG_INFO(fmt, ...)         // Info level logging
+LOG_ERROR(fmt, ...)        // Error level logging
+LogException(msg, desc)    // Exception logging
+```
+
+### Tracing Helpers
+
+```c
+TRACE_ENTRY()              // Log function entry point
+TRACE_EXIT()               // Log function exit point
+TRACE_CALL(func)           // Log when calling a function
+```
+
+### Detailed Tracing (when ENABLE_DETAILED_TRACING is defined)
+
+```c
+TRACE_FUNC_ENTRY()         // Conditional function entry logging
+TRACE_FUNC_EXIT()          // Conditional function exit logging
+TRACE_VALUE(name, value)   // Trace string value: name = value
+TRACE_INT(name, value)     // Trace integer value: name = 123
+TRACE_PTR(name, ptr)       // Trace pointer value: name = 0x12345678
+```
+
+## Environment Variables
+
+Control tracing behavior via environment variables:
+
+### WSLG_TRACE_ENABLED
+Enable/disable the tracing system.
+```bash
+export WSLG_TRACE_ENABLED=1
+export WSLG_TRACE_ENABLED=true
+```
+
+### WSLG_TRACE_LEVEL
+Set the minimum trace level to display (1-5, lower = more verbose).
+```bash
+export WSLG_TRACE_LEVEL=1    # Show everything (TRACE and above)
+export WSLG_TRACE_LEVEL=2    # DEBUG level and above
+export WSLG_TRACE_LEVEL=4    # ERROR level and above
+export WSLG_TRACE_LEVEL=5    # INFO level only (default)
+```
+
+### WSLG_TRACE_COMPONENTS
+Filter tracing to specific components (comma-separated).
+```bash
+export WSLG_TRACE_COMPONENTS=ProcessMonitor,FontMonitor
+export WSLG_TRACE_COMPONENTS=*    # Trace all components
+```
+
+### WSLG_TRACE_FILE
+Write traces to a file in addition to stderr.
+```bash
+export WSLG_TRACE_FILE=/mnt/wslg/traces.log
+```
+
+## Usage Examples
+
+### Example 1: Full Trace of ProcessMonitor
+```bash
+export WSLG_TRACE_ENABLED=1
+export WSLG_TRACE_LEVEL=1
+export WSLG_TRACE_COMPONENTS=ProcessMonitor
+wsl --system <distro>
+```
+
+### Example 2: Debug-level traces with file output
+```bash
+export WSLG_TRACE_ENABLED=1
+export WSLG_TRACE_LEVEL=2
+export WSLG_TRACE_FILE=/mnt/wslg/debug.log
+wsl --system <distro>
+```
+
+### Example 3: Error and Exception tracing only
+```bash
+export WSLG_TRACE_LEVEL=3
+wsl --system <distro>
+```
+
+## Integration with Code
+
+### Adding Tracing to Functions
+
+```c
+void MyFunction(int param) {
+    TRACE_ENTRY();
+    TRACE_INT("param", param);
+
+    // Function logic
+    int result = DoSomething();
+    TRACE_INT("result", result);
+
+    TRACE_EXIT();
+}
+```
+
+### Conditional Tracing
+
+```c
+if (TRACE_ENABLED()) {
+    if (TRACE_COMPONENT_ENABLED("ProcessMonitor")) {
+        LOG_TRACE("Detailed process information...");
+    }
+}
+```
+
+### Level-based Tracing
+
+```c
+if (TRACE_LEVEL_ENABLED(LOG_LEVEL_DEBUG)) {
+    LOG_DEBUG("Verbose debug information");
+}
+```
+
+## Log Output Format
+
+Logs are printed to stderr with the format:
+```
+[HH:MM:SS.mmm] <LEVEL> WSLGd: function:line: message
+```
+
+Example:
+```
+[14:23:45.123] <1> WSLGd: ProcessMonitor::Start:42: >>> Entering
+[14:23:45.124] <2> WSLGd: ProcessMonitor::Start:45: param = 5
+[14:23:45.125] <1> WSLGd: ProcessMonitor::Start:50: <<< Exiting
+```
+
+## Viewing Traces
+
+### In the System Distro
+```bash
+wsl --system <distro>
+ps aux | grep -E 'weston|wslgd|pulse'
+cat /mnt/wslg/stderr.log
+```
+
+### From Windows
+Traces written to the WSLG_TRACE_FILE can be viewed with any text editor:
+```powershell
+Get-Content "\\wsl.localhost\<distro>\mnt\wslg\traces.log" -Tail 100
+```
+
+## Performance Considerations
+
+- Tracing has minimal overhead when disabled
+- TRACE_FUNC_ENTRY() and similar detailed macros only compile when ENABLE_DETAILED_TRACING is defined
+- For production builds, use LOG_LEVEL_INFO or higher
+- TRACE level logging should only be used during development/debugging
+
+## Related Files
+
+- `WSLGd/common.h` - Core logging macros and log levels
+- `WSLGd/trace.h` - Advanced tracing configuration and helpers
+- `WSLGd/main.cpp` - Environment variable initialization