GNOME Bugzilla – Bug 787683
alsamidisrc behavior with non-live sinks
Last modified: 2017-11-30 02:15:41 UTC
Created attachment 359802 [details] Program to play midi notes at fixed intervals Hi, a user reported to me that alsamidisrc produces unexpected results when recording to a file. Bug description --------------- The following pipeline gives the expected result of live real-time samples: $ gst-launch-1.0 alsamidisrc ports=128:0 ! fluiddec ! autoaudiosink The following one does not: $ gst-launch-1.0 alsamidisrc ports=128:0 ! fluiddec ! wavenc ! filesink location=alsamidisrc_out.wav The user found that the music recorded in the file was "slower" compared to what was played on the MIDI keyboard, like if the pauses between the notes were longer than they should have been. This turned out to be because, even though the alsamidisrc element is supposed to be a live source[1], when using a non-real-time sink more midi ticks (silence buffers) than expected are created. Using "filesink sync=true" (or using "identity sync=true" right after alsamidisrc) would work around the issue, producing wave files with the expected timing. A more reproducible test can be performed generating midi notes at fixed intervals (see the attached midi_virtual_ticks.py) and comparing the files produced with and without sync=true (after aligning the first note) see the attached alsamidisrc_test.sh script. Bug analysis ------------ alsamidisrc is based on GstPushSrc[2], and AFAICS at a lower level the observed behavior depends on how often the create() method of the src element gets called. In case of sync=true the pipeline seems to wait that the duration of the buffers actually passes before requesting (accepting?) a new buffer, conversely when sync=false buffers are created as soon as possible. From the logic in gst_base_src_do_sync[3], and from some other docs [4,5] it seems that live sources are expected to behave like the sync=true behavior from above (wait for the buffer duration to pass), some comments suggest that live sources must implement the get_times() callback to enable this "sync" behavior. Can anyone confirm if this is actually the issue? Do I have to implement get_times() in alsamidisrc? A quick experiment seems to confirm that implementing get_times() makes alsamidisrc behavior less surprising but I'd like to have confirmation before proposing a patch. Thanks, Antonio [1] https://cgit.freedesktop.org/gstreamer/gst-plugins-base/tree/ext/alsa/gstalsamidisrc.c#n264 [2] https://gstreamer.freedesktop.org/data/doc/gstreamer/head/gstreamer-libs/html/GstPushSrc.html [3] https://cgit.freedesktop.org/gstreamer/gstreamer/tree/libs/gst/base/gstbasesrc.c#n2178 [4] https://gstreamer.freedesktop.org/documentation/design/live-source.html [5] https://cgit.freedesktop.org/gstreamer/gstreamer/tree/libs/gst/base/gstbasesrc.c#n87
Created attachment 359803 [details] Test alsamidisrc with sync=true and sync=false
Be aware, I'm not that familiar with that element and MIDI in general. It is first time I ear someone is using alsamidisrc. I think the element have several issues. 1. Tick duration is not always 10ms (there is an ALSA API to read it) 2. Tick time is indicated per event, right now we assume all events are on consecutive ticks. That's wrong and worst you could have two events with the same tick. The problem with implementing get_times() is that you may endup loosing events. Though, if you wait up to 1 tick duration, you should not be having issues. I think the proper solution is to poll, but instead of a duration use a proper timeout (calculate max delay from the clock). This way, instead of waiting 10ms, you look at the clock for when the next tick should happens, and wait at most this time. After which, you produce a MIDI tick. As a side effect, if the mini input is silence, you'll get a perfect stream of midi tick, without any jitter.
Hi Nicolas, > Be aware, I'm not that familiar with that element and MIDI in general. It is > first time I ear someone is using alsamidisrc. > I appreciate even more that you took the time to comment then. > I think the element have several issues. > > 1. Tick duration is not always 10ms (there is an ALSA API to read it) The ticks used by alsamidisrc are not the ticks-per-beat which depend on the "tempo" but rather some real-time tick[1] that MIDI never specified officially, the 0xf9 message used here is also used by midiparse to let the pipeline progress (in fact that's where I got the idea from) and it is parsed by fluiddec, so I think we can safely assume one "real-time-tick" each 10ms in a GStreamer context. [1] https://web.archive.org/web/20160223003358fw_/http://www.blitter.com/~russtopia/MIDI/~jglatt/tech/midispec/tick.htm > 2. Tick time is indicated per event, right now we assume all events are on > consecutive ticks. That's wrong and worst you could have two events with > the same tick. > I agree that there must be more granularity in event timestamps. Some comments in the code also mentions that the current situation was meant as a proof-of-concept. > The problem with implementing get_times() is that you may endup loosing > events. Though, if you wait up to 1 tick duration, you should not be having > issues. > > I think the proper solution is to poll, but instead of a duration use > a proper timeout (calculate max delay from the clock). This way, instead of > waiting 10ms, you look at the clock for when the next tick should happens, > and wait at most this time. After which, you produce a MIDI tick. As a side > effect, if the mini input is silence, you'll get a perfect stream of midi > tick, without any jitter. > I noticed that midiparse does not set a duration for buffers either, and I guess this make sense for MIDI events which do not have a concept of duration. I took a better look at the sequencer API and it looks like I can use it to schedule future events, so this could be a better way to produce the periodic ticks: let the ALSA sequencer produce them and have alsamidisrc just poll with no timeout and forward the buffers downstream regardless of their type (tick, note, etc.). I still have some doubts tho: - I am not sure how and where to correlate the timestamps from the ALSA sequencer queue with the GStreamer element running time. - Should I handle the PAUSED state? Is it a valid state for live elements? Ciao ciao, Antonio
(In reply to Antonio Ospite from comment #3) > I still have some doubts tho: > > - I am not sure how and where to correlate the timestamps from the ALSA > sequencer queue with the GStreamer element running time. We need to read the API but normally drivers will translate their timestamp to some known clock, like monotonic clock. When this is the case, you simply read that clock, then read GST clock, substract these, that gives you the delta between the two clocks. You then add this delta to the event timestamp to get a time in GST clock, substract GST element base_time and that's your ts. If you don't know the clock, then the Alsa driven tick comes handy. You then subclass GstClock around your tick counter. Then you provide that clock, or slave it. Your time stamps becomes the tick counter converted to nanosecond. > > - Should I handle the PAUSED state? Is it a valid state for live elements? Live source don't produce data in paused state. Events are lost in that state. If midi is state less, there nothing to do. Just set GstBaseSrc to live. > > Ciao ciao, > Antonio
Created attachment 360846 [details] Improved event timestamping To recap, the ALSA sequencer can timestamp events either with a tick count or with some real-time information relative to when the sequencer queue timer was started. I decided to use the real-time option to avoid conversions based on the tempo and the beats-per-quarter-notes. Letting the sequencer schedule the tick events makes the change a lot less invasive than having to wait and fire events explicitly in the GStreamer element. I prototyped a patch in gst-aseq-appsrc[1] and it seems to work quite well, see the attached image: the "after" graph shows the new, saner, behavior. The tick event must still be handled explicitly because unfortunately alsa-lib does not support decoding it. Currently[2] I am calculating the difference between the GStreamer time and the sequencer time, using the suggested formula, at the transition to the PLAYING state and then I apply the delay for each event as they come. Patches to alsamidisrc are coming in the next days. Ciao, Antonio [1] https://git.ao2.it/gst-aseq-appsrc.git/commitdiff/d49c7665151703d8074a07d2d1834e904ec85758 [2] https://git.ao2.it/gst-aseq-appsrc.git/blob/d49c7665151703d8074a07d2d1834e904ec85758:/gst-aseq-appsrc.c#l376
Created attachment 361224 [details] [review] alsamidisrc: Improve a comment and remove one trailing space
Created attachment 361225 [details] [review] alsamidisrc: Prevent Valgrind from reporting cached config as memory leaks See http://git.alsa-project.org/?p=alsa-lib.git;a=blob;f=MEMORY-LEAK;hb=HEAD This allows to have cleaner Valgrind reports about alsamidisrc and make it easier to spot actual problems.
Created attachment 361226 [details] [review] alsamidisrc: Fix a memory leak when setting the "ports" property When setting the "ports" property the value is duplicated but it's not freed when the elements stops. Reported by Valgrind (example run with "alsamidisrc ports=128:0"): 6 bytes in 1 blocks are definitely lost in loss record 30 of 1,911 at 0x4C2BBEF: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so) by 0x5411528: g_malloc (gmem.c:94) by 0x542A9FE: g_strdup (gstrfuncs.c:363) by 0x775211E: gst_alsa_midi_src_set_property (gstalsamidisrc.c:284) by 0x5184A4D: object_set_property (gobject.c:1439) by 0x5184A4D: g_object_setv (gobject.c:2245) by 0x51859DD: g_object_set_property (gobject.c:2529) by 0x4F0474C: ??? (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.1203.0) by 0x4F065C8: ??? (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.1203.0) by 0x4F07557: ??? (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.1203.0) by 0x4EFE3EE: gst_parse_launch_full (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.1203.0) by 0x4EFE673: gst_parse_launchv_full (in /usr/lib/x86_64-linux-gnu/libgstreamer-1.0.so.0.1203.0)
Created attachment 361227 [details] [review] alsamidisrc: Don't set buffer offset and duration They are not relly needed for a live source.
Created attachment 361228 [details] [review] alsamidisrc: Merge prepare_buffer() and push_buffer() The separation is not very useful since push_buffer() is the only user of prepare_buffer().
Created attachment 361229 [details] [review] alsamidisrc: Expand snd_seq_create_simple_port() and use a queue for timestamps Events are timestamped with a real-time value representing the time passed since the queue timer was started. The timestamp is not used just yet.
Created attachment 361230 [details] [review] alsamidisrc: Improve buffer timestamping Make buffer timestamps more accurate and, more importantly, actually representative of the MIDI events timing. Previously, buffers were only sent with timetamps aligned at a 10ms boundary which was just wrong, now the buffer timestamp represents the real time of the MIDI event. Conveniently, the ALSA sequencer API supports scheduling events in the future so the sequencer infrastructure can be used to have the tick delivered at the right time, avoiding any custom scheduling mechanism. The ticks scheduling starts on the first transition to PLAYING, and the delay is also calculated when the pipeline goes into PLAYING.
I spotted a couple of typos in my commit messages (relly, timetamps), they are not a big deal, but if after the review (no hurry) it turns out a v2 is going to be needed I'll be happy to fix those as well. Ciao, Antonio
Ping.
Review of attachment 361224 [details] [review]: Looks good.
Review of attachment 361225 [details] [review]: Fair.
Review of attachment 361226 [details] [review]: Good catch.
Review of attachment 361227 [details] [review]: The value we were setting these to are wrong anyway. The offset is somethings a nice to have, e.g. for v4l2src it let you know if some frames were lost ahead of the src (in the driver). But I agree, better remove them for now.
Review of attachment 361228 [details] [review]: Good.
Review of attachment 361229 [details] [review]: Looks good, even though I'm not an expert here.
Review of attachment 361230 [details] [review]: My impression is that this is clearly the right way, again I'm not ALSA expert, but should work better.
Attachment 361224 [details] pushed as 8638d81 - alsamidisrc: Improve a comment and remove one trailing space Attachment 361225 [details] pushed as f671026 - alsamidisrc: Prevent Valgrind from reporting cached config as memory leaks Attachment 361226 [details] pushed as 3c5aa0a - alsamidisrc: Fix a memory leak when setting the "ports" property Attachment 361227 [details] pushed as b5060f1 - alsamidisrc: Don't set buffer offset and duration Attachment 361228 [details] pushed as 132ead3 - alsamidisrc: Merge prepare_buffer() and push_buffer() Attachment 361229 [details] pushed as 3a64ed7 - alsamidisrc: Expand snd_seq_create_simple_port() and use a queue for timestamps Attachment 361230 [details] pushed as feacb87 - alsamidisrc: Improve buffer timestamping
Thanks a lot of this work, this element really needed some maintenance, but no one really had the equipment to test. If there is anything else, let us know, file bugs, this is really appreciated.