diff --git a/src/RemSound.App/ProbeAppLoopback.cs b/src/RemSound.App/ProbeAppLoopback.cs new file mode 100644 index 0000000..04d5761 --- /dev/null +++ b/src/RemSound.App/ProbeAppLoopback.cs @@ -0,0 +1,66 @@ +using System.Diagnostics; +using RemSound.Sender; + +namespace RemSound.App; + +/// Focused diagnostic probe for the process-loopback activation hang (per-app send). Run via +/// `RemSound.exe --probe-apploopback [pid]`. Traces the whole activation path (hr, callback delivery, +/// timing) for the given pid — or the FIRST process named in the REMSOUND_PROBE_APP env var, else self. +/// Prints to the console; not part of the gate. Temporary investigation aid. +internal static class ProbeAppLoopback +{ + public static int Run(string[] args) + { + var outPath = Path.Combine(Path.GetTempPath(), "remsound-apploopback-probe.txt"); + var sw0 = new StreamWriter(outPath, append: false) { AutoFlush = true }; + void Line(string m) => sw0.WriteLine(m); + ProcessLoopbackCapture.Diagnostic = m => Line($" [{DateTime.Now:HH:mm:ss.fff}] {m}"); + + int pid; + var explicitPid = args.FirstOrDefault(a => int.TryParse(a, out _)); + if (explicitPid is not null) pid = int.Parse(explicitPid); + else + { + var name = Environment.GetEnvironmentVariable("REMSOUND_PROBE_APP"); + var proc = string.IsNullOrWhiteSpace(name) + ? null + : Process.GetProcessesByName(name).FirstOrDefault(); + pid = proc?.Id ?? Environment.ProcessId; + } + + Line($"process-loopback probe: target pid={pid} " + + $"({(pid == Environment.ProcessId ? "SELF (silent)" : SafeName(pid))}), IsSupported={ProcessLoopbackCapture.IsSupported}"); + + var sw = Stopwatch.StartNew(); + long bytes = 0; + Exception? stopError = null; + var stopped = new ManualResetEventSlim(false); + var capture = new ProcessLoopbackCapture(pid); + capture.DataAvailable += (_, e) => Interlocked.Add(ref bytes, e.BytesRecorded); + capture.RecordingStopped += (_, e) => { stopError = e.Exception; stopped.Set(); }; + + Line("starting capture..."); + capture.StartRecording(); + + // Give activation up to 5s to complete or fail, then observe ~2s of data flow. + var settled = stopped.Wait(5000); + var afterActivate = sw.ElapsedMilliseconds; + if (!settled) Thread.Sleep(2000); // capture is live — let some audio flow + var seen = Interlocked.Read(ref bytes); + + Line($"--- after {afterActivate}ms: stopped={settled}, bytesCaptured={seen}, stopError={stopError?.GetType().Name}: {stopError?.Message}"); + + var disposeSw = Stopwatch.StartNew(); + capture.Dispose(); + disposeSw.Stop(); + Line($"dispose took {disposeSw.ElapsedMilliseconds}ms (~2000ms = capture thread was still stuck in activation)"); + Line(seen > 0 ? "RESULT: capture DELIVERED audio" : "RESULT: NO audio captured (activation failed)"); + sw0.Dispose(); + return 0; + } + + private static string SafeName(int pid) + { + try { return Process.GetProcessById(pid).ProcessName; } catch { return "unknown"; } + } +} diff --git a/src/RemSound.App/Program.cs b/src/RemSound.App/Program.cs index 6c6ee12..783d4df 100644 --- a/src/RemSound.App/Program.cs +++ b/src/RemSound.App/Program.cs @@ -87,6 +87,14 @@ internal static class Program return; } + // --probe-apploopback [pid]: temporary focused diagnostic for the per-app-send activation hang. + // Runs the process-loopback activation with full tracing and exits. Not part of the gate. + if (args.Length > 0 && Array.Exists(args, a => string.Equals(a, "--probe-apploopback", StringComparison.OrdinalIgnoreCase))) + { + Environment.ExitCode = ProbeAppLoopback.Run(args); + return; + } + // --config-dir (test / portable isolation): redirect ALL user state - config, // profiles, logs, cue sounds - to an explicit folder for THIS process only. Applied first, // before the layout migration and sound consolidation below read or write the default diff --git a/src/RemSound.App/SelfTest.cs b/src/RemSound.App/SelfTest.cs index ffca329..caba615 100644 --- a/src/RemSound.App/SelfTest.cs +++ b/src/RemSound.App/SelfTest.cs @@ -335,6 +335,7 @@ internal static class SelfTest var pid = Process.GetCurrentProcess().Id; var cycles = 0; + var disposeTimes = new List(); for (var i = 0; i < 3; i++) { var capture = new RemSound.Sender.ProcessLoopbackCapture(pid); @@ -344,7 +345,10 @@ internal static class SelfTest capture.RecordingStopped += (_, e) => stopError = e.Exception; capture.StartRecording(); Thread.Sleep(150); // let activation + the capture loop run and then be torn down + var sw = Stopwatch.StartNew(); capture.Dispose(); // teardown while the capture thread is live — the crash scenario + sw.Stop(); + disposeTimes.Add(sw.ElapsedMilliseconds); // Activation MUST have succeeded. This is the regression guard for the E_NOINTERFACE cast on // IActivateAudioInterfaceAsyncOperation that silently killed every per-app capture: it was @@ -356,7 +360,13 @@ internal static class SelfTest return $"process-loopback activation failed: {stopError.GetType().Name}: {stopError.Message}"; cycles++; } - return $"ran {cycles} start/stop/dispose cycles on pid {pid}; activation clean, no crash"; + // Activation must also be FAST. A dispose that takes ~2s means the capture thread was still stuck + // waiting on activation 150ms after start (StopRecording's thread-join times out at 2s) — per-app + // capture "working" but starting seconds late is still broken from the user's chair, and this is + // exactly how the completion-never-arrives regression looks when a retry happens to save it. + var worst = disposeTimes.Max(); + Check(worst < 1000, $"activation too slow — a dispose took {worst}ms, meaning the capture thread was still activating long after start (dispose times: {string.Join(", ", disposeTimes)}ms)"); + return $"ran {cycles} start/stop/dispose cycles on pid {pid}; activation clean + prompt (dispose {string.Join("/", disposeTimes)}ms), no crash"; } /// Soak test for runtime lifecycle transitions — the class of bug that hard-crashed when Ed diff --git a/src/RemSound.Sender/ProcessLoopbackCapture.cs b/src/RemSound.Sender/ProcessLoopbackCapture.cs index d48b34a..c078784 100644 --- a/src/RemSound.Sender/ProcessLoopbackCapture.cs +++ b/src/RemSound.Sender/ProcessLoopbackCapture.cs @@ -67,6 +67,10 @@ public sealed class ProcessLoopbackCapture : IWaveIn /// e.g. the send-mode UI that crashed at launch on Win7 (issue #22). Null = use the real OS check. internal static bool? ForceSupportedForTest; + /// Diagnostic sink for activation-path tracing (hr codes, callback delivery, timing). Static + /// so a probe can wire it without touching every construction site. Null = no tracing. + internal static Action? Diagnostic; + /// True on Windows builds new enough for the process-loopback API (10.0.19041+). public static bool IsSupported => ForceSupportedForTest ?? OperatingSystem.IsWindowsVersionAtLeast(10, 0, 19041); @@ -138,21 +142,20 @@ public sealed class ProcessLoopbackCapture : IWaveIn propVariant.blobSize = (uint)paramsSize; propVariant.blobData = paramsPtr; - var handler = new ActivationHandler(); var iidAudioClient = typeof(IAudioClient).GUID; - // The out operation is taken as a raw pointer, NOT the typed interface: the eager RCW cast of a - // context-bound operation object is exactly what threw InvalidCastException / E_NOINTERFACE in - // the field and killed every specific-app capture ("foobar2000 sends no audio"). We don't need - // the operation object — the completion handler carries the result — so just hold and release - // the reference. + var handler = new ActivationHandler(); + // The out operation is taken as a raw pointer, NOT the typed interface: casting the not-yet- + // completed operation object threw here. We don't need it — the completion handler carries the + // result — so just hold and release the reference. var opPtr = IntPtr.Zero; try { var hr = ActivateAudioInterfaceAsync(VirtualDevicePath, ref iidAudioClient, ref propVariant, handler, out opPtr); + Diagnostic?.Invoke($"activate: ActivateAudioInterfaceAsync hr=0x{hr:X8} for pid {targetPid}"); if (hr != 0) Marshal.ThrowExceptionForHR(hr); if (!handler.Completed.WaitOne(3000)) - throw new TimeoutException("Process-loopback activation timed out."); + throw new TimeoutException("Process-loopback activation timed out (completion callback never arrived)."); if (handler.ActivateResult != 0) Marshal.ThrowExceptionForHR(handler.ActivateResult); audioClient = (IAudioClient)handler.Interface!; @@ -276,6 +279,16 @@ public sealed class ProcessLoopbackCapture : IWaveIn // ---- Async activation completion handler ------------------------------------------------- + // Completion handler for ActivateAudioInterfaceAsync. TWO things here are load-bearing and were the + // reason per-app capture NEVER worked on any machine (activation always "timed out"): + // 1. ActivateCompleted takes the operation as a raw IntPtr, NOT the typed + // IActivateAudioInterfaceAsyncOperation. Typing it made the CLR QueryInterface the operation as + // the call was delivered; that QI returns E_NOINTERFACE, and it fails INSIDE the interop stub — + // before our method body — so the whole callback was silently dropped and the wait timed out. + // 2. We read the result by calling GetActivateResult through the vtable directly (see below) rather + // than casting the pointer to our interface — the same QI that fails in (1). + // The callback is delivered on an MTA worker thread; a plain WaitOne on the activation thread catches + // it. (Apartment-agility via IAgileObject was tried and is NOT required — removed to avoid confusion.) [ComVisible(true)] private sealed class ActivationHandler : IActivateAudioInterfaceCompletionHandler { @@ -283,20 +296,36 @@ public sealed class ProcessLoopbackCapture : IWaveIn public int ActivateResult { get; private set; } = unchecked((int)0x80004005); // E_FAIL until proven otherwise public object? Interface { get; private set; } - public void ActivateCompleted(IActivateAudioInterfaceAsyncOperation activateOperation) + [UnmanagedFunctionPointer(CallingConvention.StdCall)] + private delegate int GetActivateResultDelegate(IntPtr self, out int activateResult, out IntPtr activatedInterface); + + public void ActivateCompleted(IntPtr activateOperation) { + Diagnostic?.Invoke($"ActivateCompleted ENTERED on thread apartment={Thread.CurrentThread.GetApartmentState()}, op={(activateOperation == IntPtr.Zero ? "null" : "set")}"); + var ifacePtr = IntPtr.Zero; try { - activateOperation.GetActivateResult(out var hr, out var iface); - ActivateResult = hr; - Interface = iface; + // The pointer we're handed ALREADY IS an IActivateAudioInterfaceAsyncOperation* (that's the + // API contract) — do NOT QueryInterface it (that QI returns E_NOINTERFACE here, cross-proxy). + // Call GetActivateResult directly through vtable slot 3 (after IUnknown's 3 slots). + var vtbl = Marshal.ReadIntPtr(activateOperation); + var fnPtr = Marshal.ReadIntPtr(vtbl, 3 * IntPtr.Size); + var getResult = Marshal.GetDelegateForFunctionPointer(fnPtr); + var callHr = getResult(activateOperation, out var activateHr, out ifacePtr); + if (callHr != 0) { ActivateResult = callHr; Diagnostic?.Invoke($"ActivateCompleted: GetActivateResult call failed hr=0x{callHr:X8}"); return; } + ActivateResult = activateHr; + if (activateHr == 0 && ifacePtr != IntPtr.Zero) + Interface = Marshal.GetTypedObjectForIUnknown(ifacePtr, typeof(IAudioClient)); + Diagnostic?.Invoke($"ActivateCompleted: activateHr=0x{activateHr:X8}, iface={(ifacePtr == IntPtr.Zero ? "null" : "got")}"); } catch (Exception ex) { ActivateResult = ex.HResult != 0 ? ex.HResult : unchecked((int)0x80004005); + Diagnostic?.Invoke($"ActivateCompleted: THREW {ex.GetType().Name}: {ex.Message} (hr=0x{ActivateResult:X8})"); } finally { + if (ifacePtr != IntPtr.Zero) Marshal.Release(ifacePtr); // GetTypedObjectForIUnknown took its own ref Completed.Set(); } } @@ -343,19 +372,20 @@ public sealed class ProcessLoopbackCapture : IWaveIn // ---- COM interfaces (declared in vtable order — DO NOT reorder methods) ----------------------- -[ComImport, Guid("72A22D78-CDE4-4B31-B8CC-843A71199B6D"), - InterfaceType(ComInterfaceType.InterfaceIsIUnknown)] -internal interface IActivateAudioInterfaceAsyncOperation -{ - void GetActivateResult(out int activateResult, - [MarshalAs(UnmanagedType.IUnknown)] out object activatedInterface); -} +// NB: IActivateAudioInterfaceAsyncOperation is deliberately NOT declared as a managed interface — its +// GetActivateResult is invoked through the vtable directly in ActivationHandler.ActivateCompleted, +// because QueryInterface-ing the operation pointer to a managed interface returns E_NOINTERFACE here. [ComImport, Guid("41D949AB-9862-444A-80F6-C261334DA5EB"), InterfaceType(ComInterfaceType.InterfaceIsIUnknown)] internal interface IActivateAudioInterfaceCompletionHandler { - void ActivateCompleted(IActivateAudioInterfaceAsyncOperation activateOperation); + // The operation is taken as a RAW pointer, NOT the typed interface. Typing it made the CLR marshal + // (QueryInterface) the operation object as the call was delivered; that QI returns E_NOINTERFACE + // here, and the failure happened INSIDE the interop stub — before our method body — so the callback + // was silently dropped and activation always "timed out". With IntPtr the stub marshals nothing, the + // method runs, and we QI the operation ourselves on this (the delivery) thread. + void ActivateCompleted(IntPtr activateOperation); } [ComImport, Guid("1CB9AD4C-DBFA-4C32-B178-C2F568A703B2"),