[wdmaudiodev] Re: Excessive AVStream Driver Filter Creation

  • From: "Matthew van Eerde" <dmarc-noreply@xxxxxxxxxxxxx> (Redacted sender "Matthew.van.Eerde" for DMARC)
  • To: "wdmaudiodev@xxxxxxxxxxxxx" <wdmaudiodev@xxxxxxxxxxxxx>
  • Date: Wed, 29 May 2019 22:41:41 +0000

Nope, I’m out of ideas. At this point you should file a problem report in 
Feedback Hub with logs of the problem in action.

Once you’ve filed the bug, send me a link.

https://matthewvaneerde.wordpress.com/2016/09/26/report-problems-with-logs-and-suggest-features-with-the-feedback-hub/

________________________________
From: wdmaudiodev-bounce@xxxxxxxxxxxxx <wdmaudiodev-bounce@xxxxxxxxxxxxx> on 
behalf of Gatos, Cobey <cgatos@xxxxxxxxxxxxxxxxx>
Sent: Wednesday, May 29, 2019 3:36:55 PM
To: wdmaudiodev@xxxxxxxxxxxxx
Subject: [wdmaudiodev] Re: Excessive AVStream Driver Filter Creation

I added an event for register and an event for enable. As the log shows, the 
driver only makes these calls at load time. I could not find anywhere else in 
the driver where these calls are made.

For the following log, I enabled all 11 audio devices the driver will expose, 
and I also enabled MIDI. I disabled the other audio devices besides my own. The 
log once again is a result of connecting my device, without attempting to 
generate any audio or MIDI data. For some reason, the strings for my new events 
did not show up - the event labelled 5/14 is the register event, and the other 
one is the enabled event. I also added a disable event, but this is not called. 
I would not expect it to be called until the device is disconnected.

https://www.dropbox.com/s/wpykqz4gddore28/FilterCreateClose3.zip?dl=0<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.dropbox.com%2Fs%2Fwpykqz4gddore28%2FFilterCreateClose3.zip%3Fdl%3D0&data=02%7C01%7CMatthew.van.Eerde%40microsoft.com%7C052de154cdf64df6da3208d6e4863dea%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636947662638919498&sdata=tivQmB38nlVSSLc%2BjxVFv9zuiOS8tNZ9pk0CJA%2B%2Bark%3D&reserved=0>

Any other ideas on where all the device arrival notifications are coming from?




On May 28, 2019, at 6:18 PM, Matthew van Eerde (Redacted sender 
"Matthew.van.Eerde" for DMARC) 
<dmarc-noreply@xxxxxxxxxxxxx<mailto:dmarc-noreply@xxxxxxxxxxxxx>> wrote:

The ETW event in your filter creation and close callback tells us WHO is 
opening your device – Realtek, and the Audio Endpoint Builder service.

The call stack from that event tells us WHY – because there was an add-device 
callback or a remove-device callback.

To figure out why there was an add-device callback or a remove-device callback, 
we have to go one step back in the past. Can you find all the code in your 
driver that registers and/or enables KSCATEGORY_AUDIO interfaces, and add an 
ETW event there too? Then update the .wprp to listen for that event and let’s 
see what the call stack is when that event is logged.

From: Gatos, Cobey<mailto:cgatos@xxxxxxxxxxxxxxxxx>
Sent: Tuesday, May 28, 2019 2:13 PM
To: wdmaudiodev@xxxxxxxxxxxxx<mailto:wdmaudiodev@xxxxxxxxxxxxx>
Subject: [wdmaudiodev] Re: Excessive AVStream Driver Filter Creation

I disabled the other devices, and I observed that the number of filter create 
calls to my driver diminished by a factor of 2. However there were still plenty 
of arrival notifications. (I am surprised that the presence of other devices 
effects the number of calls into my driver.)

To simplify things, I disabled MIDI, and I disabled the stereo pair audio 
devices, so that the driver would expose only a multi-channel in and 
multi-channel out audio device. Leaving the other audio devices on my system 
disabled, I recorded the following etl log.

https://www.dropbox.com/s/u7s9bxy8znpmxce/FilterCreateClose2.zip?dl=0<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.dropbox.com%2Fs%2Fu7s9bxy8znpmxce%2FFilterCreateClose2.zip%3Fdl%3D0&data=02%7C01%7CMatthew.van.Eerde%40microsoft.com%7C052de154cdf64df6da3208d6e4863dea%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636947662638929511&sdata=YahAN%2BksGZxH1PZ8TsuK7Mvir4E54yAegORyp2Vsov4%3D&reserved=0>

