Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Possible issue with accessing audio inputs under Windows 11 Pro and Enterprise #50

Open
bluebrook-sean opened this issue Jun 24, 2024 · 20 comments
Labels
bug Something isn't working help wanted Extra attention is needed

Comments

@bluebrook-sean
Copy link

I have a use case experience that may (?) suggest an additional step when setting up a service wrapper under Windows 11, perhaps due to a change in permissions management. I don't work in Windows IT, and apologize if I've just missed something that should be obvious about how to use Windows 11.

I have desktop Windows software that processes audio inputs, and I'm using it for archiving two-way radio communications. In some contexts, it needs to run without a Windows user logged in, so (about a decade ago) I added XYNT as a wrapper. With Windows 11 Pro and Enterprise, the software in service mode sees the audio ports but with zero levels (but it works in desktop mode). My impression is that this is related to a change in Windows audio permissions, because the zero level symptom matches expected behavior when permissions have not been granted. I'd think LocalSystem would have permissions to do nearly anything, and I've found no way to access permissions for this user.

Because of this problem, I tried alternatives to XYNT, including shawl and Fire Daemon Pro (FDP). With FDP it works (out of the box, no special configurations entered), so I believe it is possible for a wrapper to support or enable access to audio. With shawl, I see the same symptom as under XYNT. Surprisingly, this is true even when launching the service under a Windows user where the desktop software has been granted audio input (called microphone, even when it's not a mic) permissions. I feel Windows 11 has introduced some kind of obstacle to service mode audio access, and based on my experience with FDP, overcoming this issue may be an additional step to be done in the wrapper.

Shawl is my preference going forward over XYNT (maintained - XYNT is 12 years old) and FDP (shawl is lightweight, easier to integrate). But right now I have not found a way to make this work (have the software see audio levels while running under shawl on these versions of Windows 11).

@mtkennerly
Copy link
Owner

mtkennerly commented Jun 25, 2024

Hi! Do you have the code for the radio archival program? I'm curious what APIs it's using to check the system volume.

I did a quick test, and it works for me with a service running as Local System, although I'm using Windows 11 Home and I'm logged in at the same time. Do you think it's specific to Pro and Enterprise? Does it make any difference for you if you're logged in vs logged out while the service is running?

Here's the program I used for testing. Could you give it a try, just to rule out anything specific to your archival program? It's a modified version of the shawl-child test program from this repo:

shawl-child-issue-50.zip

Set up: shawl.exe add --name shawl-audio -- C:\path\to\shawl-child.exe

For transparency, it has these changes:

diff --git a/Cargo.toml b/Cargo.toml
index ef8c291..94b09b5 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -16,6 +16,7 @@ dunce = "1.0.4"
 flexi_logger = "0.27.3"
 log = "0.4.20"
 winapi = { version = "0.3.9", features = ["consoleapi", "errhandlingapi", "winbase", "wincon"] }
+windows = { version = "0.57.0", features = ["Win32_Media_Audio", "Win32_Media_Audio_Endpoints", "Win32_System_Com"] }
 windows-service = "0.6.0"

 [dev-dependencies]
diff --git a/src/bin/shawl-child.rs b/src/bin/shawl-child.rs
index c08aebb..965adee 100644
--- a/src/bin/shawl-child.rs
+++ b/src/bin/shawl-child.rs
@@ -48,6 +48,31 @@ fn prepare_logging() -> Result<(), Box<dyn std::error::Error>> {
     Ok(())
 }

+fn get_volume() -> windows::core::Result<f32> {
+    use windows::Win32::{
+        Media::Audio::{
+            eConsole, eRender, Endpoints::IAudioEndpointVolume, IMMDeviceEnumerator,
+            MMDeviceEnumerator,
+        },
+        System::Com::{
+            CoCreateInstance, CoInitializeEx, CLSCTX_ALL, CLSCTX_INPROC_SERVER,
+            COINIT_APARTMENTTHREADED,
+        },
+    };
+
+    unsafe {
+        CoInitializeEx(None, COINIT_APARTMENTTHREADED).ok()?;
+        let device_enumerator: IMMDeviceEnumerator =
+            CoCreateInstance(&MMDeviceEnumerator, None, CLSCTX_INPROC_SERVER)?;
+        let device = device_enumerator.GetDefaultAudioEndpoint(eRender, eConsole)?;
+
+        let endpoint_volume: IAudioEndpointVolume = device.Activate(CLSCTX_ALL, None)?;
+        let volume = endpoint_volume.GetMasterVolumeLevel()?;
+
+        Ok(volume)
+    }
+}
+
 fn main() -> Result<(), Box<dyn std::error::Error>> {
     prepare_logging()?;
     info!("********** LAUNCH **********");
@@ -80,7 +105,7 @@ fn main() -> Result<(), Box<dyn std::error::Error>> {

     while running.load(std::sync::atomic::Ordering::SeqCst) {
         std::thread::sleep(std::time::Duration::from_millis(500));
-        info!("Looping!");
+        info!("Volume: {:?}", get_volume());
     }

     info!("End");

And here's an excerpt of the log output from the service (0.0 is max volume, -65.25 is min volume):

2024-06-24 23:03:39 [DEBUG] stderr: "[INFO] Volume: Ok(-15.164473)"
2024-06-24 23:03:48 [DEBUG] stderr: "[INFO] Volume: Ok(-28.66002)"
2024-06-24 23:03:49 [DEBUG] stderr: "[INFO] Volume: Ok(-30.776678)"
2024-06-24 23:03:52 [DEBUG] stderr: "[INFO] Volume: Ok(-65.25)"
2024-06-24 23:03:57 [DEBUG] stderr: "[INFO] Volume: Ok(0.0)"
2024-06-24 23:03:57 [DEBUG] stderr: "[INFO] Volume: Ok(-11.885729)"

@bluebrook-sean
Copy link
Author

Taking a look at the code (on the audio capture program), I think it's using WinMM. Doing a quick search on that, apparently this is deprecated in Windows 11, so that might be a cause (although it does work outside service mode). The problem seems to be specific to Pro and Enterprise, I believe it works on Home.

Yes, it does matter if logged in/out - my impression is that the service mode instance running under LocalSystem sees audio levels if the PC is logged into a Windows account that has authorized permissions for microphone access (even though the instance is not running under the logged in user account!) This complicated isolating the problem, because testing in service mode worked fine when logged in and looking at performance; it was only upon a reboot (so there was no logged in user) that it reverted to not working. (I have not tried logging out without a reboot.)

I have access to a PC with Pro where I can do testing, and I'll try out your test program tomorrow.

@bluebrook-sean
Copy link
Author

I tried shawl-audio yesterday on the Windows 11 Pro system. So I could test without a Windows login, I set the service to delayed start through Windows Services properties.

The logs showed a constant audio value of -15.0 under all conditions. I grepped the logs and verified that no other values were ever recorded.

I should note this PC has four audio inputs, and I don't know which input shawl-audio was sampling. Because of that, the most revealing test was while logged into a Windows user account, viewing the audio input levels in Windows Sound (recording tab). I triggered a configuration action that makes all four audio sources generate white noise for several seconds for level calibration, and I could see the audio levels change in Windows Sound. But the shawl-audio logs showed only -15.0, despite the sample period (about 2x/second) being fast enough that it should have picked up on the increased audio levels.

I would have expected a constant value to be full quiet, and -15.0 is well above that, which I find a confusing symptom. (If the range is -64 to 0, and min/max reflect +/- variation around a zero quiet center level, I assume "zero level" would be -32.)

In my original report, I said that the symptom was the service seeing zero audio levels when no Windows user was logged in. That was too specific a claim. The level calibration step looks for expected changes in audio level, and any constant level would return an "audio not found" error.

Before posting here, I had gotten audio levels through the desktop application being wrapped while logged into a Windows user account. In contrast, shawl-audio didn't seem to see audio under the same conditions. In both cases (my original experiments and the shawl-audio test) the service was running under LocalSystem, and I'm not sure why extending microphone permissions for a specific Windows user in this way would allow one service but not the other. I had extended permissions to desktop applications in that user's microphone privacy settings, and the audio program I'm using has a GUI while shawl does not, perhaps that affects what programs are included in the granted microphone permissions. This observation may not be relevant or useful, but noting since it seems unexpected to me.

@mtkennerly
Copy link
Owner

Sorry, I should clarify that the shawl-child test is checking for the configured system volume (i.e., the Windows volume slider), not necessarily the level of audio that's currently playing. I know that's different from your case, but I wanted to rule out if general audio-related calls would work.

Let me see if I can update the test to check the live audio output level.

@mtkennerly
Copy link
Owner

mtkennerly commented Jun 26, 2024

Okay, here's a better test:

shawl-child-issue-50-v2.zip

It logs both the configured system volume and the current peak output value. It's checking the main/default audio endpoint - I'll try to find out how to check specific input devices. Here's a sample log from playing a brief sound effect:

2024-06-26 10:33:10 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.0 })"
2024-06-26 10:33:11 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 2.0359856e-34 })"
2024-06-26 10:33:11 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.39385164 })"
2024-06-26 10:33:12 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.5367883 })"
2024-06-26 10:33:12 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.0878225 })"
2024-06-26 10:33:13 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.01044412 })"
2024-06-26 10:33:13 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.0018324464 })"
2024-06-26 10:33:14 [DEBUG] stderr: "[INFO] Audio: Ok(Audio { volume: -34.75468, peak: 0.0 })"
Code diff
diff --git a/src/bin/shawl-child.rs b/src/bin/shawl-child.rs
index 965adee..8913c8b 100644
--- a/src/bin/shawl-child.rs
+++ b/src/bin/shawl-child.rs
@@ -48,11 +48,18 @@ fn prepare_logging() -> Result<(), Box<dyn std::error::Error>> {
     Ok(())
 }

