search

PortAudio / portaudio

PortAudio is a cross-platform, open-source C language library for real-time audio input and output.
Other
1.43k stars 296 forks source link

Playback stopped and not able to continue after Windows hibernate/sleep #944

Closed BLumia closed 1 month ago

BLumia commented 1 month ago

Describe the bug

When a playback stream starts and turns Windows into hibernate/sleep, the playback will be stopped after Windows recovered from a hibernate/sleep.

To Reproduce Steps to reproduce the behavior. Include code if applicable.

  1. Setup a playback stream by using Pa_Initialize, Pa_OpenDefaultStream and Pa_StartStream API, and also register a Pa_SetStreamFinishedCallback callback just in case.
  2. Turn Windows into hibernate/sleep.
  3. Turn Windows back on from hibernate/sleep.
  4. The playback is stopped and no longer continues. If we manually trigger a Pa_IsStreamStopped check, we won't getting any error, the callback registered by Pa_SetStreamFinishedCallback also isn't getting called.

Expected behavior Not sure, but it could be:

  1. Let the program know the stream is stopped via a callback like the one we registered by Pa_SetStreamFinishedCallback API.
  2. Continue the playback stream without any error.

Actual behavior See reproduce step 4. In short, playback stopped with no error, no callback getting called.

Desktop (please complete the following information):

Additional context

Let me know if you need any additional information.

edit (240714 15:51): there's something wrong with my Pa_IsStreamStopped error checking code previously, there are actually no error returns by that API. The description is updated accordingly.

BLumia commented 1 month ago

Some additional information:

  1. beside MME:
    • Windows DirectSound also have the same issue.
    • Windows WASAPI and Windows WDM-KS won't pass the Pa_IsFormatSupported check with a unsupported sample rate error so I didn't check those two. (My sample rate is set to 44100 btw)
  2. after issue happens:
    • Pa_IsStreamStopped returns 0.
    • the callback registered by Pa_SetStreamFinishedCallback isn't getting called.
    • Pa_IsStreamActive also returns 0 instead of 1.
      • If we simply calling Pa_StartStream() when this happened, it won't continue
      • If we redo the whole setup process (Pa_OpenDefaultStream -> Pa_SetStreamFinishedCallback -> Pa_StartStream) then it will work.
BLumia commented 1 month ago

:joy: I feel so dumb now, turns out I did the same mistake while registering Pa_SetStreamFinishedCallback callback by passing PaStream** instead of PaStream* to it, cause the callback isn't actually registered. After correcting this issue, we indeed can get notified when stream is finished, while it seems we cannot redo the whole setup process in that callback.

Since I don't really know the expected behavior, does it still count as a bug? If not, is the intended usage calling the OS specific API to know when the application gets recovered from a hibernation and redo the setup process there?

dmitrykos commented 1 month ago

Since I don't really know the expected behavior, does it still count as a bug?

The expected behavior is to pass pointer to PaStream (PaStream *). Passing anything else is a user-side bug.

If not, is the intended usage calling the OS specific API to know when the application gets recovered from a hibernation and redo the setup process there?

You do not need to reallocate anything after hibernation because OS restores RAM contents from the disk. You need to take care of your timers which will jump if depend on current time but it is unrelated to PA.

BLumia commented 1 month ago

If not, is the intended usage calling the OS specific API to know when the application gets recovered from a hibernation and redo the setup process there?

You do not need to reallocate anything after hibernation because OS restores RAM contents from the disk. You need to take care of your timers which will jump if depend on current time but it is unrelated to PA.

But from the application developer's side, the playback stream is stopped when hibernation/sleep and we don't know when to restart the stream since the stream won't get resumed automatically when Windows is restored from a hibernation/sleep.

Or do you mean the stream also shouldn't stop when the end-user triggers the hibernation/sleep? If so, then it's still likely a PortAudio bug.

dmitrykos commented 1 month ago

I made test with PA WASAPI by making paex_sine.c test playing sine endlessly then hibernated PC and after some time powered it on, test kept playing sine. Therefore, please test hibernation issues with paex_sine.c. For this test you will need to make endless loop here: https://github.com/PortAudio/portaudio/blob/2fa021931944b141302697f0750c3e5484888726/examples/paex_sine.c#L157

like this:

    while (1) {
        Pa_Sleep( NUM_SECONDS * 1000 );
    }

Please make this test and check if you get sound after power on. I you get then check your app, if not then check which PA backend is failing in your case.

the playback stream is stopped when hibernation/sleep