Can you give me any clues on now my driver would be creating multiple device 
arrival notifications?

Cobey


On May 24, 2019, at 3:05 PM, Matthew van Eerde (Redacted sender 
"Matthew.van.Eerde" for DMARC) 
<dmarc-noreply@xxxxxxxxxxxxx<mailto:dmarc-noreply@xxxxxxxxxxxxx>> wrote:


Let’s start by figuring out the source of the arrival and removal notifications.

Go into Device Manager > Sound, video and game controllers.

Disable all the other devices but your own and see if the problem still happens.

If so, your driver is the source of the notifications.

If not, you can re-enable the other devices, one by one, until the problem 
recurs. That device is the source of the notifications.

<70FB68EF19394D21BA098C3C24E7324A.png>
From: wdmaudiodev-bounce@xxxxxxxxxxxxx<mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx
<wdmaudiodev-bounce@xxxxxxxxxxxxx<mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx>> on 
behalf of Gatos, Cobey 
<cgatos@xxxxxxxxxxxxxxxxx<mailto:cgatos@xxxxxxxxxxxxxxxxx>>
Sent: Friday, May 24, 2019 11:50:44 AM
To: wdmaudiodev@xxxxxxxxxxxxx<mailto:wdmaudiodev@xxxxxxxxxxxxx>
Subject: [wdmaudiodev] Re: Excessive AVStream Driver Filter Creation


I found some code that did a single disable during the startup process, 
followed shortly by an enable. This disable only occurred once early on. I 
removed the disable call, and it did not appreciably change the behavior. Is 
there anything else the driver might be doing that might contribute to the 
problem?

I have another issue which I believe is related to this problem. If, during 
this period of multiple filter create and close calls, I repeatedly send MIDI 
messages to the driver, I will eventually receive an error return from Windows, 
despite the driver not detecting or returning any errors. If I wait 5 - 10 
minutes after connecting the device for these filter calls to stop happening, 
the error does not occur. Also, if I disable audio in the driver so that only 
MIDI is exposed, the error does not occur. I may successfully send 100 or 1000 
messages before seeing an error.

The error value I receive is MMSYSERR_NODRIVER. When I ran the MIDI test by 
repeatedly sending sysex messages using midiOutLongMsg(), during the call to 
midiOutLongMsg that returned the error, the driver would receive a set of MIDI 
messages that correspond to those sent after calling midiOutReset(), despite my 
code not calling that function. I was also able to reproduce the 
MMSYSERR_NODRIVER error by repeatedly calling midiOutPrepareHeader() and 
midiOutUnprepareHeader(), without actually sending any MIDI data. During this 
test, the driver received calls to create a filter and MIDI pin (corresponding 
to opening the MIDI device), but did not receive any data to send, and did not 
generate any errors. I have also duplicated the error with repeated calls to 
midiOutShortMsg().

It is possible this problem is unrelated and represents a separate issue, but I 
suspect it may be related.

Cobey





On May 24, 2019, at 11:52 AM, Matthew van Eerde (Redacted sender 
"Matthew.van.Eerde" for DMARC) 
<dmarc-noreply@xxxxxxxxxxxxx<mailto:dmarc-noreply@xxxxxxxxxxxxx>> wrote:


About half of it is RtkNGUI64.exe and about half of it is the 
AudioEndpointBuilder service (with some other processes too.)

It looks like there is a whole lot of device arrival and removal notifications 
going on. Are you enabling and disabling your KSCATEGORY_AUDIO interface?

<866945E8B46741A4BE4914044A7C9E5A.png>
From: wdmaudiodev-bounce@xxxxxxxxxxxxx<mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx
<wdmaudiodev-bounce@xxxxxxxxxxxxx<mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx>> on 
behalf of Gatos, Cobey 
<cgatos@xxxxxxxxxxxxxxxxx<mailto:cgatos@xxxxxxxxxxxxxxxxx>>
Sent: Friday, May 24, 2019 8:00:50 AM
To: wdmaudiodev@xxxxxxxxxxxxx<mailto:wdmaudiodev@xxxxxxxxxxxxx>
Subject: [wdmaudiodev] Re: Excessive AVStream Driver Filter Creation


As suggested, I have created a log of the Create and Close calls in my driver. 
I have posted the .etl file here:

https://www.dropbox.com/s/f6hiicanmwm8tq9/FilterCreateClose.zip?dl=0<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.dropbox.com%2Fs%2Ff6hiicanmwm8tq9%2FFilterCreateClose.zip%3Fdl%3D0&data=02%7C01%7CMatthew.van.Eerde%40microsoft.com%7C052de154cdf64df6da3208d6e4863dea%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636947662638929511&sdata=UVwEYccAYX%2BBVn6t%2Fj%2BOkre3ZkhLqhZKxmznjZNzAyg%3D&reserved=0>

