diff --git a/doc/psy-doc.toml.in b/doc/psy-doc.toml.in index d422cec..7dfc24f 100644 --- a/doc/psy-doc.toml.in +++ b/doc/psy-doc.toml.in @@ -57,13 +57,15 @@ doc_url = "https://docs.gtk.org/pango/" # The generated files will be placed in the root output directory content_files = [ "introduction.md", - "building-psylib.md", - "building-psylib-on-linux.md", - "building-psylib-on-windows.md", "stepping-through-experiment.md", "drawing-with-psylib-developer.md", "audio-with-psylib.md", + "building-psylib.md", + "building-psylib-on-linux.md", + "building-psylib-on-windows.md", + "testing-psylib.md", ] + # Additional images referenced by the documentation; their path # is relative to the content directory specified on the command # line. diff --git a/doc/testing-psylib.md b/doc/testing-psylib.md new file mode 100644 index 0000000..c4ddb2f --- /dev/null +++ b/doc/testing-psylib.md @@ -0,0 +1,44 @@ +Title:Testing psylib +SPDX-License-Identifier: MIT +SPDX-FileCopyrightText: 2024 Maarten Duijndam + +# Testing psylib + +Before running the tests make sure you are able to configure and compile a build first. +In order to run all unit tests and examples - the examples are also tested in CI - you +will have to setup an environment where you can run the tests. If you don't e.g. +libpsy.dll isn't found isn't found on windows. Additionally in order to get the python +(and in the future maybe other) examples, the GI_TYPELIB_PATH must be setup. +meson helps out in this respect. Consider that you have builddir is called "debug" and +your in the root of psylib. You can activate the environment by running: + +```bash +meson devenv -C debug +``` + +Now you can run the tests with: `meson test`, or you can do use one command to run +everything and step out of the debug environment by running: + +```bash +meson devenv -C debug meson test +``` +In order to run a release instead of debug, replace debug with release in the commands +above. + +## Issues on Ubuntu-22.04 with clang address sanitizers + +The test can be run using the ASAN and LSAN tools in order to inspect +issues related to memory issues. On Ubuntu 22.04 this sometimes crashes with a great +number of errors being printed. + +``` +AddressSanitizer:DEADLYSIGNAL +``` + +There is a [work around](https://github.com/actions/runner-images/issues/9524#issuecomment-2002475952) +posted for this, because it came out in a lot of CI of other projects. +The workaround with the following command: + +```bash +sudo sysctl vm.mmap_rnd_bits=28 +``` diff --git a/psy/psy-init.c b/psy/psy-init.c index 4d9f79d..a16fa54 100644 --- a/psy/psy-init.c +++ b/psy/psy-init.c @@ -57,6 +57,8 @@ initializer_constructed(GObject *obj) init_count++; + g_info("Initializer::Initializing psylib count: %d", init_count); + if (init_count == 1) { // stuff we always init @@ -89,6 +91,9 @@ initializer_finalize(GObject *obj) g_mutex_lock(&init_mutex); init_count--; + + g_info("Initializer::Deinitializing psylib count: %d", init_count); + if (init_count == 0) { // stuff we always deinit timer_private_stop_timer_thread(); diff --git a/psy/psy-timer-private.c b/psy/psy-timer-private.c index 984e85e..4697490 100644 --- a/psy/psy-timer-private.c +++ b/psy/psy-timer-private.c @@ -7,6 +7,8 @@ #include #endif +#define TEN_MS 10000 + /* *********** globals *************** */ static PsyTimerThread *g_timer_thread; @@ -40,10 +42,15 @@ typedef struct ThreadData { static gint compare_timer_time_stamps_values(gconstpointer t1, gconstpointer t2) { - const PsyTimePoint *tp1 = psy_timer_get_fire_time(PSY_TIMER((gpointer) t1)); - const PsyTimePoint *tp2 = psy_timer_get_fire_time(PSY_TIMER((gpointer) t2)); + PsyTimePoint *tp1 = psy_timer_get_fire_time(PSY_TIMER((gpointer) t1)); + PsyTimePoint *tp2 = psy_timer_get_fire_time(PSY_TIMER((gpointer) t2)); + + gboolean ret = psy_compare_time_point(tp1, tp2); + + psy_time_point_free(tp1); + psy_time_point_free(tp2); - return psy_compare_time_point(tp1, tp2); + return ret; } #if !GLIB_CHECK_VERSION(2, 76, 0) @@ -212,12 +219,14 @@ psy_timer_thread_fire_timers(PsyTimerThread *self) PsyTimePoint *tp = psy_timer_get_fire_time(first); if (psy_time_point_greater_equal(now, tp)) { - psy_timer_fire(first, psy_timer_get_fire_time(first)); + psy_timer_fire_async_cb(first, tp); + psy_timer_fire(first, tp); g_ptr_array_remove_index(self->timers, 0); psy_time_point_free(now); psy_time_point_free(now_plus_busy_dur); - break; + psy_time_point_free(tp); + continue; } ThreadData *msg = g_async_queue_try_pop(self->queue); @@ -227,6 +236,7 @@ psy_timer_thread_fire_timers(PsyTimerThread *self) psy_time_point_free(now); psy_time_point_free(now_plus_busy_dur); + psy_time_point_free(tp); } } @@ -256,6 +266,7 @@ psy_timer_thread_check_timers(PsyTimerThread *self) ret = TRUE; } psy_duration_free(dur); + psy_time_point_free(tp); psy_time_point_free(now); } @@ -291,6 +302,10 @@ timer_thread(gpointer data) { PsyTimerThread *self = data; + g_info("TimerThread %p, with thread = %p is running", + (gpointer) self, + (gpointer) self->thread); + while (self->running) { ThreadData *data = g_async_queue_timeout_pop(self->queue, 1000); if (data) { @@ -313,11 +328,14 @@ psy_timer_thread_join(PsyTimerThread *self) return; // Send stop message + g_debug("Sending stop msg to timer thread"); ThreadData *data = thread_data_new(MSG_STOP, self, NULL); g_async_queue_push(self->queue, data); + g_debug("joining timer thread"); g_thread_join(self->thread); + g_debug("timer thread joined"); self->thread = NULL; } diff --git a/psy/psy-timer.c b/psy/psy-timer.c index 0ca5e88..2f46088 100644 --- a/psy/psy-timer.c +++ b/psy/psy-timer.c @@ -33,6 +33,9 @@ typedef struct _PsyTimer { GAsyncQueue *queue; + PsyTimerAsyncCb callback; + gpointer callback_data; + } PsyTimer; typedef enum { @@ -133,21 +136,6 @@ thread_default_fire(FireData *data) return G_SOURCE_REMOVE; } -void -psy_timer_fire(PsyTimer *self, PsyTimePoint *tp) -{ - FireData *data = g_new(FireData, 1); - - data->fire_time = psy_time_point_copy(tp); - data->timer = self; - - g_main_context_invoke_full(self->context, - G_PRIORITY_DEFAULT, - G_SOURCE_FUNC(thread_default_fire), - data, - (GDestroyNotify) fire_data_free); -} - static void psy_timer_class_init(PsyTimerClass *klass) { @@ -266,7 +254,7 @@ psy_timer_set_fire_time(PsyTimer *self, PsyTimePoint *tp) * * Gets the timepoint when this timer is set * - * Returns:(nullable)(transfer none):The time for when this timer is/was + * Returns:(nullable)(transfer full):The time for when this timer is/was * set. */ PsyTimePoint * @@ -274,7 +262,8 @@ psy_timer_get_fire_time(PsyTimer *self) { g_return_val_if_fail(PSY_IS_TIMER((PsyTimer *) self), NULL); - return self->fire_time; + return self->fire_time != NULL ? psy_time_point_copy(self->fire_time) + : NULL; } /** @@ -294,6 +283,77 @@ psy_timer_cancel(PsyTimer *self) g_clear_pointer(&self->fire_time, psy_time_point_free); } +/** + * psy_timer_set_async_fire_cb: + * @cb:(nullable)(closure data)(scope forever): a callback to be called + * @data: the data passed to the callback + * + * You may only set this member when the fire-time is not yet set. + * This callback is called from the timer thread, hence, you must take care not + * to run in any thread related issues when operation on/with data. You should + * only call this function when its fire time isn't set yet, as that could + * complicate stuff. + * The thread that monitors the timers will first undertake the steps to emit + * the fired signal, as that is guaranteed pretty quickly. Only then it will + * call this callback asynchronously. It is advised that this callback is non + * blocking, as a blocking callback will mess with other timer scheduled . + * + * Returns: TRUE when the callback was successfully set. + */ +gboolean +psy_timer_set_async_fire_cb(PsyTimer *self, PsyTimerAsyncCb cb, gpointer data) +{ + g_return_val_if_fail(PSY_IS_TIMER(self), FALSE); + + if (self->fire_time) { // cancel ongoing operations first + g_warning("Unable to set callback when timer is already scheduled."); + return FALSE; + } + + self->callback = cb; + self->callback_data = data; + + return TRUE; +} + +/** + * psy_timer_fire: + * @self, the timer to fire + * @tp: The timepoint at which the timer should be fired + * + * Fire the timer in the thread default context at the time the timer was + * created. + */ +void +psy_timer_fire(PsyTimer *self, PsyTimePoint *tp) +{ + FireData *data = g_new(FireData, 1); + + data->fire_time = psy_time_point_copy(tp); + data->timer = self; + + g_main_context_invoke_full(self->context, + G_PRIORITY_DEFAULT, + G_SOURCE_FUNC(thread_default_fire), + data, + (GDestroyNotify) fire_data_free); +} + +/** + * psy_timer_fire_async_cb:(skip) + * + * fires the async callback + */ +void +psy_timer_fire_async_cb(PsyTimer *self, PsyTimePoint *tp) +{ + g_return_if_fail(PSY_IS_TIMER(self)); + + if (self->callback) { + self->callback(tp, self->callback_data); + } +} + /** * psy_timer_get_queue:(skip) * @self: the timer diff --git a/psy/psy-timer.h b/psy/psy-timer.h index 474241f..9a85b89 100644 --- a/psy/psy-timer.h +++ b/psy/psy-timer.h @@ -29,11 +29,28 @@ psy_timer_get_fire_time(PsyTimer *self); G_MODULE_EXPORT void psy_timer_cancel(PsyTimer *self); -/*The next functions are internal*/ +/** + * psy_timer_async_cb: + * @tp:The timepoint at which the timer was set. + * @data:(closure): + * + * This is a callback that will be called from a thread that monitors the + * timers. The callback should last as short as possible in order not to hinder + * other timers. + */ +typedef void (*PsyTimerAsyncCb)(PsyTimePoint *tp, gpointer data); + +G_MODULE_EXPORT gboolean +psy_timer_set_async_fire_cb(PsyTimer *self, PsyTimerAsyncCb cb, gpointer data); + +/* **** The next functions are internal **** */ void psy_timer_fire(PsyTimer *self, PsyTimePoint *tp); +void +psy_timer_fire_async_cb(PsyTimer *self, PsyTimePoint *tp); + GAsyncQueue * psy_timer_get_queue(PsyTimer *self); diff --git a/tests/test-timer2.c b/tests/test-timer2.c index 00864f0..ba3a680 100644 --- a/tests/test-timer2.c +++ b/tests/test-timer2.c @@ -3,14 +3,19 @@ #include #include +#include // Setup the tests +const int NUM_TIMERS = 100; +const int NUM_SIMULTANEOUS = 100; +int g_num_fired = 0; + static int timer_setup(void) { install_log_handler(); - set_log_handler_level(G_LOG_LEVEL_INFO); + set_log_handler_level(G_LOG_LEVEL_DEBUG); set_log_handler_file("test-timer.txt"); return 0; } @@ -46,6 +51,8 @@ fixture_new(const MunitParameter params[], void *user_data) ret->loop = g_main_loop_new(ret->context, FALSE); + g_num_fired = 0; + return ret; } @@ -67,12 +74,13 @@ test_timer_create(const MunitParameter params[], void *user_data) { (void) user_data; (void) params; - PsyTimer *t1; + PsyTimer *t1; + PsyTimePoint *tf = NULL; t1 = psy_timer_new(); munit_assert_not_null(t1); - munit_assert_null(psy_timer_get_fire_time(t1)); + munit_assert_null(tf = psy_timer_get_fire_time(t1)); psy_timer_free(t1); return MUNIT_OK; @@ -87,6 +95,7 @@ test_timer_set_fire_time(const MunitParameter params[], void *user_data) PsyTimer *t1; PsyClock *clk = psy_clock_new(); PsyTimePoint *now = psy_clock_now(clk); + PsyTimePoint *ft = NULL; t1 = psy_timer_new(); munit_assert_not_null(t1); @@ -95,8 +104,9 @@ test_timer_set_fire_time(const MunitParameter params[], void *user_data) g_object_set(t1, "fire-time", now, NULL); - munit_assert_not_null(psy_timer_get_fire_time(t1)); + munit_assert_not_null(ft = psy_timer_get_fire_time(t1)); + psy_time_point_free(ft); psy_time_point_free(now); psy_clock_free(clk); psy_timer_free(t1); @@ -149,6 +159,7 @@ test_timer_fire(const MunitParameter params[], void *user_data) PsyTimer *t1 = NULL; PsyClock *clk = psy_clock_new(); PsyTimePoint *now = psy_clock_now(clk); + PsyTimePoint *ft = NULL; t1 = psy_timer_new(); munit_assert_not_null(t1); @@ -167,7 +178,7 @@ test_timer_fire(const MunitParameter params[], void *user_data) g_timeout_add(10, G_SOURCE_FUNC(quit_loop), utils->loop); - munit_assert_not_null(psy_timer_get_fire_time(t1)); + munit_assert_not_null(ft = psy_timer_get_fire_time(t1)); g_main_loop_run(utils->loop); @@ -175,6 +186,7 @@ test_timer_fire(const MunitParameter params[], void *user_data) munit_assert_true(test_data.time_is_equal_to_set); munit_assert_true(test_data.timer_is_the_same); + psy_time_point_free(ft); psy_time_point_free(now); psy_timer_free(t1); psy_clock_free(clk); @@ -182,9 +194,6 @@ test_timer_fire(const MunitParameter params[], void *user_data) return MUNIT_OK; } -const int NUM_TIMERS = 100; -int g_num_fired; - typedef struct { TimerTestUtilities *utils; PsyClock *clk; @@ -200,7 +209,7 @@ timer_fire_accuratately_test_new(TimerTestUtilities *utils, PsyTimer *timer, PsyTimePoint *scheduled) { - TimerFireAccuratelyTest *ret = g_new(TimerFireAccuratelyTest, 1); + TimerFireAccuratelyTest *ret = g_new0(TimerFireAccuratelyTest, 1); g_assert(utils != NULL && clk != NULL && timer != NULL && scheduled != NULL); @@ -256,6 +265,7 @@ test_timer_fire_accurately(const MunitParameter params[], void *user_data) PsyTimePoint *now = psy_clock_now(clk); GPtrArray *timer_data = g_ptr_array_new_full(NUM_TIMERS, timer_fire_accuratately_test_free); + g_info("Timer accuracy test"); for (int i = 0; i < NUM_TIMERS; i++) { @@ -314,52 +324,237 @@ test_timer_fire_accurately(const MunitParameter params[], void *user_data) return MUNIT_OK; } +static gboolean +async_quit_loop(gpointer data) +{ + TimerFireAccuratelyTest *test_data = data; + g_main_loop_quit(test_data->utils->loop); + + return G_SOURCE_REMOVE; +} + +static void +fire_async_cb(PsyTimePoint *tp, gpointer data) +{ + (void) tp; + TimerFireAccuratelyTest *fire_data = data; + + // Must be freed + fire_data->fire_time = psy_clock_now(fire_data->clk); + + (*fire_data->num_fired)++; + + if ((*fire_data->num_fired) == NUM_TIMERS) { + g_info("Stopping fire_async test"); + GSource *source = g_idle_source_new(); + g_source_set_callback(source, async_quit_loop, data, NULL); + g_source_attach(source, fire_data->utils->context); + g_source_unref(source); + } +} + +static MunitResult +test_timer_fire_async(const MunitParameter params[], void *user_data) +{ + (void) params; + gint num_correct, n_failed = 0; + TimerTestUtilities *utils = user_data; + PsyClock *clk = psy_clock_new(); + PsyTimePoint *now = psy_clock_now(clk); + GPtrArray *timer_data + = g_ptr_array_new_full(NUM_TIMERS, timer_fire_accuratately_test_free); + + g_info("Timer async callback test"); + + for (int i = 0; i < NUM_TIMERS; i++) { + + PsyTimer *t1 = psy_timer_new(); + + PsyDuration *dur = psy_duration_new_ms(munit_rand_int_range(100, 1000)); + PsyTimePoint *time_future = psy_time_point_add(now, dur); + psy_duration_free(dur); + + TimerFireAccuratelyTest *test_data + = timer_fire_accuratately_test_new(utils, clk, t1, time_future); + psy_timer_set_async_fire_cb(t1, fire_async_cb, test_data); + + g_object_set(t1, "fire-time", time_future, NULL); + + g_ptr_array_add(timer_data, test_data); + } + + g_main_loop_run(utils->loop); + + for (int i = 0; i < NUM_TIMERS; i++) { + TimerFireAccuratelyTest *test_data = g_ptr_array_index(timer_data, i); + PsyDuration *time_diff = NULL; + + time_diff = psy_time_point_subtract(test_data->fire_time, + test_data->scheduled); + + // We expect that a timer is not fired ahead of time. + munit_assert_int64(psy_duration_get_us(time_diff), >=, 0); + +#if !defined(_WIN32) // Seems unlikely in CI does seem to work in vm/pc + munit_assert_int64(psy_duration_get_us(time_diff), <, 1000); +#endif + g_info("The timer was fired at %" PRId64 " us", + psy_duration_get_us(time_diff)); + if (psy_duration_get_us(time_diff) >= 1000) { + munit_logf(MUNIT_LOG_WARNING, + "Timer was late %lf\n", + psy_duration_get_seconds(time_diff)); + n_failed++; + } + + psy_duration_free(time_diff); + } + + num_correct = NUM_TIMERS - n_failed; + gdouble percentage = (double) num_correct / NUM_TIMERS * 100; + munit_assert_double(percentage, >, 90.0); + + g_ptr_array_unref(timer_data); + + psy_time_point_free(now); + psy_clock_free(clk); + + return MUNIT_OK; +} + +static void +on_timer_fire_simutaneously(PsyTimer *t, PsyTimePoint *tp, gpointer data) +{ + (void) t; + (void) tp; + TimerFireAccuratelyTest *fire_data = data; + + // Must be freed + fire_data->fire_time = psy_clock_now(fire_data->clk); + + (*fire_data->num_fired)++; + + if ((*fire_data->num_fired) == NUM_SIMULTANEOUS) { + g_info("quiting %s", __func__); + g_main_loop_quit(fire_data->utils->loop); + } +} + +static MunitResult +test_timer_simultaneous(const MunitParameter params[], void *user_data) +{ + (void) params; + gint num_correct, n_failed = 0; + TimerTestUtilities *utils = user_data; + PsyClock *clk = psy_clock_new(); + PsyTimePoint *now = psy_clock_now(clk); + GPtrArray *timer_data = g_ptr_array_new_full( + NUM_SIMULTANEOUS, timer_fire_accuratately_test_free); + PsyDuration *dur = psy_duration_new_ms(100); + + g_info("Timer simultaneous test"); + + for (int i = 0; i < NUM_SIMULTANEOUS; i++) { + + PsyTimer *t1 = psy_timer_new(); + + // freed by the function timer_fire_accuratately_test_free + PsyTimePoint *time_future = psy_time_point_add(now, dur); + + TimerFireAccuratelyTest *test_data + = timer_fire_accuratately_test_new(utils, clk, t1, time_future); + + g_object_set(t1, "fire-time", time_future, NULL); + g_signal_connect( + t1, "fired", G_CALLBACK(on_timer_fire_simutaneously), test_data); + + g_ptr_array_add(timer_data, test_data); + } + + g_main_loop_run(utils->loop); + + for (int i = 0; i < NUM_SIMULTANEOUS; i++) { + TimerFireAccuratelyTest *test_data = g_ptr_array_index(timer_data, i); + PsyDuration *time_diff = NULL; + + time_diff = psy_time_point_subtract(test_data->fire_time, + test_data->scheduled); + + // We expect that a timer is not fired ahead of time. + munit_assert_int64(psy_duration_get_us(time_diff), >=, 0); + + g_info("The timer was fired at %" PRId64 " us", + psy_duration_get_us(time_diff)); + if (psy_duration_get_us(time_diff) >= 1000) { + munit_logf(MUNIT_LOG_WARNING, + "Timer was late %lf\n", + psy_duration_get_seconds(time_diff)); + n_failed++; + } + + psy_duration_free(time_diff); + } + + num_correct = NUM_SIMULTANEOUS - n_failed; + gdouble percentage = (double) num_correct / NUM_SIMULTANEOUS * 100; + munit_assert_double(percentage, >=, 90.0); + + psy_duration_free(dur); + g_ptr_array_unref(timer_data); + + psy_time_point_free(now); + psy_clock_free(clk); + + return MUNIT_OK; +} + // clang-format off MunitTest tests[] = { {"create",test_timer_create, NULL, NULL, MUNIT_TEST_OPTION_NONE, NULL}, {"set-fire-time",test_timer_set_fire_time, NULL, NULL, MUNIT_TEST_OPTION_NONE, NULL}, {"fire",test_timer_fire, fixture_new, fixture_free , MUNIT_TEST_OPTION_NONE, NULL}, {"fire-accurately",test_timer_fire_accurately, fixture_new, fixture_free , MUNIT_TEST_OPTION_NONE, NULL}, + {"fire-asynchronous",test_timer_fire_async, fixture_new, fixture_free , MUNIT_TEST_OPTION_NONE, NULL}, + {"fire-simultaneous",test_timer_simultaneous, fixture_new, fixture_free , MUNIT_TEST_OPTION_NONE, NULL}, {0} }; // clang-format on MunitSuite suite = {"psy-timer/", tests, NULL, 1, MUNIT_SUITE_OPTION_NONE}; +static void +signal_handler(int sig) +{ + switch (sig) { + case SIGINT: + case SIGABRT: + case SIGSEGV: + remove_log_handler(); + g_print("Received signal %d\nquitting\n", sig); + exit(sig); + } +} + +static void +setup_signal_handlers(void) +{ + if (signal(SIGINT, signal_handler) == SIG_ERR) { + g_printerr("Unable to catch SIGINT"); + } + if (signal(SIGABRT, signal_handler) == SIG_ERR) { + g_printerr("Unable to catch SIGABRT"); + } + if (signal(SIGSEGV, signal_handler) == SIG_ERR) { + g_printerr("Unable to catch SIGABRT"); + } +} + int main(int argc, char **argv) { timer_setup(); + setup_signal_handlers(); int ret = munit_suite_main(&suite, NULL, argc, argv); timer_teardown(); return ret; } - -// -// int -// add_timer_suite(void) -// { -// CU_Suite *suite -// = CU_add_suite("PsyTimer suite", timer_setup, timer_teardown); -// CU_Test *test; -// if (!suite) -// return 1; -// -// test = CU_ADD_TEST(suite, test_timer_create); -// if (!test) -// return 1; -// -// test = CU_ADD_TEST(suite, test_timer_set_fire_time); -// if (!test) -// return 1; -// -// test = CU_ADD_TEST(suite, test_timer_fire); -// if (!test) -// return 1; -// -// test = CU_ADD_TEST(suite, test_timer_fire_accurately); -// if (!test) -// return 1; -// -// return 0; -// }