In Win32 app you can detect power state change by catching WM_POWERBROADCAST message in your window event loop, therefore you can process state transition gracefully for your app. Check Microsoft docs: https://learn.microsoft.com/en-us/windows/win32/power/wm-powerbroadcast

BLumia commented 1 month ago

I made test with PA WASAPI by making paex_sine.c test playing sine endlessly then hibernated PC and after some time powered it on, test kept playing sine. Therefore, please test hibernation issues with paex_sine.c.

I made the change you provided, compiled with gcc paex_sine.c `pkg-config --cflags --libs portaudio-2.0` under MSYS2 UCRT environment, and tested. The playback didn't resume after the system is recovered from the hibernation, the output:

$ ./a.exe
PortAudio Test: output sine wave. SR = 44100, BufSize = 64
Play for 5 seconds.
Stream Completed: No Message

Note: I only changed line 157 to the infinite loop you've suggested, so the output still says it will "Play for 5 seconds":

$ sed -n '155,161p' paex_sine.c

    printf("Play for %d seconds.\n", NUM_SECONDS );
    while (1) {
        Pa_Sleep( NUM_SECONDS * 1000 );
    }

    err = Pa_StopStream( stream );

As a reference, when compiling the unchanged example source and run it for more than 5 seconds, the output will be:

$ ./a.exe
PortAudio Test: output sine wave. SR = 44100, BufSize = 64
Play for 5 seconds.
Stream Completed: No Message
Test finished.

Let me know if you need any additional information.

dmitrykos commented 1 month ago

How long did you wait to power on PC?

You got callback triggered that stream was finished that means that some WASAPI objects could report that stream stopped. It can be driver dependent behavior by the way. In your app currently you could use Pa_SetStreamFinishedCallback to detect that stream finished prematurely and schedule its restart if WM_POWERBROADCAST reported power state change.

Let's also check which object breaks rendering loop. Could you compile PA with PA_ENABLE_DEBUG_OUTPUT defined, so that you could also have debug logs in console and re-do your test again.

POI:

https://github.com/PortAudio/portaudio/blob/2fa021931944b141302697f0750c3e5484888726/src/hostapi/wasapi/pa_win_wasapi.c#L6254-L6258

https://github.com/PortAudio/portaudio/blob/2fa021931944b141302697f0750c3e5484888726/src/hostapi/wasapi/pa_win_wasapi.c#L6277-L6281

https://github.com/PortAudio/portaudio/blob/2fa021931944b141302697f0750c3e5484888726/src/hostapi/wasapi/pa_win_wasapi.c#L6290-L6293

PA_ENABLE_DEBUG_OUTPUT shell help to identify which POI broke the loop.

BLumia commented 1 month ago

How long did you wait to power on PC?

When testing, I wait about 5 seconds. Steps are:

  1. run test program
  2. turn system into hibernation, wait until the laptop keyboard backlight is off (and the computer fan is also off at that moment).
  3. wait for a few seconds
  4. press keyboard to wake the system up, which also take about 15 seconds, then login back to the system
  5. see the result

In your app currently you could use Pa_SetStreamFinishedCallback to detect that stream finished prematurely and schedule its restart if WM_POWERBROADCAST reported power state change.

Yeah, agree :)

I'd still like to ask, what's the intended behavior? PA should resume the stream once OS is restored from a hibernation? or the stream shouldn't be stopped in the first place?

Could you compile PA with PA_ENABLE_DEBUG_OUTPUT defined, so that you could also have debug logs in console and re-do your test again.

Sure, following are the result of the test:

Output of $ ccmake build:

                                                     Page 1 of 1
 CMAKE_BUILD_TYPE
 CMAKE_GNUtoMS                    OFF
 CMAKE_INSTALL_PREFIX             C:/Users/Gary/Programs/CMAKE_INSTALL_PREFIX
 PA_BUILD_EXAMPLES                OFF
 PA_BUILD_SHARED_LIBS             OFF
 PA_BUILD_TESTS                   OFF
 PA_ENABLE_DEBUG_OUTPUT           ON
 PA_USE_ASIO                      OFF
 PA_USE_DS                        ON
 PA_USE_SKELETON                  OFF
 PA_USE_WASAPI                    ON
 PA_USE_WDMKS                     ON
 PA_USE_WDMKS_DEVICE_INFO         ON
 PA_USE_WMME                      ON
 PA_WARNINGS_ARE_ERRORS           OFF

Complete log of the modified test program, which I didn't see any extra debug log:

$ ./a.exe
PortAudio Test: output sine wave. SR = 44100, BufSize = 64
Play for 5 seconds.
Stream Completed: No Message

