GNOME Bugzilla – Bug 793839
audiolatency: New plugin for measuring audio latency
Last modified: 2018-02-27 18:38:41 UTC
Measures the audio latency between the source pad and the sink pad by outputting period ticks on the source pad and measuring how long they take to arrive on the sink pad. Very useful for quantifying latency improvements in audio pipelines. This plugin was particularly useful during development of the low-latency features of the wasapi plugin.
Created attachment 368936 [details] [review] audiolatency: New plugin for measuring audio latency Measures the audio latency between the source pad and the sink pad by outputting period ticks on the source pad and measuring how long they take to arrive on the sink pad. Very useful for quantifying latency improvements in audio pipelines. This plugin was particularly useful during development of the low-latency features of the wasapi plugin.
Just a curiosity, how much did the numbers differ to using the latency tracer ?
(In reply to Nicolas Dufresne (stormer) from comment #2) > Just a curiosity, how much did the numbers differ to using the latency > tracer ? I wrote this element not to measure gstreamer's latency (which can be manually added up), but to measure the latency of the Windows Sound API (in various configurations) and the underlying audio drivers (for different hardware and drivers). So I do not have numbers from the latency tracer to compare. However, you should be able to do that comparison yourself since the plugin is quite easy to use. :)
Please fix your commit message then, it's incorrect. In your message you say that you mesure Latency between pads, which would exclude the HW latency. This is what the latency tracer does.
The latency tracer measures the latency between a sink pad and a source pad, no? This element measures the latency between its source pad and its sink pad aiui, which can include pipeline-external latency. So I think the commit message is fine, although perhaps it could be made clearer? In any case, let's get it in?
(In reply to Nicolas Dufresne (stormer) from comment #4) > Please fix your commit message then, it's incorrect. In your message you say > that you mesure Latency between pads, which would exclude the HW latency. Not in this case. I thought the commit message was pretty clear; it measures the latency between the source pad of the audiolatency element and the sink pad of the same audiolatency element, which means you must loop it up somehow; either externally (with a wire) or by linking pads. Audio editing and recording apps usually have a feature like this; for example Audacity does. I'll add language to that effect if it makes things clearer.
(In reply to Nirbheek Chauhan from comment #6) > (In reply to Nicolas Dufresne (stormer) from comment #4) > > Please fix your commit message then, it's incorrect. In your message you say > > that you mesure Latency between pads, which would exclude the HW latency. > > Not in this case. I thought the commit message was pretty clear; it measures > the latency between the source pad of the audiolatency element and the sink > pad of the same audiolatency element, which means you must loop it up > somehow; either externally (with a wire) or by linking pads. You should add a example pipeline, it's not clear there is two audiolatency element being used, but make sense. (it's easy when we know already).
Review of attachment 368936 [details] [review]: I have no doubt this element is really useful, but I don't understand why it's a bin that contains the audio src (unlike the example). Also, the code is not thread safe, the getters access various internal variable and is racing with the streaming thread. ::: gst/audiolatency/gstaudiolatency.c @@ +20,3 @@ + +/** + * SECTION:element-audiolatency I don't see any changes to the doc/ folder that would accompany this. @@ +45,3 @@ + * + * For programmatic use, instead of using 'print-stats', you should read the + * 'last-latency' and 'average-latency' properties at most once a second. Why this polling ? Other elements like this will post a periodic message, with a configurable timer. @@ +55,3 @@ + +#define AUDIOLATENCY_CAPS "audio/x-raw, " \ + "format = (string) F32LE, " \ A bit limiting, but ok. @@ +144,3 @@ + g_param_spec_boolean ("print-latency", "Print latencies", + "Print the measured latencies on stdout", + DEFAULT_PRINT_LATENCY, G_PARAM_READWRITE | G_PARAM_STATIC_STRINGS)); Maybe GST_PARAM_MUTABLE_READY (we often forget) or add locking. @@ +182,3 @@ + self->audiosrc = gst_element_factory_make ("audiotestsrc", NULL); + g_object_set (self->audiosrc, "wave", 8, "samplesperbuffer", 240, NULL); + gst_bin_add (GST_BIN (self), self->audiosrc); Wait a minute, your example says "autoaudiosrc ! audiolatency print-stats=true ! ...", but here I see that this is a bind that contains the audiosrc. Something is miss-aligned. I don't get why this is a bin instead of a audio filter. @@ +198,3 @@ + +static gint64 +gst_audiolatency_get_latency (GstAudioLatency * self) Which lock is protecting this? @@ +211,3 @@ + +static void +gst_audiolatency_set_latency (GstAudioLatency * self, gint64 latency) Which lock is protecting this ? @@ +253,3 @@ + gboolean ret; + + g_assert_cmpint (1, >=, gst_buffer_n_memory (buffer)); Isn't that bad, why don't you just warn and using gst_buffer_map() instead ? At least it won't just break if you have multiple memory object being appended. @@ +256,3 @@ + memory = gst_buffer_peek_memory (buffer, 0); + ret = gst_memory_map (memory, &minfo, GST_MAP_READ); + g_assert_true (ret); That's wrong, handle the error here. @@ +261,3 @@ + s = gst_caps_get_structure (caps, 0); + ret = gst_structure_get_int (s, "channels", &channels); + g_assert_true (ret); Validate this onces when you get the caps, and remove that assertion. @@ +270,3 @@ + duration = GST_BUFFER_DURATION (buffer); + /* Read only one channel */ + for (int ii = 1; ii < fsize; ii += channels) { This is C99, we don't usually do that. Move out the variable declaration please. And name it just 'i' maybe ? why ii ? @@ +302,3 @@ + pts = g_get_monotonic_time (); + /* The ticks are once a second, so we can skip checking most buffers */ + if (self->send_pts > 0 && pts - self->send_pts <= 950 * 1000) I'd move these magic numbers as defines. Also, we usually do all our constant math around G_USEC_PER_SEC. @@ +311,3 @@ + goto out; + + pts -= offset / 1000; Like (G_USEC_PER_SEC / 10), the compiler will do the math at compile time, an we know this is 1 / 10 of a second.
(In reply to Nicolas Dufresne (stormer) from comment #7) > You should add a example pipeline, it's not clear there is two audiolatency > element being used, but make sense. (it's easy when we know already). There is an example pipeline in the gtk-doc comments of the plugin, with a few paragraphs on how to set it up. I can copy that to the commit message if you like. (In reply to Nicolas Dufresne (stormer) from comment #10) > Review of attachment 368936 [details] [review] [review]: > > I have no doubt this element is really useful, but I don't understand why > it's a bin that contains the audio src (unlike the example). From the docs: Measures the audio latency between the source pad and the sink pad by outputting period ticks on the source pad and measuring how long they take to arrive on the sink pad. The ticks are, of course, generated by an audiotestsrc element. > Also, the code > is not thread safe, the getters access various internal variable and is > racing with the streaming thread. > It is impossible for there to be a race on these. set_latency is only ever called once a second, at most, and get_latency is only reading a single integer property. > ::: gst/audiolatency/gstaudiolatency.c > @@ +20,3 @@ > + > +/** > + * SECTION:element-audiolatency > > I don't see any changes to the doc/ folder that would accompany this. > I honestly don't understand the magic incantations required to update the docs, and it seems like for other plugins we update it separately anyway. > @@ +45,3 @@ > + * > + * For programmatic use, instead of using 'print-stats', you should read the > + * 'last-latency' and 'average-latency' properties at most once a second. > > Why this polling ? Other elements like this will post a periodic message, > with a configurable timer. > Because it only ever updates once a second (with the periodic tick). I can, of course, update it to set the property instead of setting the internal variable so people can subscribe to the ::notify signal. > @@ +144,3 @@ > + g_param_spec_boolean ("print-latency", "Print latencies", > + "Print the measured latencies on stdout", > + DEFAULT_PRINT_LATENCY, G_PARAM_READWRITE | > G_PARAM_STATIC_STRINGS)); > > Maybe GST_PARAM_MUTABLE_READY (we often forget) or add locking. Why does this need locking? It is an integer that is accessed in one place to selectively print to stdout. > @@ +182,3 @@ > + self->audiosrc = gst_element_factory_make ("audiotestsrc", NULL); > + g_object_set (self->audiosrc, "wave", 8, "samplesperbuffer", 240, NULL); > + gst_bin_add (GST_BIN (self), self->audiosrc); > > Wait a minute, your example says "autoaudiosrc ! audiolatency > print-stats=true ! ...", but here I see that this is a bind that contains > the audiosrc. Something is miss-aligned. I don't get why this is a bin > instead of a audio filter. > It's a bin because it's not an audio filter ;) The element generates period ticks, which is why it needs its own source. Do you have documentation suggestions to make this clearer? > @@ +198,3 @@ > + > +static gint64 > +gst_audiolatency_get_latency (GstAudioLatency * self) > > Which lock is protecting this? > > @@ +211,3 @@ > + > +static void > +gst_audiolatency_set_latency (GstAudioLatency * self, gint64 latency) > > Which lock is protecting this ? > Both these do not need locks, as I explained above. > @@ +253,3 @@ > + gboolean ret; > + > + g_assert_cmpint (1, >=, gst_buffer_n_memory (buffer)); > > Isn't that bad, why don't you just warn and using gst_buffer_map() instead ? > At least it won't just break if you have multiple memory object being > appended. > > @@ +256,3 @@ > + memory = gst_buffer_peek_memory (buffer, 0); > + ret = gst_memory_map (memory, &minfo, GST_MAP_READ); > + g_assert_true (ret); > > That's wrong, handle the error here. > > @@ +261,3 @@ > + s = gst_caps_get_structure (caps, 0); > + ret = gst_structure_get_int (s, "channels", &channels); > + g_assert_true (ret); > > Validate this onces when you get the caps, and remove that assertion. > Sure, I can fix these asserts. > @@ +270,3 @@ > + duration = GST_BUFFER_DURATION (buffer); > + /* Read only one channel */ > + for (int ii = 1; ii < fsize; ii += channels) { > > This is C99, we don't usually do that. Move out the variable declaration > please. And name it just 'i' maybe ? why ii ? > Actually, variable declarations inside for loops was introduced in C99, so this is completely valid. However, if we want to target C89, or if this is a style rule in gstreamer, I can change that. `ii` is easier to search for compared to `i`. Just personal preference. > @@ +302,3 @@ > + pts = g_get_monotonic_time (); > + /* The ticks are once a second, so we can skip checking most buffers */ > + if (self->send_pts > 0 && pts - self->send_pts <= 950 * 1000) > > I'd move these magic numbers as defines. Also, we usually do all our > constant math around G_USEC_PER_SEC. > > @@ +311,3 @@ > + goto out; > + > + pts -= offset / 1000; > > Like (G_USEC_PER_SEC / 10), the compiler will do the math at compile time, > an we know this is 1 / 10 of a second. Makes sense, I'll use defines instead of magic numbers.
I think it would be nice to get this merged today before the feature freeze in any case, even if some bits have to be left to be fixed later.
>> Also, the code >> is not thread safe, the getters access various internal variable and is >> racing with the streaming thread. >> > >It is impossible for there to be a race on these. set_latency is only ever >called once a second, at most, and get_latency is only reading a single integer >property. GST_OBJECT_LOCK() please, no excuse to mess with the CPU cache.
>> @@ +45,3 @@ >> + * >> + * For programmatic use, instead of using 'print-stats', you should read the >> + * 'last-latency' and 'average-latency' properties at most once a second. >> >> Why this polling ? Other elements like this will post a periodic message, >> with a configurable timer. >> > >Because it only ever updates once a second (with the periodic tick). I can, of >course, update it to set the property instead of setting the internal variable >so people can subscribe to the ::notify signal. Notify signal is on streaming thread, that's why we use element message in every other elements like this.
> It's a bin because it's not an audio filter ;) > The element generates period ticks, which is why it needs its own source. Do you have documentation suggestions to make this clearer? Ok, just miss-read that code, that's ok then.
> Actually, variable declarations inside for loops was introduced in C99, so this > is completely valid. However, if we want to target C89, or if this is a style rule in gstreamer, I can change that. We target C89 in the entire GStreamer code, until further notice.
Created attachment 369049 [details] [review] audiolatency: New plugin for measuring audio latency Measures the audio latency between the source pad and the sink pad by outputting period ticks on the source pad and measuring how long they take to arrive on the sink pad. Very useful for quantifying latency improvements in audio pipelines. This plugin was particularly useful during development of the low-latency features of the wasapi plugin.
This should address all the comments, the element now: 1. Posts an element message for each new latency measurement 2. Has locks around set/get latency 3. Handles the case where buffers have multiple memories
Thanks for the review, I've pushed the element with changes as requested. Do poke me if you find anything else. :) Attachment 369049 [details] pushed as 3fb8153 - audiolatency: New plugin for measuring audio latency