-fn get_volume() -> windows::core::Result<f32> {
+#[derive(Debug)]
+struct Audio {
+    volume: f32,
+    peak: f32,
+}
+
+fn get_audio() -> windows::core::Result<Audio> {
     use windows::Win32::{
         Media::Audio::{
-            eConsole, eRender, Endpoints::IAudioEndpointVolume, IMMDeviceEnumerator,
-            MMDeviceEnumerator,
+            eConsole, eRender,
+            Endpoints::{IAudioEndpointVolume, IAudioMeterInformation},
+            IMMDeviceEnumerator, MMDeviceEnumerator,
         },
         System::Com::{
             CoCreateInstance, CoInitializeEx, CLSCTX_ALL, CLSCTX_INPROC_SERVER,
@@ -69,7 +76,10 @@ fn get_volume() -> windows::core::Result<f32> {
         let endpoint_volume: IAudioEndpointVolume = device.Activate(CLSCTX_ALL, None)?;
         let volume = endpoint_volume.GetMasterVolumeLevel()?;

-        Ok(volume)
+        let meter: IAudioMeterInformation = device.Activate(CLSCTX_ALL, None)?;
+        let peak = meter.GetPeakValue()?;
+
+        Ok(Audio { volume, peak })
     }
 }

@@ -105,7 +115,7 @@ fn main() -> Result<(), Box<dyn std::error::Error>> {

     while running.load(std::sync::atomic::Ordering::SeqCst) {
         std::thread::sleep(std::time::Duration::from_millis(500));
-        info!("Volume: {:?}", get_volume());
+        info!("Audio: {:?}", get_audio());
     }

     info!("End");

@mtkennerly
Copy link
Owner

One more version 😅 This one logs the default input and output audio device volume/level for multiple categories.

shawl-child-issue-50-v3.zip

[INFO] Audio: Ok({"input-console": Audio { volume: 18.0, peak: 0.0 }, "input-multimedia": Audio { volume: 18.0, peak: 0.0 }, "input-communications": Audio { volume: 0.0, peak: 0.0 }, "output-console": Audio { volume: -34.75468, peak: 0.0061646323 }, "output-multimedia": Audio { volume: -34.75468, peak: 0.0061646323 }, "output-communications": Audio { volume: -34.75468, peak: 0.0061646323 }})

Windows documentation for the categories:

  • Console: "Games, system notification sounds, and voice commands."
  • Multimedia: "Music, movies, narration, and live music recording."
  • Communications: "Voice communications (talking to another person)."
Code diff
diff --git a/src/bin/shawl-child.rs b/src/bin/shawl-child.rs
index 8913c8b..948622d 100644
--- a/src/bin/shawl-child.rs
+++ b/src/bin/shawl-child.rs
@@ -1,3 +1,5 @@
+use std::collections::HashMap;
+
 use log::info;
 
 use clap::Parser;
@@ -48,16 +50,18 @@ fn prepare_logging() -> Result<(), Box<dyn std::error::Error>> {
     Ok(())
 }
 
+type DeviceAudio = HashMap<String, Audio>;
+
 #[derive(Debug)]
 struct Audio {
     volume: f32,
     peak: f32,
 }
 
-fn get_audio() -> windows::core::Result<Audio> {
+fn get_audio() -> windows::core::Result<DeviceAudio> {
     use windows::Win32::{
         Media::Audio::{
-            eConsole, eRender,
+            eConsole, eRender, eCapture, eCommunications, eMultimedia,
             Endpoints::{IAudioEndpointVolume, IAudioMeterInformation},
             IMMDeviceEnumerator, MMDeviceEnumerator,
         },
@@ -71,15 +75,29 @@ fn get_audio() -> windows::core::Result<Audio> {
         CoInitializeEx(None, COINIT_APARTMENTTHREADED).ok()?;
         let device_enumerator: IMMDeviceEnumerator =
             CoCreateInstance(&MMDeviceEnumerator, None, CLSCTX_INPROC_SERVER)?;
-        let device = device_enumerator.GetDefaultAudioEndpoint(eRender, eConsole)?;
 
-        let endpoint_volume: IAudioEndpointVolume = device.Activate(CLSCTX_ALL, None)?;
-        let volume = endpoint_volume.GetMasterVolumeLevel()?;
+        let mut out = HashMap::<String, Audio>::new();
+
+        for (label, dataflow, role) in [
+            ("output-console", eRender, eConsole),
+            ("output-multimedia", eRender, eMultimedia),
+            ("output-communications", eRender, eCommunications),
+            ("input-console", eCapture, eConsole),
+            ("input-multimedia", eCapture, eMultimedia),
+            ("input-communications", eCapture, eCommunications),
+        ] {
+            let device = device_enumerator.GetDefaultAudioEndpoint(dataflow, role)?;
 
-        let meter: IAudioMeterInformation = device.Activate(CLSCTX_ALL, None)?;
-        let peak = meter.GetPeakValue()?;
+            let endpoint_volume: IAudioEndpointVolume = device.Activate(CLSCTX_ALL, None)?;
+            let volume = endpoint_volume.GetMasterVolumeLevel()?;
+
+            let meter: IAudioMeterInformation = device.Activate(CLSCTX_ALL, None)?;
+            let peak = meter.GetPeakValue()?;
+
+            out.insert(label.to_string(), Audio { volume, peak });
+        }
 
-        Ok(Audio { volume, peak })
+        Ok(out)
     }
 }

@bluebrook-sean
Copy link
Author

bluebrook-sean commented Jul 2, 2024

From testing, my impression is that the problem is specific to the Windows Multimedia winmm API. If I'm reading correctly, your shawl-audio test code is using the Windows Core Audio API, and appears to work (more below). There's a rumor that the Windows Multimedia API is deprecated in Windows 11, but I don't know where to verify that claim. The test using FDP shows it is possible to use winmm in service mode on Windows 11 Pro, but if deprecated, it's likely not important to support.

I changed the test environment to have a single audio input, making it easier to be sure of what level changes are expected.
Copied below is part of a sample log from shawl-audio test version v3 when there was a calibration test making the audio source generate white noise for a few seconds. The test was after a reboot, with no Windows user logged in.

The input volume is reported as 30.0 consistently during this sample, while peak varies between 0 and 0.5, so I wonder if volume and peak are reversed in the capture or logging. The changes in the reported peak (low/high/low) are consistent with the expected pattern of audio level changes during the calibration test. I see -15.0 for the audio output, so I think my report of constant audio from shawl-audio v1 was seeing the output, not the input.

2024-06-26 12:52:54 [DEBUG] stderr: "[INFO] Audio: Ok({"input-multimedia": Audio { volume: 30.0, peak: 0.0019836426 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.0019836426 }, "input-console": Audio { volume: 30.0, peak: 0.0019836426 }, "output-console": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:54 [DEBUG] stderr: "[INFO] Audio: Ok({"input-communications": Audio { volume: 30.0, peak: 0.0019836426 }, "input-console": Audio { volume: 30.0, peak: 0.0019836426 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.0019836426 }})"
2024-06-26 12:52:55 [DEBUG] stderr: "[INFO] Audio: Ok({"output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.0024719238 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.0024719238 }, "input-communications": Audio { volume: 30.0, peak: 0.0024719238 }})"
2024-06-26 12:52:55 [DEBUG] stderr: "[INFO] Audio: Ok({"input-console": Audio { volume: 30.0, peak: 0.0027770996 }, "input-multimedia": Audio { volume: 30.0, peak: 0.0027770996 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.0027770996 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:56 [DEBUG] stderr: "[INFO] Audio: Ok({"input-console": Audio { volume: 30.0, peak: 0.0020446777 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.0020446777 }, "input-communications": Audio { volume: 30.0, peak: 0.0020446777 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:56 [DEBUG] stderr: "[INFO] Audio: Ok({"output-console": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.002105713 }, "input-communications": Audio { volume: 30.0, peak: 0.002105713 }, "input-multimedia": Audio { volume: 30.0, peak: 0.002105713 }})"
2024-06-26 12:52:57 [DEBUG] stderr: "[INFO] Audio: Ok({"input-console": Audio { volume: 30.0, peak: 0.002960205 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.002960205 }, "input-communications": Audio { volume: 30.0, peak: 0.002960205 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:57 [DEBUG] stderr: "[INFO] Audio: Ok({"input-console": Audio { volume: 30.0, peak: 0.0024108887 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.0024108887 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.0024108887 }, "output-console": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:58 [DEBUG] stderr: "[INFO] Audio: Ok({"output-console": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.0016479492 }, "input-multimedia": Audio { volume: 30.0, peak: 0.001739502 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.001739502 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:58 [DEBUG] stderr: "[INFO] Audio: Ok({"output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.43878174 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.43878174 }, "input-console": Audio { volume: 30.0, peak: 0.43878174 }, "output-console": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:52:59 [DEBUG] stderr: "[INFO] Audio: Ok({"input-multimedia": Audio { volume: 30.0, peak: 0.442688 }, "input-communications": Audio { volume: 30.0, peak: 0.442688 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.442688 }})"
2024-06-26 12:52:59 [DEBUG] stderr: "[INFO] Audio: Ok({"input-multimedia": Audio { volume: 30.0, peak: 0.43798828 }, "input-communications": Audio { volume: 30.0, peak: 0.43798828 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.43798828 }})"
2024-06-26 12:53:00 [DEBUG] stderr: "[INFO] Audio: Ok({"input-console": Audio { volume: 30.0, peak: 0.43969727 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.43969727 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.43969727 }})"
2024-06-26 12:53:00 [DEBUG] stderr: "[INFO] Audio: Ok({"output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.44232178 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.44232178 }, "input-multimedia": Audio { volume: 30.0, peak: 0.44232178 }})"
2024-06-26 12:53:01 [DEBUG] stderr: "[INFO] Audio: Ok({"input-multimedia": Audio { volume: 30.0, peak: 0.4401245 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.4401245 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.4401245 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:53:01 [DEBUG] stderr: "[INFO] Audio: Ok({"output-console": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.45022583 }, "input-multimedia": Audio { volume: 30.0, peak: 0.45022583 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.45022583 }})"
2024-06-26 12:53:02 [DEBUG] stderr: "[INFO] Audio: Ok({"output-console": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.44198608 }, "input-communications": Audio { volume: 30.0, peak: 0.44198608 }, "input-console": Audio { volume: 30.0, peak: 0.44198608 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:53:02 [DEBUG] stderr: "[INFO] Audio: Ok({"output-communications": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.44122314 }, "input-multimedia": Audio { volume: 30.0, peak: 0.44122314 }, "input-communications": Audio { volume: 30.0, peak: 0.44122314 }})"
2024-06-26 12:53:03 [DEBUG] stderr: "[INFO] Audio: Ok({"input-console": Audio { volume: 30.0, peak: 0.4373474 }, "input-multimedia": Audio { volume: 30.0, peak: 0.4373474 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.4373474 }})"
2024-06-26 12:53:03 [DEBUG] stderr: "[INFO] Audio: Ok({"output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.0024108887 }, "input-multimedia": Audio { volume: 30.0, peak: 0.0024108887 }, "input-communications": Audio { volume: 30.0, peak: 0.0024108887 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:53:04 [DEBUG] stderr: "[INFO] Audio: Ok({"output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-multimedia": Audio { volume: 30.0, peak: 0.002532959 }, "input-console": Audio { volume: 30.0, peak: 0.002532959 }, "input-communications": Audio { volume: 30.0, peak: 0.002532959 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:53:04 [DEBUG] stderr: "[INFO] Audio: Ok({"input-multimedia": Audio { volume: 30.0, peak: 0.001739502 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.001739502 }, "input-console": Audio { volume: 30.0, peak: 0.001739502 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }})"
2024-06-26 12:53:05 [DEBUG] stderr: "[INFO] Audio: Ok({"input-multimedia": Audio { volume: 30.0, peak: 0.0018005371 }, "output-communications": Audio { volume: -15.0, peak: 0.0 }, "input-communications": Audio { volume: 30.0, peak: 0.0018005371 }, "output-console": Audio { volume: -15.0, peak: 0.0 }, "output-multimedia": Audio { volume: -15.0, peak: 0.0 }, "input-console": Audio { volume: 30.0, peak: 0.0018005371 }})"

@mtkennerly
Copy link
Owner

I wonder if volume and peak are reversed in the capture or logging

That's just what it's called in the Windows API calls I was using. "Volume" is the system volume slider configuration, and "peak value" is the loudness of the current playing audio. It threw me off at first too.

From testing, my impression is that the problem is specific to the Windows Multimedia winmm API. If I'm reading correctly, your shawl-audio test code is using the Windows Core Audio API, and appears to work (more below).

Gotcha, at least we've ruled out it being an issue with all audio in general 👍

I'm not familiar with the WinMM API and haven't found a good guide so far. Do you know which specific API calls the audio capture program is using to check the audio level? If you do, I can try adding the same calls in the shawl-child test.

@bluebrook-sean
Copy link
Author

The API calls are using mciSendStringA, which is documented here: (the A suffix is for an ANSI implementation)

https://learn.microsoft.com/en-us/previous-versions/dd757161(v=vs.85)

And the Windows Multimedia commands that can be sent via mciSendStringA are documented here:

https://learn.microsoft.com/en-us/windows/win32/multimedia/multimedia-command-strings?redirectedfrom=MSDN

The series of commands sent via mciSendStringA appears to be: ("arbitrary" = user specified name for an opened instance)

open new type waveaudio alias arbitrary
set arbitrary bitspersample 16 channels 1 alignment 2 samplespersec 22050 format tag pcm wait
status arbitrary level
close arbitrary

The first two initialize, then status can be periodically sampled with the instance left open, and close on program exit.

The full code also runs additional mciSendStringA commands to select a specific audio input, and to save audio to file. The step of selecting an audio input is optional, and uses a default Windows selection if not specified, which seems fine for testing.

Aside from mciSendStringA, there is one other winmm action the code takes, which I think is working: waveInGetNumDevs

https://learn.microsoft.com/en-us/windows/win32/api/mmeapi/nf-mmeapi-waveingetnumdevs?redirectedfrom=MSDN

When diagnosing the issue originally, I believe I observed that the correct number of audio inputs were detected, but auto detection of the correct audio input was failing (this is done with the calibration process commanding a particular input to generate a pattern of white noise, and then recognizing the pattern from sampling audio levels on all audio inputs). This is why I had interpreted this as a possible permissions issue, since my understanding of Windows 11 privacy is that when software does not have permission to access a microphone, the audio input appears to exist but audio levels are silent. But for testing winmm, waveInGetNumdevices makes an interesting contrast, because getting an accurate count of audio devices implies that winmm itself is accessible and responding, the problem would be deeper in the audio system. If winmm was deprecated by Microsoft, I wonder if winmm may not be interfacing correctly with modified microphone permission logic in Windows 11?

@mtkennerly
Copy link
Owner

Thanks, that helped! Here's a test using mciSendStringA:

shawl-child-issue-50-v4.zip

Sample output (for mci-status, the message starts with the level, like 31 when it was quiet or 4220 when it was loud):

[INFO] [mci-open] code: 0, message: Ok("1\0\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-set] code: 0, message: Ok("\0\0\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("1\0\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("1\0\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("31\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("24\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("59\0\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("250\0\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("4220\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("2079\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("1978\0\0\0\0\0\0\0\0")
[INFO] [mci-status] code: 0, message: Ok("238\0\0\0\0\0\0\0\0\0")
[INFO] [mci-close] code: 0, message: Ok("\0\0\0\0\0\0\0\0\0\0\0\0")
Diff
diff --git a/Cargo.toml b/Cargo.toml
index 94b09b5..8dba5ca 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -16,7 +16,7 @@ dunce = "1.0.4"
 flexi_logger = "0.27.3"
 log = "0.4.20"
 winapi = { version = "0.3.9", features = ["consoleapi", "errhandlingapi", "winbase", "wincon"] }
-windows = { version = "0.57.0", features = ["Win32_Media_Audio", "Win32_Media_Audio_Endpoints", "Win32_System_Com"] }
+windows = { version = "0.57.0", features = ["Win32_Media_Audio", "Win32_Media_Audio_Endpoints", "Win32_Media_Multimedia", "Win32_System_Com"] }
 windows-service = "0.6.0"
 
 [dev-dependencies]
diff --git a/src/bin/shawl-child.rs b/src/bin/shawl-child.rs
index 948622d..9b5a457 100644
--- a/src/bin/shawl-child.rs
+++ b/src/bin/shawl-child.rs
@@ -1,6 +1,7 @@
 use std::collections::HashMap;
 
 use log::info;
+use windows::core::s;
 
 use clap::Parser;
 
@@ -101,6 +102,27 @@ fn get_audio() -> windows::core::Result<DeviceAudio> {
     }
 }
 
+unsafe fn mci_send_string(label: &str, input: windows::core::PCSTR) -> Result<(), String> {
+    use windows::Win32::Media::Multimedia::mciSendStringA;
+
+    let mut buffer = [0; 12];
+
+    let code = mciSendStringA(
+        input,
+        Some(&mut buffer),
+        windows::Win32::Foundation::HWND::default(),
+    );
+
+    let message = String::from_utf8(buffer.to_vec());
+
+    log::info!("[mci-{label}] code: {code}, message: {message:?}");
+    if code == 0 {
+        Ok(())
+    } else {
+        Err(format!("[mci-{label}] code: {code}"))
+    }
+}
+
 fn main() -> Result<(), Box<dyn std::error::Error>> {
     prepare_logging()?;
     info!("********** LAUNCH **********");
@@ -131,9 +153,20 @@ fn main() -> Result<(), Box<dyn std::error::Error>> {
         }
     })?;
 
+    unsafe {
+        mci_send_string("open", s!("open new type waveaudio alias arbitrary"))?;
+        mci_send_string("set", s!("set arbitrary bitspersample 16 channels 1 alignment 2 samplespersec 22050 format tag pcm wait"))?;
+    }
+
     while running.load(std::sync::atomic::Ordering::SeqCst) {
-        std::thread::sleep(std::time::Duration::from_millis(500));
-        info!("Audio: {:?}", get_audio());
+        std::thread::sleep(std::time::Duration::from_millis(250));
+        unsafe {
+            mci_send_string("status", s!("status arbitrary level"))?;
+        }
+    }
+
+    unsafe {
+        mci_send_string("close", s!("close arbitrary"))?;
     }
 
     info!("End");

@mtkennerly
Copy link
Owner

@bluebrook-sean Hey, just wanted to follow up and see if you've had a chance to try the v4 test?

@bluebrook-sean
Copy link
Author

Yes. I had inconsistent and inexplicable problems with Windows audio, sometimes even in normal Desktop via Windows Sound - then found out that others were trying to find solutions on the same PC, and in the process making somewhat random changes to Windows configuration settings to try things. We reinstalled Windows 11 Pro yesterday, and with a clean environment, got clear results.

What I see is consistent zero audio levels in shawl v4 logs after a reboot, until the first Windows UI login, and consistent normal audio levels from that point forward (while logged in, and then even after logging out of Windows) until the next reboot. (Oddly, the first shawl audio reading after a reboot was 1, but 0 after that.) So it seems a Windows login unlocks something, with an effect even outside the scope of the Windows user account.

shawl audio test v4 logs

Across logging into Windows for the first time after a reboot:

2024-07-30 19:53:45 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:46 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:46 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:46 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:46 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:47 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:47 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:47 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:47 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:48 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:48 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:48 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:49 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:49 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:49 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("99\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:50 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("67\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:50 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("60\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:50 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("60\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:50 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("57\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:51 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("43\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:51 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("71\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:51 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("73\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:51 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("71\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:52 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("94\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:52 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("84\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:52 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("54\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:53 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("50\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:53 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("93\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:53 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("117\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:53 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("63\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:54 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("75\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:54 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("73\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:54 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("57\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 19:53:54 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("60\0\0\0\0\0\0\0\0\0\0")"

After logging out of Windows:

2024-07-30 20:25:12 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("2964\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:12 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("10562\0\0\0\0\0\0\0")"
2024-07-30 20:25:12 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("11755\0\0\0\0\0\0\0")"
2024-07-30 20:25:12 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("8230\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:13 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("5728\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:13 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("27695\0\0\0\0\0\0\0")"
2024-07-30 20:25:13 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("89\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:13 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("364\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:14 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("12102\0\0\0\0\0\0\0")"
2024-07-30 20:25:14 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("11935\0\0\0\0\0\0\0")"
2024-07-30 20:25:14 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("6397\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:14 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("475\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("789\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("12257\0\0\0\0\0\0\0")"
2024-07-30 20:25:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("4669\0\0\0\0\0\0\0\0")"
2024-07-30 20:25:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("270\0\0\0\0\0\0\0\0\0")"

Across a reboot (after logging back into Windows, to trigger the reboot):

2024-07-30 20:39:14 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("133\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("3306\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("3476\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("52\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:15 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("59\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:16 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("13718\0\0\0\0\0\0\0")"
2024-07-30 20:39:16 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("116\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:16 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("85\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:16 [INFO] Received shutdown event
2024-07-30 20:39:16 [INFO] Sending ctrl-C to command
2024-07-30 20:39:16 [DEBUG] stderr: "[INFO] [mci-close] code: 0, message: Ok("\0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:39:16 [DEBUG] stderr: "[INFO] End"
2024-07-30 20:39:17 [INFO] Command exited after 258 ms with code 0
2024-07-30 20:39:17 [DEBUG] Exited main service loop
2024-07-30 20:39:17 [DEBUG] Finished successfully
2024-07-30 20:41:59 [DEBUG] ********** LAUNCH **********
2024-07-30 20:41:59 [DEBUG] Cli { sub: Run { common: CommonOpts { pass: None, restart: false, no_restart: false, restart_if: [], restart_if_not: [], stop_timeout: None, no_log: false, no_log_cmd: false, log_dir: None, log_as: None, log_cmd_as: None, log_rotate: None, log_retain: None, pass_start_args: false, env: [], path: [], priority: None, command: ["C:\Users\rc\Desktop\SENDER\shawl-child.exe"] }, cwd: None, name: "shawl-audio" } }
2024-07-30 20:41:59 [DEBUG] Entering main service loop
2024-07-30 20:41:59 [INFO] Launching command
2024-07-30 20:42:04 [DEBUG] stderr: "[INFO] ********** LAUNCH **********"
2024-07-30 20:42:04 [DEBUG] stderr: "[INFO] Cli { infinite: false, exit: None, test: false }"
2024-07-30 20:42:04 [DEBUG] stderr: "[INFO] PATH: C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0;C:\WINDOWS\System32\OpenSSH;C:\WINDOWS\system32\config\systemprofile\AppData\Local\Microsoft\WindowsApps"
2024-07-30 20:42:04 [DEBUG] stderr: "[INFO] env.SHAWL_FROM_CLI: Err(NotPresent)"
2024-07-30 20:42:04 [DEBUG] stderr: "shawl-child message on stderr"
2024-07-30 20:42:04 [DEBUG] stdout: "shawl-child message on stdout"
2024-07-30 20:42:04 [DEBUG] stderr: "[INFO] [mci-open] code: 0, message: Ok("1\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:05 [DEBUG] stderr: "[INFO] [mci-set] code: 0, message: Ok("\0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:05 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:05 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:05 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:06 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:06 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:06 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:06 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:07 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:07 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:07 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:07 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:08 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:08 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:08 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:08 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:09 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:09 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:09 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:09 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"
2024-07-30 20:42:10 [DEBUG] stderr: "[INFO] [mci-status] code: 0, message: Ok("0\0\0\0\0\0\0\0\0\0\0\0")"

@mtkennerly
Copy link
Owner

Thanks for testing! I get the same behavior on my system, so we have a minimal, consistent test case.

I found a solution that works on my system, if you can give it a try on yours as well. There are two requirements:

  • Shawl has to flag the service as both SERVICE_WIN32_OWN_PROCESS (which it already does) and SERVICE_INTERACTIVE_PROCESS (which it does not).
  • Your program (not Shawl itself) has to be marked as "run this program as an administrator", under file properties -> compatibility.

When I do that, I see the audio levels being logged after a reboot before I log in.

Here's a version of Shawl that sets the SERVICE_INTERACTIVE_PROCESS flag:

shawl-issue-50.zip

If that works for you, I'll make a new release with a CLI flag to enable this behavior.

Diff
diff --git a/src/service.rs b/src/service.rs
index e0ebf47..9bde829 100644
--- a/src/service.rs
+++ b/src/service.rs
@@ -11,7 +11,9 @@ use windows_service::{
     service_dispatcher,
 };

-const SERVICE_TYPE: ServiceType = ServiceType::OWN_PROCESS;
+fn get_service_type() -> ServiceType {
+    ServiceType::OWN_PROCESS | ServiceType::INTERACTIVE_PROCESS
+}

 define_windows_service!(ffi_service_main, service_main);

@@ -124,7 +126,7 @@ pub fn run_service(start_arguments: Vec<std::ffi::OsString>) -> windows_service:
     let status_handle = service_control_handler::register(name, event_handler)?;

     status_handle.set_service_status(ServiceStatus {
-        service_type: SERVICE_TYPE,
+        service_type: get_service_type(),
         current_state: ServiceState::Running,
         controls_accepted: ServiceControlAccept::STOP | ServiceControlAccept::SHUTDOWN,
         exit_code: ServiceExitCode::NO_ERROR,
@@ -248,7 +250,7 @@ pub fn run_service(start_arguments: Vec<std::ffi::OsString>) -> windows_service:
             match shutdown_rx.recv_timeout(std::time::Duration::from_secs(1)) {
                 Ok(_) | Err(std::sync::mpsc::RecvTimeoutError::Disconnected) => {
                     status_handle.set_service_status(ServiceStatus {
-                        service_type: SERVICE_TYPE,
+                        service_type: get_service_type(),
                         current_state: ServiceState::StopPending,
                         controls_accepted: ServiceControlAccept::empty(),
                         exit_code: ServiceExitCode::NO_ERROR,
@@ -363,7 +365,7 @@ pub fn run_service(start_arguments: Vec<std::ffi::OsString>) -> windows_service:
     debug!("Exited main service loop");

     status_handle.set_service_status(ServiceStatus {
-        service_type: SERVICE_TYPE,
+        service_type: get_service_type(),
         current_state: ServiceState::Stopped,
         controls_accepted: ServiceControlAccept::empty(),
         exit_code: service_exit_code,

@bluebrook-sean
Copy link
Author

Unfortunately, I'm not getting good results. I assume the new test shawl.exe doesn't need a CLI flag, I left the service definition unchanged (just replaced shawl.exe with the services stopped).

My first run had our software set to "run this program as an administrator". No success, so I tried doing the same to shawl-child.exe, and verified that the logs look identical to before. (I also checked the shawl.exe file size and creation date to make sure I had actually put the exe file in place.) Then in Properties, I noticed there's a separate control for making such changes for all users, so I tried making the same "run as administrator" change there (for both programs). No change in results.

@mtkennerly
Copy link
Owner

Hmm, that's strange. I'm not sure why it would behave differently on our systems (unless this is the Home vs Pro/Enterprise difference you suspected). Could you also try:

  • Set "run as administrator" for Shawl itself
  • Set the Shawl and shawl-child compatibility mode to Vista
  • In the service properties log on tab, enable the "allow service to interact with desktop" option

Those didn't make a difference in my testing, but it's worth a shot.

@bluebrook-sean
Copy link
Author

Are you using Windows 11 Home?

@mtkennerly
Copy link
Owner

Yes, I don't have a Pro/Enterprise system available to test, unfortunately.

@bluebrook-sean
Copy link
Author

You can experiment with the Win 11 Pro that I'm using, if you want to try things directly. It's a test PC, and it's fine to make changes to anything. The PC has Anydesk as remote desktop software, so I'd have to get you the access code. Also, the person hosting the PC would need to click an accept button to allow a session, so there would be a bit of timing coordination.

@mtkennerly
Copy link
Owner

Sure, that would be a big help. Feel free to send the code using whichever is easier:

Would someone need to be around each time I reboot the system?

@mtkennerly
Copy link
Owner

Hey, sorry this fell off my radar for a while 😅

To be honest, I'm not confident that I can figure out the root cause here. Besides trying different combinations of the executable and service properties, I'm not sure what else to try, and I don't know what internal Windows differences could explain #50 (comment) working on my Windows 11 Home but not your Windows 11 Pro.

If anyone else sees this and wants to give it a try, the bugfix/mci branch can be used for testing, and I'd be happy to review any PRs related to this.

@mtkennerly mtkennerly added help wanted Extra attention is needed bug Something isn't working labels Sep 12, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working help wanted Extra attention is needed
Projects
None yet
Development

No branches or pull requests

2 participants