What I did:

  1. Compile portaudio git HEAD version (currently 2fa021931944b141302697f0750c3e5484888726) with $ cmake -Bbuild . -DPA_ENABLE_DEBUG_OUTPUT=ON and $ cmake --build build/ -j4 under MSYS2 UCRT environment
  2. Replace MSYS2's libportaudio.dll with the one built by the previous step
  3. Run the test program mentioned in https://github.com/PortAudio/portaudio/issues/944#issuecomment-2231154029
dmitrykos commented 1 month ago

I'd still like to ask, what's the intended behavior? PA should resume the stream once OS is restored from a hibernation? or the stream shouldn't be stopped in the first place?

On my system stream keeps playing after exit from hibernation, so generally playback shall continue. In your case it stops triggering callback, so it means some WASAPI system object reported error. This behavior is driver dependent, therefore not guaranteed. PA WASAPI can not workaround this and it is better for you to assume such behavior and restart playback once you get callback called and also detect that power state changed.

Complete log of the modified test program, which I didn't see any extra debug log

I think you need to set CMAKE_BUILD_TYPE to value Debug additionally. Would you please retry.

BLumia commented 1 month ago

I think you need to set CMAKE_BUILD_TYPE to value Debug additionally.

Indeed!

Would you please retry.

$ ./a.exe
PortAudio Test: output sine wave. SR = 44100, BufSize = 64
before paHostApiInitializers[0].
getting Windows version with RtlGetVersion(): major=10, minor=0, build=22631, platform=2
Windows version=10
after paHostApiInitializers[0].
before paHostApiInitializers[1].
after paHostApiInitializers[1].
before paHostApiInitializers[2].
WASAPI: device idx: 00
WASAPI: ---------------
WASAPI:0| name[鎵０鍣?(Realtek(R) Audio)]
WASAPI:0| form-factor[1]
WASAPI: IAudioClient version = 3
WASAPI:0| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device idx: 01
WASAPI: ---------------
WASAPI:1| name[P27QBC-RG (NVIDIA High Definition Audio)]
WASAPI:1| form-factor[9]
WASAPI:1| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device idx: 02
WASAPI: ---------------
WASAPI:2| name[楹﹀厠椋庨樀鍒?(Realtek(R) Audio)]
WASAPI:2| form-factor[4]
WASAPI:2| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device list ok - found 5 devices, 2 loopback devices
WASAPI: initialized ok
after paHostApiInitializers[2].
before paHostApiInitializers[3].
PaWinWdm_Initialize {
BuildFilterList {
Setup called
Enum called
noError = 0
Enum called
noError = 1
Device 1 has render alias
Enum called
noError = 0
Enum called
noError = 0
Enum called
noError = 0
Device 4 has capture alias
Enum called
noError = 0
Device 5 has capture alias
Enum called
noError = 1
Device 6 has render alias
Device 6 has capture alias
Enum called
noError = 0
Enum called
noError = 0
Enum called
noError = 0
Enum called
noError = 1
Device 10 has render alias
Enum called
noError = 1
Device 11 has render alias
Device 11 has capture alias
Enum called
Interfaces found: 6
Device 1 has render alias
Device 1 has realtime alias
Interface 1, Name: R
FilterNew: Creating filter 'Realtek HD Audio output'
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=2, nodes=1
  Connection: 0 - FromNode=4294967295,FromPin=0 -> ToNode=0,ToPin=1
  Connection: 1 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=1
  Node: 0 - {507AE360-C554-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
PinNew {
PinNew: Creating pin 0:
PinNew: Checking 1 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 2
PinNew: Format PCM 16 bit supported
PinNew: Format PCM 24 bit supported
PinNew: Format PCM 32 bit supported
PinNew: Default sample rate = 44100 Hz
PinQueryNotificationSupport {
Failed PinQueryNotificationSupport
} PinQueryNotificationSupport
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionTo: Startpin 0, Checking 2 connections...
FindStartConnectionTo: returning 00000000006AD4C8
GetConnectedPin: count=1, forward=1, muxPosition=-1
GetConnectionTo: Checking 2 connections... (pFrom = 00000000006AD4C8)GetConnectionTo: Returning 00000000006AD4D8
PinNew: Getting physical connection...
PinNew: Physical connection found!
PinNew: Creating topology filter '\\?\HDAUDIO#FUNC_01&VEN_10EC&DEV_0236&SUBSYS_17AA391F&REV_1000#4&4128e3&0&0001#{6994ad04-93ef-11d0-a3cc-00a0c9223196}\SingleLineOutTopo'
FilterNew: Creating filter ''
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=3, nodes=2
  Connection: 0 - FromNode=4294967295,FromPin=0 -> ToNode=0,ToPin=1
  Connection: 1 - FromNode=0,FromPin=0 -> ToNode=1,ToPin=1
  Connection: 2 - FromNode=1,FromPin=0 -> ToNode=4294967295,ToPin=1
  Node: 0 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 1 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
FilterRelease {
} FilterRelease
PinNew: Opening topology filter...FilterUse {
} FilterUse
PinNew: Checking for output endpoint pin id...
GetConnectedPin {
FindStartConnectionTo: Startpin 0, Checking 3 connections...
FindStartConnectionTo: returning 00000000006B3318
GetConnectedPin: count=2, forward=1, muxPosition=-1
GetConnectionTo: Checking 3 connections... (pFrom = 00000000006B3318)GetConnectionTo: Returning 00000000006B3328
GetConnectedPin: count=2, forward=1, muxPosition=-1
GetConnectionTo: Checking 3 connections... (pFrom = 00000000006B3328)GetConnectionTo: Returning 00000000006B3338
PinNew: Found endpoint pin id 1
GetNameFromCategory {
GetNameFromCategory: USB GUID 0301 -> 'Speakers'
} GetNameFromCategory
PinNew: Pin name 'Speakers'
PinNew: Releasing topology filter...
FilterRelease {
} FilterRelease
Pin created successfully
} PinNew
PinNew {
PinNew: Creating pin 1:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
FilterRelease {
} FilterRelease
Filter (WaveRT) created with 1 valid pins (total I/Os: 1)
Device 4 has capture alias
Device 4 has realtime alias
Interface 4, Name: R
FilterNew: Creating filter 'Realtek HD Audio Stereo input'
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=2, nodes=1
  Connection: 0 - FromNode=4294967295,FromPin=1 -> ToNode=0,ToPin=1
  Connection: 1 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=0
  Node: 0 - {4D837FE0-C555-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
PinNew {
PinNew: Creating pin 0:
PinNew: Checking 1 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 2
PinNew: Format PCM 16 bit supported
PinNew: Default sample rate = 48000 Hz
PinQueryNotificationSupport {
Failed PinQueryNotificationSupport
} PinQueryNotificationSupport
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionFrom: Startpin 0, Checking 2 connections...
FindStartConnectionFrom: returning 00000000006AD8F8
GetConnectedPin: count=1, forward=0, muxPosition=-1
GetConnectionFrom: Checking 2 connections... (pTo = 00000000006AD8F8)
GetConnectionFrom: Returning 00000000006AD8E8
PinNew: Getting physical connection...
PinNew: Physical connection found!
PinNew: Creating topology filter '\\?\HDAUDIO#FUNC_01&VEN_10EC&DEV_0236&SUBSYS_17AA391F&REV_1000#4&4128e3&0&0001#{6994ad04-93ef-11d0-a3cc-00a0c9223196}\RtStereoMixTopo'
FilterNew: Creating filter ''
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=3, nodes=2
  Connection: 0 - FromNode=4294967295,FromPin=1 -> ToNode=1,ToPin=1
  Connection: 1 - FromNode=1,FromPin=0 -> ToNode=0,ToPin=1
  Connection: 2 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=0
  Node: 0 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 1 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
FilterRelease {
} FilterRelease
PinNew: Opening topology filter...FilterUse {
} FilterUse
PinNew: Checking for input endpoint pin id (0)...
GetConnectedPin {
FindStartConnectionFrom: Startpin 0, Checking 3 connections...
FindStartConnectionFrom: returning 00000000006B3378
GetConnectedPin: count=2, forward=0, muxPosition=0
GetConnectionFrom: Checking 3 connections... (pTo = 00000000006B3378)
GetConnectionFrom: Returning 00000000006B3368
GetConnectedPin: count=2, forward=0, muxPosition=0
GetConnectionFrom: Checking 3 connections... (pTo = 00000000006B3368)
GetConnectionFrom: Returning 00000000006B3358
PinNew: Found endpoint pin id 1
PinNew: Input friendly name 'PinNew: Releasing topology filter...
FilterRelease {
} FilterRelease
Pin created successfully
} PinNew
PinNew {
PinNew: Creating pin 1:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
FilterRelease {
} FilterRelease
Filter (WaveRT) created with 1 valid pins (total I/Os: 1)
Device 5 has capture alias
Device 5 has realtime alias
Interface 5, Name: R
FilterNew: Creating filter 'Realtek HD Audio Mic input'
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=2, nodes=1
  Connection: 0 - FromNode=4294967295,FromPin=1 -> ToNode=0,ToPin=1
  Connection: 1 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=0
  Node: 0 - {4D837FE0-C555-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
PinNew {
PinNew: Creating pin 0:
PinNew: Checking 1 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 2
PinNew: Format PCM 16 bit supported
PinNew: Default sample rate = 44100 Hz
PinQueryNotificationSupport {
Failed PinQueryNotificationSupport
} PinQueryNotificationSupport
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionFrom: Startpin 0, Checking 2 connections...
FindStartConnectionFrom: returning 00000000006AD538
GetConnectedPin: count=1, forward=0, muxPosition=-1
GetConnectionFrom: Checking 2 connections... (pTo = 00000000006AD538)
GetConnectionFrom: Returning 00000000006AD528
PinNew: Getting physical connection...
PinNew: Physical connection found!
PinNew: Creating topology filter '\\?\HDAUDIO#FUNC_01&VEN_10EC&DEV_0236&SUBSYS_17AA391F&REV_1000#4&4128e3&0&0001#{6994ad04-93ef-11d0-a3cc-00a0c9223196}\RtMicInTopo'
FilterNew: Creating filter ''
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=4, nodes=3
  Connection: 0 - FromNode=4294967295,FromPin=1 -> ToNode=0,ToPin=1
  Connection: 1 - FromNode=0,FromPin=0 -> ToNode=2,ToPin=1
  Connection: 2 - FromNode=2,FromPin=0 -> ToNode=1,ToPin=1
  Connection: 3 - FromNode=1,FromPin=0 -> ToNode=4294967295,ToPin=0
  Node: 0 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 1 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 2 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
FilterRelease {
} FilterRelease
PinNew: Opening topology filter...FilterUse {
} FilterUse
PinNew: Checking for input endpoint pin id (0)...
GetConnectedPin {
FindStartConnectionFrom: Startpin 0, Checking 4 connections...
FindStartConnectionFrom: returning 00000000006C35A8
GetConnectedPin: count=3, forward=0, muxPosition=0
GetConnectionFrom: Checking 4 connections... (pTo = 00000000006C35A8)
GetConnectionFrom: Returning 00000000006C3598
GetConnectedPin: count=3, forward=0, muxPosition=0
GetConnectionFrom: Checking 4 connections... (pTo = 00000000006C3598)
GetConnectionFrom: Returning 00000000006C3588
GetConnectedPin: count=3, forward=0, muxPosition=0
GetConnectionFrom: Checking 4 connections... (pTo = 00000000006C3588)
GetConnectionFrom: Returning 00000000006C3578
PinNew: Found endpoint pin id 1
PinNew: Input friendly name 'PinNew: Releasing topology filter...
FilterRelease {
} FilterRelease
Pin created successfully
} PinNew
PinNew {
PinNew: Creating pin 1:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
FilterRelease {
} FilterRelease
Filter (WaveRT) created with 1 valid pins (total I/Os: 1)
Device 6 has render alias
Device 6 has capture alias
Device 6 has realtime alias
FilterNew: Creating filter ''
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=1, nodes=0
  Connection: 0 - FromNode=4294967295,FromPin=0 -> ToNode=4294967295,ToPin=1
} DumpConnectionsAndNodes
PinNew {
PinNew: Creating pin 0:
PinNew: Checking 2 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 2
PinNew: Format PCM 24 bit supported
PinNew: DR major format 73647561
PinNew: MaxChannel: 2
PinNew: Format PCM 16 bit supported
PinNew: Default sample rate = 48000 Hz
PinQueryNotificationSupport {
Failed PinQueryNotificationSupport
} PinQueryNotificationSupport
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionTo: Startpin 0, Checking 1 connections...
FindStartConnectionTo: returning 00000000006C70E8
PinNew: Getting physical connection...
PinNew: Physical connection found!
PinNew: Creating topology filter '\\?\HDAUDIO#FUNC_01&VEN_10DE&DEV_0084&SUBSYS_00000000&REV_1001#5&2a15e728&3&0001#{6994ad04-93ef-11d0-a3cc-00a0c9223196}\Topo02'
FilterNew: Creating filter ''
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=2, nodes=1
  Connection: 0 - FromNode=4294967295,FromPin=0 -> ToNode=0,ToPin=1
  Connection: 1 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=1
  Node: 0 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
FilterRelease {
} FilterRelease
PinNew: Opening topology filter...FilterUse {
} FilterUse
PinNew: Checking for output endpoint pin id...
GetConnectedPin {
FindStartConnectionTo: Startpin 0, Checking 2 connections...
FindStartConnectionTo: returning 00000000006AD6D8
GetConnectedPin: count=1, forward=1, muxPosition=-1
GetConnectionTo: Checking 2 connections... (pFrom = 00000000006AD6D8)GetConnectionTo: Returning 00000000006AD6E8
PinNew: Found endpoint pin id 1
GetNameFromCategory {
} GetNameFromCategory
PinNew: Pin name 'Output'
PinNew: Releasing topology filter...
FilterRelease {
} FilterRelease
Pin created successfully
} PinNew
PinNew {
PinNew: Creating pin 1:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
FilterRelease {
} FilterRelease
Filter (WaveRT) created with 1 valid pins (total I/Os: 1)
Device 10 has render alias
FilterNew: Creating filter ''
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=4, nodes=3
  Connection: 0 - FromNode=4294967295,FromPin=0 -> ToNode=1,ToPin=1
  Connection: 1 - FromNode=1,FromPin=0 -> ToNode=2,ToPin=1
  Connection: 2 - FromNode=2,FromPin=0 -> ToNode=0,ToPin=1
  Connection: 3 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=1
  Node: 0 - {507AE360-C554-11D0-8A2B-00A0C9255AC1}
  Node: 1 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 2 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
PinNew {
PinNew: Creating pin 0:
PinNew: Checking 1 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 2
PinNew: Format PCM 16 bit supported
PinNew: Default sample rate = 44100 Hz
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionTo: Startpin 0, Checking 4 connections...
FindStartConnectionTo: returning 00000000006C2FD8
GetConnectedPin: count=3, forward=1, muxPosition=-1
GetConnectionTo: Checking 4 connections... (pFrom = 00000000006C2FD8)GetConnectionTo: Returning 00000000006C2FE8
GetConnectedPin: count=3, forward=1, muxPosition=-1
GetConnectionTo: Checking 4 connections... (pFrom = 00000000006C2FE8)GetConnectionTo: Returning 00000000006C2FF8
GetConnectedPin: count=3, forward=1, muxPosition=-1
GetConnectionTo: Checking 4 connections... (pFrom = 00000000006C2FF8)GetConnectionTo: Returning 00000000006C3008
PinNew: Getting physical connection...
PinNew: No physical connection! Getting the pin name
Pin created successfully
} PinNew
PinNew {
PinNew: Creating pin 1:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
FilterRelease {
} FilterRelease
Filter (WaveCyclic) created with 1 valid pins (total I/Os: 1)
Device 11 has render alias
Device 11 has capture alias
Interface 11, Name: @
FilterNew: Creating filter '@System32\drivers\bthhfenum.sys,#2;%1 Hands-Free%0
;(Redmi AirDots 3 Pro)'
FilterNew: Opening filter...
FilterUse {
} FilterUse
DumpConnectionsAndNodes {
DumpConnectionsAndNodes: connections=8, nodes=6
  Connection: 0 - FromNode=4294967295,FromPin=0 -> ToNode=2,ToPin=1
  Connection: 1 - FromNode=2,FromPin=0 -> ToNode=4,ToPin=1
  Connection: 2 - FromNode=4,FromPin=0 -> ToNode=0,ToPin=1
  Connection: 3 - FromNode=0,FromPin=0 -> ToNode=4294967295,ToPin=1
  Connection: 4 - FromNode=4294967295,FromPin=2 -> ToNode=1,ToPin=1
  Connection: 5 - FromNode=1,FromPin=0 -> ToNode=5,ToPin=1
  Connection: 6 - FromNode=5,FromPin=0 -> ToNode=3,ToPin=1
  Connection: 7 - FromNode=3,FromPin=0 -> ToNode=4294967295,ToPin=3
  Node: 0 - {507AE360-C554-11D0-8A2B-00A0C9255AC1}
  Node: 1 - {4D837FE0-C555-11D0-8A2B-00A0C9255AC1}
  Node: 2 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 3 - {3A5ACC00-C557-11D0-8A2B-00A0C9255AC1}
  Node: 4 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
  Node: 5 - {02B223C0-C557-11D0-8A2B-00A0C9255AC1}
} DumpConnectionsAndNodes
PinNew {
PinNew: Creating pin 0:
PinNew: Checking 1 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 1
PinNew: Format PCM 16 bit supported
PinNew: Default sample rate = 8000 Hz
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionTo: Startpin 0, Checking 8 connections...
FindStartConnectionTo: returning 00000000006C5AB8
GetConnectedPin: count=6, forward=1, muxPosition=-1
GetConnectionTo: Checking 8 connections... (pFrom = 00000000006C5AB8)GetConnectionTo: Returning 00000000006C5AC8
GetConnectedPin: count=6, forward=1, muxPosition=-1
GetConnectionTo: Checking 8 connections... (pFrom = 00000000006C5AC8)GetConnectionTo: Returning 00000000006C5AD8
GetConnectedPin: count=6, forward=1, muxPosition=-1
GetConnectionTo: Checking 8 connections... (pFrom = 00000000006C5AD8)GetConnectionTo: Returning 00000000006C5AE8
PinNew: Getting physical connection...
PinNew: No physical connection! Getting the pin name
Pin created successfully
} PinNew
PinNew {
PinNew: Creating pin 1:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
PinNew {
PinNew: Creating pin 2:
PinNew: Not source/sink
PinNew: Error -9996
PinFree {
PinClose {
} PinClose
} PinFree
} PinNew
PinNew {
PinNew: Creating pin 3:
PinNew: Checking 1 no of dataranges...
PinNew: DR major format 73647561
PinNew: MaxChannel: 1
PinNew: Format PCM 16 bit supported
PinNew: Default sample rate = 8000 Hz
PinNew: Finding topology pin...
GetConnectedPin {
FindStartConnectionFrom: Startpin 3, Checking 8 connections...
FindStartConnectionFrom: returning 00000000006C5B28
GetConnectedPin: count=6, forward=0, muxPosition=-1
GetConnectionFrom: Checking 8 connections... (pTo = 00000000006C5B28)
GetConnectionFrom: Returning 00000000006C5B18
GetConnectedPin: count=6, forward=0, muxPosition=-1
GetConnectionFrom: Checking 8 connections... (pTo = 00000000006C5B18)
GetConnectionFrom: Returning 00000000006C5B08
GetConnectedPin: count=6, forward=0, muxPosition=-1
GetConnectionFrom: Checking 8 connections... (pTo = 00000000006C5B08)
GetConnectionFrom: Returning 00000000006C5AF8
PinNew: Getting physical connection...
PinNew: No physical connection! Getting the pin name
Pin created successfully
} PinNew
FilterRelease {
} FilterRelease
Filter (WaveCyclic) created with 2 valid pins (total I/Os: 2)
} PaWinWdm_Initialize
after paHostApiInitializers[3].
Play for 5 seconds.
Stream Completed: No Message
dmitrykos commented 1 month ago

In your log I can see output from PA WDMKS and WASAPI device list code (init phase). There are no log messages from the WASAPI backend which are common to its operation when you open/start stream.

Would you please recompile PA with only WASAPI allowed as such and retry again:

 PA_USE_ASIO                      OFF
 PA_USE_DS                        OFF
 PA_USE_SKELETON                  OFF
 PA_USE_WASAPI                    ON
 PA_USE_WDMKS                     OFF
 PA_USE_WDMKS_DEVICE_INFO         OFF
 PA_USE_WMME                      OFF
BLumia commented 1 month ago

Would you please recompile PA with only WASAPI allowed as such and retry again:

Sure!

$ ./a.exe
PortAudio Test: output sine wave. SR = 44100, BufSize = 64
before paHostApiInitializers[0].
getting Windows version with RtlGetVersion(): major=10, minor=0, build=22631, platform=2
Windows version=10
WASAPI: device idx: 00
WASAPI: ---------------
WASAPI:0| name[鎵０鍣?(Realtek(R) Audio)]
WASAPI:0| form-factor[1]
WASAPI: IAudioClient version = 3
WASAPI:0| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device idx: 01
WASAPI: ---------------
WASAPI:1| name[P27QBC-RG (NVIDIA High Definition Audio)]
WASAPI:1| form-factor[9]
WASAPI:1| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device idx: 02
WASAPI: ---------------
WASAPI:2| name[楹﹀厠椋庨樀鍒?(Realtek(R) Audio)]
WASAPI:2| form-factor[4]
WASAPI:2| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device list ok - found 5 devices, 2 loopback devices
WASAPI: initialized ok
after paHostApiInitializers[0].
WASAPI: IAudioClient2 set properties: IsOffload = 0, Category = 0, Options = 0
WASAPI ERROR HRESULT: 0x88890008 : AUDCLNT_E_UNSUPPORTED_FORMAT
 [FUNCTION: CreateAudioClient FILE: C:/msys64/home/Gary/Source/portaudio/src/hostapi/wasapi/pa_win_wasapi.c {LINE: 3331}]
WASAPI ERROR PAERROR: -9997 : Invalid sample rate
 [FUNCTION: ActivateAudioClient FILE: C:/msys64/home/Gary/Source/portaudio/src/hostapi/wasapi/pa_win_wasapi.c {LINE: 3646}]
WASAPI ERROR PAERROR: -9997 : Invalid sample rate
 [FUNCTION: OpenStream FILE: C:/msys64/home/Gary/Source/portaudio/src/hostapi/wasapi/pa_win_wasapi.c {LINE: 3983}]
TerminateHostApis in
TerminateHostApis out
An error occurred while using the portaudio stream
Error number: -9997
Error message: Invalid sample rate

I guess WASAPI doesn't support that sample rate used by the test program?

dmitrykos commented 1 month ago

It is because your are using WASAPI device in Shared mode, therefore it is expected behavior. Change your test bench to 48000 and it will work.

BLumia commented 1 month ago

After change the sample rate to 48000:

$ ./a.exe
PortAudio Test: output sine wave. SR = 48000, BufSize = 64
before paHostApiInitializers[0].
getting Windows version with RtlGetVersion(): major=10, minor=0, build=22631, platform=2
Windows version=10
WASAPI: device idx: 00
WASAPI: ---------------
WASAPI:0| name[鎵０鍣?(Realtek(R) Audio)]
WASAPI:0| form-factor[1]
WASAPI: IAudioClient version = 3
WASAPI:0| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device idx: 01
WASAPI: ---------------
WASAPI:1| name[P27QBC-RG (NVIDIA High Definition Audio)]
WASAPI:1| form-factor[9]
WASAPI:1| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device idx: 02
WASAPI: ---------------
WASAPI:2| name[楹﹀厠椋庨樀鍒?(Realtek(R) Audio)]
WASAPI:2| form-factor[4]
WASAPI:2| def.SR[48000] max.CH[2] latency{hi[0.010000] lo[0.003000]}
WASAPI: device list ok - found 5 devices, 2 loopback devices
WASAPI: initialized ok
after paHostApiInitializers[0].
WASAPI: IAudioClient2 set properties: IsOffload = 0, Category = 0, Options = 0
wFormatTag     =WAVE_FORMAT_EXTENSIBLE
SubFormat      =KSDATAFORMAT_SUBTYPE_IEEE_FLOAT
Samples.wValidBitsPerSample =32
dwChannelMask  =0x3
nChannels      =2
nSamplesPerSec =48000
nAvgBytesPerSec=384000
nBlockAlign    =8
wBitsPerSample =32
cbSize         =22
WASAPI::OpenStream(output): framesPerUser[ 64 ] framesPerHost[ 1056 ] latency[ 22.00ms ] exclusive[ NO ] wow64_fix[ NO ] mode[ POLL ]
WASAPI: thread[ priority-0xD class-0x20 ]
Play for 5 seconds.
WASAPI ERROR HRESULT: 0x88890004 : AUDCLNT_E_DEVICE_INVALIDATED
 [FUNCTION: _PollGetOutputFramesAvailable FILE: C:/msys64/home/Gary/Source/portaudio/src/hostapi/wasapi/pa_win_wasapi.c {LINE: 5559}]
WASAPI ERROR HRESULT: 0x88890004 : AUDCLNT_E_DEVICE_INVALIDATED
 [FUNCTION: ProcThreadPoll FILE: C:/msys64/home/Gary/Source/portaudio/src/hostapi/wasapi/pa_win_wasapi.c {LINE: 6256}]
Stream Completed: No Message
dmitrykos commented 1 month ago

Ok, now we see that WASAPI device gets invalidated (AUDCLNT_E_DEVICE_INVALIDATED). It is driver-dependent behavior because earlier your test was failing similarly with another PA backend API. WASAPI and other backends of course depend on audio driver installed in the OS. So if driver invalidates audio device when PC is hibernated than nothing can be done from PA side but you need to be prepared for this, catch this condition and re-start audio stream.

In case of WASAPI you can catch AUDCLNT_E_DEVICE_INVALIDATED if you install additional PA WASAPI-specific callback:

https://github.com/PortAudio/portaudio/blob/2fa021931944b141302697f0750c3e5484888726/include/pa_win_wasapi.h#L609-L617

BLumia commented 1 month ago

So if driver invalidates audio device when PC is hibernated than nothing can be done from PA side but you need to be prepared for this, catch this condition and re-start audio stream.

Then I know it's a case that needs to be taken care of from the application developer's side instead of a PA bug. I'll close this issue then.

Many thanks for your help, really appreciated :)

BLumia commented 1 month ago

I just found out this issue only happened when I set my external monitor's audio output as the default output device from Windows (I'm using a laptop). Might be something worth to mention. HTH