To generate this log, I just connected my device to the computer. I did not 
open any audio applications. The driver includes a MIDI filter factory, and 
calls create and close MIDI filters are included in the log.

Thanks.

Cobey


On May 15, 2019, at 1:33 PM, Matthew van Eerde (Redacted sender 
"Matthew.van.Eerde" for DMARC) 
<dmarc-noreply@xxxxxxxxxxxxx<mailto:dmarc-noreply@xxxxxxxxxxxxx>> wrote:


Log an ETW event from your Create and Close callbacks.
Author a .wprp which listens for these events and grabs stacks at the time they 
happen (see 
https://blogs.msdn.microsoft.com/matthew_van_eerde/2018/11/12/what-api-is-being-used-to-play-or-record-audio/<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fblogs.msdn.microsoft.com%2Fmatthew_van_eerde%2F2018%2F11%2F12%2Fwhat-api-is-being-used-to-play-or-record-audio%2F&data=02%7C01%7CMatthew.van.Eerde%40microsoft.com%7C052de154cdf64df6da3208d6e4863dea%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636947662638939515&sdata=zqelRbvgkXTT3iIhAdQYkgcjTvxUw5JMdqysB9CPvv0%3D&reserved=0>)
Record the 2000 calls into an .etl.
Share the .etl.
This will reveal who is instantiating the filters (and, hopefully, why.)


<866945E8B46741A4BE4914044A7C9E5A.png>
From: wdmaudiodev-bounce@xxxxxxxxxxxxx<mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx
<wdmaudiodev-bounce@xxxxxxxxxxxxx<mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx>> on 
behalf of Gatos, Cobey 
<cgatos@xxxxxxxxxxxxxxxxx<mailto:cgatos@xxxxxxxxxxxxxxxxx>>
Sent: Wednesday, May 15, 2019 10:29:38 AM
To: wdmaudiodev@xxxxxxxxxxxxx<mailto:wdmaudiodev@xxxxxxxxxxxxx>
Subject: [wdmaudiodev] Excessive AVStream Driver Filter Creation


I have an AVStream driver for a 10 x 8 USB audio device. The driver exposes 
both multi-channel input and output audio devices to Windows, and additionally 
stereo pair audio devices for each available audio channel pair. There is a 
separate filter factory for each of these (11 total).

When I plug my device in, the driver receives hundreds of filter Create and 
Close calls - on one of my machines the number approaches 2000 create calls. 
This happens without any audio applications open, and without any pins being 
created. These calls can continue for a period of 5 - 10 minutes before they 
diminish in frequency and stop. When the calls stop, there will be 50 - 60 
filters remaining open, and they remain open until I disconnect the device, at 
which point they will all be closed. If the driver exposes only multi-channel 
input and output devices (2 filter factories), the number of filter Create 
calls will decrease to 60 - 80.

I am curious as to why this is happening. Is this normal behavior for Windows? 
I have examined the filter using KS Studio, and compared it to filters created 
by Windows USB audio class driver, and I am not noticing any significant issues 
or differences.

Thanks.

Cobey******************

WDMAUDIODEV addresses:
Post message: mailto:wdmaudiodev@xxxxxxxxxxxxx
Subscribe:    mailto:wdmaudiodev-request@xxxxxxxxxxxxx?subject=subscribe
Unsubscribe:  mailto:wdmaudiodev-request@xxxxxxxxxxxxx?subject=unsubscribe
Moderator:    mailto:wdmaudiodev-moderators@xxxxxxxxxxxxx

URL to WDMAUDIODEV page:
https://nam06.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.wdmaudiodev.com%2F&amp;data=01%7C01%7Cmatthew.van.eerde%40microsoft.com%7Ccb8b9c4726114e89a65a08d6d95aff76%7C72f988bf86f141af91ab2d7cd011db47%7C1&amp;sdata=XdiNC4umPLq%2BCIQqCbEuVRrltNfQ1YPI%2FHvTUXnT3zk%3D&amp;reserved=0<https://nam06.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.wdmaudiodev.com%2F&data=02%7C01%7CMatthew.van.Eerde%40microsoft.com%7C052de154cdf64df6da3208d6e4863dea%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C636947662638949524&sdata=gN8rFqiGu92abgiRHiKo0fgjfN37WPxTwzsTAW8kzI4%3D&reserved=0>




Other related posts: