libobs: Add audio to source profiler

docs/sphinx/reference-libobs-util-source-profiler.rst

@@ -37,6 +37,16 @@ The source profiler is used to get information about individual source's perform
 
    Only valid for async sources (e.g. Media Source).
 
+.. member:: uint64_t profiler_result.audio_render_avg
+            uint64_t profiler_result.audio_async_avg
+
+   Execution time of this source's audio functions within a second.
+
+.. member:: uint64_t profiler_result.audio_render_max
+            uint64_t profiler_result.audio_async_max
+
+   Maximum execution time of this source's audio functions within a second.
+
 .. type:: struct profiler_result profiler_result_t
 
 .. code:: cpp

libobs/obs-audio.c

@@ -533,6 +533,7 @@ bool audio_callback(void *param, uint64_t start_ts_in, uint64_t end_ts_in, uint6
 	/* render audio data */
 	for (size_t i = 0; i < audio->render_order.num; i++) {
 		obs_source_t *source = audio->render_order.array[i];
+		const uint64_t start = source_profiler_source_audio_render_start();
 		obs_source_audio_render(source, mixers, channels, sample_rate, audio_size);
 
 		/* if a source has gone backward in time and we can no
@@ -560,6 +561,7 @@ bool audio_callback(void *param, uint64_t start_ts_in, uint64_t end_ts_in, uint6
 					obs_source_audio_render(source, mixers, channels, sample_rate, audio_size);
 			}
 		}
+		source_profiler_source_audio_render_end(source, start, AUDIO_OUTPUT_FRAMES);
 	}
 
 	/* ------------------------------------------------ */

libobs/obs-internal.h

@@ -1382,5 +1382,15 @@ extern uint64_t source_profiler_source_render_begin(gs_timer_t **timer);
 /* Submit start timestamp and GPU timer after rendering source */
 extern void source_profiler_source_render_end(obs_source_t *source, uint64_t start, gs_timer_t *timer);
 
+/* Get timestamp for start of audio */
+extern uint64_t source_profiler_source_audio_render_start(void);
+/* Submit start timestamp for source */
+extern void source_profiler_source_audio_render_end(obs_source_t *source, uint64_t start, uint32_t frames);
+
+/* Get timestamp for start of async audio */
+extern uint64_t source_profiler_source_audio_async_render_start(void);
+/* Submit start timestamp for source */
+extern void source_profiler_source_audio_async_render_end(obs_source_t *source, uint64_t start, uint32_t frames);
+
 /* Remove source from profiler hashmaps */
 extern void source_profiler_remove_source(obs_source_t *source);

libobs/obs-source.c

@@ -3730,7 +3730,10 @@ static inline struct obs_audio_data *filter_async_audio(obs_source_t *source, st
 			continue;
 
 		if (filter->context.data && filter->info.filter_audio) {
+			const uint64_t start = source_profiler_source_audio_async_render_start();
+			const uint32_t frames = in->frames;
 			in = filter->info.filter_audio(filter->context.data, in);
+			source_profiler_source_audio_async_render_end(filter, start, frames);
 			if (!in)
 				return NULL;
 		}
@@ -3893,6 +3896,8 @@ void obs_source_output_audio(obs_source_t *source, const struct obs_source_audio
 	if (!obs_ptr_valid(audio_in, "obs_source_output_audio"))
 		return;
 
+	const uint64_t start = source_profiler_source_audio_async_render_start();
+
 	/* sets unused data pointers to NULL automatically because apparently
 	 * some filter plugins aren't checking the actual channel count, and
 	 * instead are checking to see whether the pointer is non-zero. */
@@ -3921,6 +3926,7 @@ void obs_source_output_audio(obs_source_t *source, const struct obs_source_audio
 	}
 
 	pthread_mutex_unlock(&source->filter_mutex);
+	source_profiler_source_audio_async_render_end(source, start, source->audio_data.frames);
 }
 
 void remove_async_frame(obs_source_t *source, struct obs_source_frame *frame)

libobs/util/source-profiler.c

@@ -70,6 +70,9 @@ struct profiler_entry {
 	/* Timestamps of last N async frames rendered */
 	struct ucirclebuf async_rendered_ts;
 
+	struct ucirclebuf audio_render;
+	struct ucirclebuf async_audio_render;
+
 	UT_hash_handle hh;
 };
 
@@ -174,6 +177,8 @@ static struct profiler_entry *entry_create(const uintptr_t key)
 	ucirclebuf_init(&ent->render_gpu_sum, profiler_samples);
 	ucirclebuf_init(&ent->async_frame_ts, profiler_samples);
 	ucirclebuf_init(&ent->async_rendered_ts, profiler_samples);
+	ucirclebuf_init(&ent->audio_render, profiler_samples);
+	ucirclebuf_init(&ent->async_audio_render, profiler_samples);
 	return ent;
 }
 
@@ -186,6 +191,8 @@ static void entry_destroy(struct profiler_entry *entry)
 	ucirclebuf_free(&entry->render_gpu_sum);
 	ucirclebuf_free(&entry->async_frame_ts);
 	ucirclebuf_free(&entry->async_rendered_ts);
+	ucirclebuf_free(&entry->audio_render);
+	ucirclebuf_free(&entry->async_audio_render);
 	bfree(entry);
 }
 
@@ -478,6 +485,60 @@ void source_profiler_source_render_end(obs_source_t *source, uint64_t start, gs_
 	}
 }
 
+uint64_t source_profiler_source_audio_render_start(void)
+{
+	if (!enabled)
+		return 0;
+
+	return os_gettime_ns();
+}
+
+void source_profiler_source_audio_render_end(obs_source_t *source, uint64_t start, uint32_t frames)
+{
+	if (!enabled)
+		return;
+
+	const uint32_t sample_rate = audio_output_get_sample_rate(obs_get_audio());
+
+	const uint64_t delta = (os_gettime_ns() - start) * sample_rate / frames;
+
+	pthread_rwlock_wrlock(&hm_rwlock);
+
+	struct profiler_entry *ent;
+	HASH_FIND_PTR(hm_entries, &source, ent);
+	if (ent)
+		ucirclebuf_push(&ent->audio_render, delta);
+
+	pthread_rwlock_unlock(&hm_rwlock);
+}
+
+uint64_t source_profiler_source_audio_async_render_start(void)
+{
+	if (!enabled)
+		return 0;
+
+	return os_gettime_ns();
+}
+
+void source_profiler_source_audio_async_render_end(obs_source_t *source, uint64_t start, uint32_t frames)
+{
+	if (!enabled)
+		return;
+
+	const uint32_t sample_rate = audio_output_get_sample_rate(obs_get_audio());
+
+	const uint64_t delta = (os_gettime_ns() - start) * sample_rate / frames;
+
+	pthread_rwlock_wrlock(&hm_rwlock);
+
+	struct profiler_entry *ent;
+	HASH_FIND_PTR(hm_entries, &source, ent);
+	if (ent)
+		ucirclebuf_push(&ent->async_audio_render, delta);
+
+	pthread_rwlock_unlock(&hm_rwlock);
+}
+
 static void task_delete_source(void *key)
 {
 	struct source_samples *smp;
@@ -591,6 +652,40 @@ static inline void calculate_fps(const struct ucirclebuf *frames, double *avg, u
 	}
 }
 
+static inline void calculate_audio_render(struct profiler_entry *ent, struct profiler_result *result)
+{
+	size_t idx = 0;
+	uint64_t sum = 0;
+
+	for (; idx<ent->audio_render.num; idx++) {
+		const uint64_t delta = ent->audio_render.array[idx];
+		if (delta > result->audio_render_max)
+			result->audio_render_max = delta;
+
+		sum += delta;
+	}
+
+	if (idx)
+		result->audio_render_avg = sum / idx;
+}
+
+static inline void calculate_async_audio_render(struct profiler_entry *ent, struct profiler_result *result)
+{
+	size_t idx = 0;
+	uint64_t sum = 0;
+
+	for (; idx < ent->async_audio_render.num; idx++) {
+		const uint64_t delta = ent->async_audio_render.array[idx];
+		if (delta > result->audio_async_max)
+			result->audio_async_max = delta;
+
+		sum += delta;
+	}
+
+	if (idx)
+		result->audio_async_avg = sum / idx;
+}
+
 bool source_profiler_fill_result(obs_source_t *source, struct profiler_result *result)
 {
 	if (!enabled || !result)
@@ -612,6 +707,9 @@ bool source_profiler_fill_result(obs_source_t *source, struct profiler_result *r
 			calculate_fps(&ent->async_rendered_ts, &result->async_rendered, &result->async_rendered_best,
 				      &result->async_rendered_worst);
 		}
+
+		calculate_audio_render(ent, result);
+		calculate_async_audio_render(ent, result);
 	}
 
 	pthread_rwlock_unlock(&hm_rwlock);
@@ -628,3 +726,5 @@ profiler_result_t *source_profiler_get_result(obs_source_t *source)
 	}
 	return ret;
 }
+
+

libobs/util/source-profiler.h

@@ -49,6 +49,14 @@ typedef struct profiler_result {
 	uint64_t async_input_worst;
 	uint64_t async_rendered_best;
 	uint64_t async_rendered_worst;
+
+	/* Audio render time in ns */
+	uint64_t audio_render_avg;
+	uint64_t audio_render_max;
+
+	/* Audio async render time in ns */
+	uint64_t audio_async_avg;
+	uint64_t audio_async_max;
 } profiler_result_t;
 
 /* Enable/disable profiler (applied on next frame) */