slow snd_rawmidi_drain() for VirMidi devcies
Takashi Iwai
tiwai at suse.de
Wed Jan 5 21:20:18 CET 2022
On Wed, 05 Jan 2022 20:53:33 +0100,
Stefan Sauer wrote:
>
> From 6b97042bc91ebee267cbb05e6b937cbab5502f61 Mon Sep 17 00:00:00 2001
> From: Stefan Sauer <ensonic at google.com>
> Date: Wed, 5 Jan 2022 20:44:57 +0100
> Subject: [PATCH] ALSA: seq: virmidi: Add a drain operation
>
> If a driver does not supply a drain operation for outputs, a default code
> path will execute msleep(50). Especially for a virtual midi device
> this severely limits the throughput.
>
> This implementation for the virtual midi driver simply flushes the output
> workqueue.
Your signed-off-by is missing. Could you resubmit with it?
thanks,
Takashi
> ---
> sound/core/seq/seq_virmidi.c | 11 +++++++++++
> 1 file changed, 11 insertions(+)
>
> diff --git a/sound/core/seq/seq_virmidi.c b/sound/core/seq/seq_virmidi.c
> index 4abc38c70cae..1d708dc20443 100644
> --- a/sound/core/seq/seq_virmidi.c
> +++ b/sound/core/seq/seq_virmidi.c
> @@ -262,6 +262,16 @@ static int snd_virmidi_output_close(struct
> snd_rawmidi_substream *substream)
> return 0;
> }
>
> +/*
> + * drain output work queue
> + */
> +static void snd_virmidi_output_drain(struct snd_rawmidi_substream *substream)
> +{
> + struct snd_virmidi *vmidi = substream->runtime->private_data;
> +
> + flush_work(&vmidi->output_work);
> +}
> +
> /*
> * subscribe callback - allow output to rawmidi device
> */
> @@ -336,6 +346,7 @@ static const struct snd_rawmidi_ops snd_virmidi_output_ops
> = {
> .open = snd_virmidi_output_open,
> .close = snd_virmidi_output_close,
> .trigger = snd_virmidi_output_trigger,
> + .drain = snd_virmidi_output_drain,
> };
>
> /*
> --
> 2.34.1
>
> Am Mi., 5. Jan. 2022 um 15:13 Uhr schrieb Takashi Iwai <tiwai at suse.de>:
> >
> > On Wed, 05 Jan 2022 14:39:05 +0100,
> > Stefan Sauer wrote:
> > >
> > > - 28,78% 0,00% rawmidi_alsa [snd_rawmidi] [k]
> > > snd_rawmidi_drain_output
> > > - snd_rawmidi_drain_output
> > > - 26,59% msleep
> > > schedule_timeout
> > > schedule
> > > + __schedule
> > > + 2,13% schedule_timeout
> > >
> > > Seems to be because of:
> > > https://github.com/torvalds/linux/blob/master/sound/core/rawmidi.c#L244
> > > if (substream->ops->drain)
> > > substream->ops->drain(substream);
> > > else
> > > msleep(50);
> > >
> > > It see what fileops have no drain impl:
> > > https://github.com/torvalds/linux/blob/master/sound/core/rawmidi.c#L1708
> > > and I see
> > >
> https://github.com/torvalds/linux/blob/master/sound/core/seq/seq_virmidi.c#L329
> > > that define no drain op. Not which ones are actually used here :/
> > >
> > > The docs confirm teh 50 ms wait though:
> > >
> https://github.com/torvalds/linux/blob/master/Documentation/sound/kernel-api/writing-an-alsa-driver.rst#drain-callback
> > >
> > > would it make sense to have a dummy drain function for the seq_virmidi
> output
> > > ops?
> >
> > Yes, a proper drain implementation is definitely better.
> > I guess just calling flush_work(&vmidi->output_work) there would
> > suffice.
> >
> >
> > thanks,
> >
> > Takashi
> >
> > >
> > > Stefan
> > >
> > > Am Di., 4. Jan. 2022 um 16:54 Uhr schrieb Takashi Iwai <tiwai at suse.de>:
> > >
> > > On Sat, 01 Jan 2022 12:49:13 +0100,
> > > Stefan Sauer wrote:
> > > >
> > > > hi,
> > > >
> > > > I've tried to link BitwigStudio to the webapp cables.gl over
> virmidi.
> > > > Unfortunately Bitwig Studio only supports rawmidi. What I discovered
> is
> > > > that there is a strange slowness when sending data to virmidi caused
> > > > by snd_rawmidi_drain().
> > > >
> > > > I've posted two tiny, self-contained c apps to:
> > > > https://gist.github.com/ensonic/c7588b87fa6c1fa94a8f753b1e0aa394
> > > > See some examples below. 2 observations:
> > > > * snd_rawmidi_type() is *not* reporting virmidi as VIRTUAL
> > > > * snd_rawmidi_drain() takes about 60ms! on virtual vs. less that 0.1
> ms
> > > on
> > > > usb midi (I checked all my hw midi and the worst was avg=1ms on
> physical
> > > > midi image unitor8)
> > > >
> > > > When comparing the implementations:
> > > >
> > >
> https://github.com/alsa-project/alsa-lib/blob/master/src/rawmidi/rawmidi_virt.c#L173
> > > >
> > >
> https://github.com/alsa-project/alsa-lib/blob/master/src/rawmidi/rawmidi_hw.c#L164
> > > > I see that the hw one results in an IOCTL which I can see when
> striking
> > > the
> > > > code and I wonder if this is the root cause? Why is rawmidi_virt.c
> not
> > > used
> > > > for virmidi?
> > > > >From poking at snd_rawmidi_open_conf() I have not yet figured where
> > > this is
> > > > decided ....
> > > >
> > > > Stefan
> > > >
> > > > > amidi -l
> > > > Dir Device Name
> > > > IO hw:0,0,0 Scarlett 18i20 USB MIDI 1
> > > > IO hw:3,0,0 nanoKEY2 nanoKEY2 _ KEYBOARD
> > > > IO hw:5,0,0 nanoKONTROL nanoKONTROL _ SLIDE
> > > > IO hw:10,0 Virtual Raw MIDI (16 subdevices)
> > > > IO hw:11,0 Virtual Raw MIDI (16 subdevices)
> > > >
> > > > # using direct i/o to virmidi - all good
> > > > > ./rawmidi_oss /dev/midi11 0
> > > > Using device '/dev/midi11' without draining
> > > > write took min= 0.0015 ms, avg= 0.0016 ms, max= 0.0110 ms
> > > > > ./rawmidi_oss /dev/midi11 1
> > > > Using device '/dev/midi11' with draining
> > > > write took min= 0.0015 ms, avg= 0.0017 ms, max= 0.0101 ms
> > > > drain took min= 0.0001 ms, avg= 0.0001 ms, max= 0.0008 ms
> > > >
> > > > # using snd_rawmidi to virmidi - slow drain operations
> > > > > ./rawmidi_alsa hw:11,0 0
> > > > Using device 'hw:11,0' without draining
> > > > SND_RAWMIDI_TYPE_HW
> > > > write took min= 0.0010 ms, avg= 0.0011 ms, max= 0.0056 ms
> > > > > ./rawmidi_alsa hw:11,0 1
> > > > Using device 'hw:11,0' with draining
> > > > SND_RAWMIDI_TYPE_HW
> > > > write took min= 0.0016 ms, avg= 0.0040 ms, max= 0.0077 ms
> > > > drain took min= 55.9951 ms, avg= 60.4330 ms, max= 64.0653 ms
> > > >
> > > > # using snd_rawmidi to usb hw - all good
> > > > > ./rawmidi_alsa hw:3,0 0
> > > > Using device 'hw:3,0' without draining
> > > > SND_RAWMIDI_TYPE_HW
> > > > write took min= 0.0012 ms, avg= 0.0015 ms, max= 0.0121 ms
> > > > > ./rawmidi_alsa hw:3,0 1
> > > > Using device 'hw:3,0' with draining
> > > > SND_RAWMIDI_TYPE_HW
> > > > write took min= 0.0024 ms, avg= 0.0032 ms, max= 0.0110 ms
> > > > drain took min= 0.0293 ms, avg= 0.0636 ms, max= 0.2277 ms
> > >
> > > This kind of thing needs profiling. You can try perf or whatever
> > > available, and identify which call takes long. My wild guess is
> > > something about snd_seq_sync_output_queue(), maybe poll syscall takes
> > > unexpected long.
> > >
> > > thanks,
> > >
> > > Takashi
> > >
> > >
>
>
More information about the Alsa-devel
mailing list