From 3317af804b0540820d9b22f90a1b279e74be7a3b Mon Sep 17 00:00:00 2001 From: Wim Taymans Date: Fri, 31 Jan 2020 15:07:26 +0100 Subject: [PATCH] pw-profiler: add profiler tool Add Profiler object and fields. Add profiler extension API. It notifies Profiler objects with real-time performance data. Add module that implements the profiler extension. Add pw-profiler tool that binds to the profiler API and dumps the data into a log file, gnuplot files, a html page and a script to generate svg graphs. This is almost the same as what JACK2 JackEngineProfiling does. --- spa/include/spa/meson.build | 1 + spa/include/spa/param/profiler.h | 51 ++ spa/include/spa/param/type-info.h | 13 + spa/include/spa/utils/type-info.h | 1 + spa/include/spa/utils/type.h | 1 + spa/tests/test-utils.c | 3 +- src/daemon/pipewire.conf.in | 1 + src/extensions/profiler.h | 83 +++ src/modules/meson.build | 10 + src/modules/module-profiler.c | 372 +++++++++++++ src/modules/module-profiler/protocol-native.c | 125 +++++ src/tools/meson.build | 7 + src/tools/pw-profiler.c | 515 ++++++++++++++++++ 13 files changed, 1182 insertions(+), 1 deletion(-) create mode 100644 spa/include/spa/param/profiler.h create mode 100644 src/extensions/profiler.h create mode 100644 src/modules/module-profiler.c create mode 100644 src/modules/module-profiler/protocol-native.c create mode 100644 src/tools/pw-profiler.c diff --git a/spa/include/spa/meson.build b/spa/include/spa/meson.build index 3072618b5..6d4a64ba7 100644 --- a/spa/include/spa/meson.build +++ b/spa/include/spa/meson.build @@ -60,6 +60,7 @@ spa_param_headers = [ 'param/format.h', 'param/format-utils.h', 'param/param.h', + 'param/profiler.h', 'param/props.h', 'param/type-info.h', ] diff --git a/spa/include/spa/param/profiler.h b/spa/include/spa/param/profiler.h new file mode 100644 index 000000000..03ed68226 --- /dev/null +++ b/spa/include/spa/param/profiler.h @@ -0,0 +1,51 @@ +/* Simple Plugin API + * + * Copyright © 2020 Wim Taymans + * + * Permission is hereby granted, free of charge, to any person obtaining a + * copy of this software and associated documentation files (the "Software"), + * to deal in the Software without restriction, including without limitation + * the rights to use, copy, modify, merge, publish, distribute, sublicense, + * and/or sell copies of the Software, and to permit persons to whom the + * Software is furnished to do so, subject to the following conditions: + * + * The above copyright notice and this permission notice (including the next + * paragraph) shall be included in all copies or substantial portions of the + * Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + * DEALINGS IN THE SOFTWARE. + */ + +#ifndef SPA_PARAM_PROFILER_H +#define SPA_PARAM_PROFILER_H + +#ifdef __cplusplus +extern "C" { +#endif + +#include + +/** properties for SPA_TYPE_OBJECT_Profiler */ +enum spa_profiler { + SPA_PROFILER_START, + + SPA_PROFILER_START_Driver = 0x10000, /**< driver related profiler properties */ + SPA_PROFILER_driverBlock, /**< generic driver info block */ + + SPA_PROFILER_START_Follower = 0x20000, /**< follower related profiler properties */ + SPA_PROFILER_followerBlock, /**< generic follower info block */ + + SPA_PROFILER_START_CUSTOM = 0x1000000, +}; + +#ifdef __cplusplus +} /* extern "C" */ +#endif + +#endif /* SPA_PARAM_PROFILER_H */ diff --git a/spa/include/spa/param/type-info.h b/spa/include/spa/param/type-info.h index 140c7809e..81f977e4f 100644 --- a/spa/include/spa/param/type-info.h +++ b/spa/include/spa/param/type-info.h @@ -322,6 +322,19 @@ static const struct spa_type_info spa_type_param_route[] = { { 0, 0, NULL, NULL }, }; +#include + +#define SPA_TYPE_INFO_Profiler SPA_TYPE_INFO_OBJECT_BASE "Profiler" +#define SPA_TYPE_INFO_PROFILER_BASE SPA_TYPE_INFO_Profiler ":" + +static const struct spa_type_info spa_type_profiler[] = { + { SPA_PROFILER_START, SPA_TYPE_Id, SPA_TYPE_INFO_PROFILER_BASE, spa_type_param, }, + { SPA_PROFILER_driverBlock, SPA_TYPE_Struct, SPA_TYPE_INFO_PROFILER_BASE "driverBlock", NULL, }, + { SPA_PROFILER_followerBlock, SPA_TYPE_Struct, SPA_TYPE_INFO_PROFILER_BASE "followerBlock", NULL, }, + { 0, 0, NULL, NULL }, +}; + + #ifdef __cplusplus } /* extern "C" */ #endif diff --git a/spa/include/spa/utils/type-info.h b/spa/include/spa/utils/type-info.h index 954616764..60d1f2e9d 100644 --- a/spa/include/spa/utils/type-info.h +++ b/spa/include/spa/utils/type-info.h @@ -116,6 +116,7 @@ static const struct spa_type_info spa_types[] = { { SPA_TYPE_OBJECT_ParamProfile, SPA_TYPE_Object, SPA_TYPE_INFO_PARAM_Profile, spa_type_param_profile }, { SPA_TYPE_OBJECT_ParamPortConfig, SPA_TYPE_Object, SPA_TYPE_INFO_PARAM_PortConfig, spa_type_param_port_config }, { SPA_TYPE_OBJECT_ParamRoute, SPA_TYPE_Object, SPA_TYPE_INFO_PARAM_Route, spa_type_param_route }, + { SPA_TYPE_OBJECT_Profiler, SPA_TYPE_Object, SPA_TYPE_INFO_Profiler, spa_type_profiler }, { 0, 0, NULL, NULL } }; diff --git a/spa/include/spa/utils/type.h b/spa/include/spa/utils/type.h index 2b5f10e79..fb295653f 100644 --- a/spa/include/spa/utils/type.h +++ b/spa/include/spa/utils/type.h @@ -86,6 +86,7 @@ enum { SPA_TYPE_OBJECT_ParamProfile, SPA_TYPE_OBJECT_ParamPortConfig, SPA_TYPE_OBJECT_ParamRoute, + SPA_TYPE_OBJECT_Profiler, SPA_TYPE_OBJECT_LAST, /**< not part of ABI */ /* vendor extensions */ diff --git a/spa/tests/test-utils.c b/spa/tests/test-utils.c index 76c6d399a..4953633b0 100644 --- a/spa/tests/test-utils.c +++ b/spa/tests/test-utils.c @@ -123,7 +123,8 @@ static void test_abi(void) spa_assert(SPA_TYPE_OBJECT_ParamProfile == 0x40007); spa_assert(SPA_TYPE_OBJECT_ParamPortConfig == 0x40008); spa_assert(SPA_TYPE_OBJECT_ParamRoute == 0x40009); - spa_assert(SPA_TYPE_OBJECT_LAST == 0x4000a); + spa_assert(SPA_TYPE_OBJECT_Profiler == 0x4000a); + spa_assert(SPA_TYPE_OBJECT_LAST == 0x4000b); spa_assert(SPA_TYPE_VENDOR_PipeWire == 0x02000000); spa_assert(SPA_TYPE_VENDOR_Other == 0x7f000000); diff --git a/src/daemon/pipewire.conf.in b/src/daemon/pipewire.conf.in index 4bfb96b1d..94936002c 100644 --- a/src/daemon/pipewire.conf.in +++ b/src/daemon/pipewire.conf.in @@ -25,6 +25,7 @@ add-spa-lib api.jack.* jack/libspa-jack #load-module libpipewire-module-spa-node api.alsa.seq.bridge node.name=MIDI-Bridge load-module libpipewire-module-rtkit load-module libpipewire-module-protocol-native +load-module libpipewire-module-profiler load-module libpipewire-module-metadata load-module libpipewire-module-spa-device-factory load-module libpipewire-module-spa-node-factory diff --git a/src/extensions/profiler.h b/src/extensions/profiler.h new file mode 100644 index 000000000..d17a646a2 --- /dev/null +++ b/src/extensions/profiler.h @@ -0,0 +1,83 @@ +/* PipeWire + * + * Copyright © 2020 Wim Taymans + * + * Permission is hereby granted, free of charge, to any person obtaining a + * copy of this software and associated documentation files (the "Software"), + * to deal in the Software without restriction, including without limitation + * the rights to use, copy, modify, merge, publish, distribute, sublicense, + * and/or sell copies of the Software, and to permit persons to whom the + * Software is furnished to do so, subject to the following conditions: + * + * The above copyright notice and this permission notice (including the next + * paragraph) shall be included in all copies or substantial portions of the + * Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + * DEALINGS IN THE SOFTWARE. + */ + +#ifndef PIPEWIRE_EXT_PROFILER_H +#define PIPEWIRE_EXT_PROFILER_H + +#ifdef __cplusplus +extern "C" { +#endif + +#include + +#define PW_TYPE_INTERFACE_Profiler PW_TYPE_INFO_INTERFACE_BASE "Profiler" + +#define PW_VERSION_PROFILER 3 +struct pw_profiler; + +#define PW_EXTENSION_MODULE_PROFILER PIPEWIRE_MODULE_PREFIX "module-profiler" + +#define PW_PROFILER_EVENT_PROFILE 0 +#define PW_PROFILER_EVENT_NUM 1 + +/** \ref pw_profiler events */ +struct pw_profiler_events { +#define PW_VERSION_PROFILER_EVENTS 0 + uint32_t version; + + void (*profile) (void *object, const struct spa_pod *pod); +}; + +#define PW_PROFILER_METHOD_ADD_LISTENER 0 +#define PW_PROFILER_METHOD_NUM 1 + +/** \ref pw_profiler methods */ +struct pw_profiler_methods { +#define PW_VERSION_PROFILER_METHODS 0 + uint32_t version; + + int (*add_listener) (void *object, + struct spa_hook *listener, + const struct pw_profiler_events *events, + void *data); +}; + +#define pw_profiler_method(o,method,version,...) \ +({ \ + int _res = -ENOTSUP; \ + spa_interface_call_res((struct spa_interface*)o, \ + struct pw_profiler_methods, _res, \ + method, version, ##__VA_ARGS__); \ + _res; \ +}) + +#define pw_profiler_add_listener(c,...) pw_profiler_method(c,add_listener,0,__VA_ARGS__) + +#define PW_KEY_PROFILER_NAME "profiler.name" + +#ifdef __cplusplus +} /* extern "C" */ +#endif + +#endif /* PIPEWIRE_EXT_PROFILER_H */ diff --git a/src/modules/meson.build b/src/modules/meson.build index 7aa847780..556e9bb26 100644 --- a/src/modules/meson.build +++ b/src/modules/meson.build @@ -13,6 +13,16 @@ pipewire_module_access = shared_library('pipewire-module-access', [ 'module-acce dependencies : [mathlib, dl_lib, pipewire_dep], ) +pipewire_module_profiler = shared_library('pipewire-module-profiler', + [ 'module-profiler.c', + 'module-profiler/protocol-native.c', ], + c_args : pipewire_module_c_args, + include_directories : [configinc, spa_inc], + install : true, + install_dir : modules_install_dir, + dependencies : [mathlib, dl_lib, pipewire_dep], +) + if dbus_dep.found() pipewire_module_rtkit = shared_library('pipewire-module-rtkit', [ 'module-rtkit.c' ], c_args : pipewire_module_c_args, diff --git a/src/modules/module-profiler.c b/src/modules/module-profiler.c new file mode 100644 index 000000000..c824374a3 --- /dev/null +++ b/src/modules/module-profiler.c @@ -0,0 +1,372 @@ +/* PipeWire + * + * Copyright © 2020 Wim Taymans + * + * Permission is hereby granted, free of charge, to any person obtaining a + * copy of this software and associated documentation files (the "Software"), + * to deal in the Software without restriction, including without limitation + * the rights to use, copy, modify, merge, publish, distribute, sublicense, + * and/or sell copies of the Software, and to permit persons to whom the + * Software is furnished to do so, subject to the following conditions: + * + * The above copyright notice and this permission notice (including the next + * paragraph) shall be included in all copies or substantial portions of the + * Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + * DEALINGS IN THE SOFTWARE. + */ + +#include +#include +#include +#include +#include +#include +#include + +#include "config.h" + +#include +#include +#include +#include + +#include +#include +#include + +#define NAME "profiler" + +#define MAX_BUFFER (8 * 1024 * 1024) +#define MIN_FLUSH (16 * 1024) +#define DEFAULT_IDLE 5 +#define DEFAULT_INTERVAL 1 + +int pw_protocol_native_ext_profiler_init(struct pw_context *context); + +#define pw_profiler_resource(r,m,v,...) \ + pw_resource_call(r,struct pw_profiler_events,m,v,__VA_ARGS__) + +#define pw_profiler_resource_profile(r,...) \ + pw_profiler_resource(r,profile,0,__VA_ARGS__) + +static const struct spa_dict_item module_props[] = { + { PW_KEY_MODULE_AUTHOR, "Wim Taymans " }, + { PW_KEY_MODULE_DESCRIPTION, "Generate Profiling data" }, + { PW_KEY_MODULE_VERSION, PACKAGE_VERSION }, +}; + +struct impl { + struct pw_context *context; + struct pw_properties *properties; + + struct spa_hook context_listener; + struct spa_hook module_listener; + + struct pw_global *global; + + int64_t count; + uint32_t busy; + uint32_t empty; + struct spa_source *flush_timeout; + unsigned int flushing:1; + unsigned int listening:1; + + struct spa_ringbuffer buffer; + uint8_t data[MAX_BUFFER]; +}; + +struct resource_data { + struct impl *impl; + + struct pw_resource *resource; + struct spa_hook resource_listener; +}; + +static void start_flush(struct impl *impl) +{ + struct timespec value, interval; + + value.tv_sec = 0; + value.tv_nsec = 1; + interval.tv_sec = DEFAULT_INTERVAL; + interval.tv_nsec = 0; + pw_loop_update_timer(impl->context->main_loop, + impl->flush_timeout, &value, &interval, false); + impl->flushing = true; +} + +static void stop_flush(struct impl *impl) +{ + struct timespec value, interval; + + if (!impl->flushing) + return; + + value.tv_sec = 0; + value.tv_nsec = 0; + interval.tv_sec = 0; + interval.tv_nsec = 0; + pw_loop_update_timer(impl->context->main_loop, + impl->flush_timeout, &value, &interval, false); + impl->flushing = false; +} + +static void flush_timeout(void *data, uint64_t expirations) +{ + struct impl *impl = data; + int32_t avail, size; + uint32_t idx; + struct spa_pod_struct *p; + struct pw_resource *resource; + + avail = spa_ringbuffer_get_read_index(&impl->buffer, &idx); + + pw_log_trace(NAME"%p avail %d", impl, avail); + + if (avail <= 0) { + if (++impl->empty == DEFAULT_IDLE) + stop_flush(impl); + return; + } + impl->empty = 0; + + size = avail + sizeof(struct spa_pod_struct); + p = alloca(size); + *p = SPA_POD_INIT_Struct(avail); + + spa_ringbuffer_read_data(&impl->buffer, impl->data, MAX_BUFFER, + idx % MAX_BUFFER, + SPA_MEMBER(p, sizeof(struct spa_pod_struct), void), avail); + spa_ringbuffer_read_update(&impl->buffer, idx + avail); + + spa_list_for_each(resource, &impl->global->resource_list, link) + pw_profiler_resource_profile(resource, &p->pod); +} + +static void context_start(void *data, struct pw_impl_node *node) +{ + struct impl *impl = data; + char buffer[4096]; + struct spa_pod_builder b; + struct spa_pod_frame f[2]; + struct pw_node_activation *a = node->rt.activation; + struct spa_io_position *pos = &a->position; + struct pw_node_target *t; + int32_t filled; + uint32_t idx, avail; + + spa_pod_builder_init(&b, buffer, sizeof(buffer)); + spa_pod_builder_push_object(&b, &f[0], + SPA_TYPE_OBJECT_Profiler, 0); + + spa_pod_builder_prop(&b, SPA_PROFILER_driverBlock, 0); + spa_pod_builder_add_struct(&b, + SPA_POD_Long(impl->count), + SPA_POD_Int(node->info.id), + SPA_POD_String(node->name), + SPA_POD_Float(a->cpu_load[0]), + SPA_POD_Float(a->cpu_load[1]), + SPA_POD_Float(a->cpu_load[2]), + SPA_POD_Long(pos->clock.nsec), + SPA_POD_Fraction(&pos->clock.rate), + SPA_POD_Long(pos->clock.position), + SPA_POD_Long(pos->clock.duration), + SPA_POD_Long(pos->clock.delay), + SPA_POD_Double(pos->clock.rate_diff), + SPA_POD_Long(pos->clock.next_nsec), + SPA_POD_Long(a->prev_signal_time), + SPA_POD_Long(a->signal_time), + SPA_POD_Long(a->awake_time), + SPA_POD_Long(a->finish_time), + SPA_POD_Int(a->status)); + + spa_list_for_each(t, &node->rt.target_list, link) { + struct pw_impl_node *n = t->node; + struct pw_node_activation *na; + + if (n == NULL || n == node) + continue; + + na = n->rt.activation; + spa_pod_builder_prop(&b, SPA_PROFILER_followerBlock, 0); + spa_pod_builder_add_struct(&b, + SPA_POD_Int(n->info.id), + SPA_POD_String(n->name), + SPA_POD_Long(na->signal_time), + SPA_POD_Long(na->awake_time), + SPA_POD_Long(na->finish_time), + SPA_POD_Int(na->status)); + } + spa_pod_builder_pop(&b, &f[0]); + + filled = spa_ringbuffer_get_write_index(&impl->buffer, &idx); + if (filled < 0 || filled > MAX_BUFFER) { + pw_log_warn(NAME " %p: queue xrun %d", impl, filled); + goto done; + } + avail = MAX_BUFFER - filled; + if (avail < b.state.offset) { + pw_log_warn(NAME " %p: queue full %d < %d", impl, avail, b.state.offset); + goto done; + } + spa_ringbuffer_write_data(&impl->buffer, + impl->data, MAX_BUFFER, + idx % MAX_BUFFER, + b.data, b.state.offset); + spa_ringbuffer_write_update(&impl->buffer, idx + b.state.offset); + + if (!impl->flushing || filled + b.state.offset > MIN_FLUSH) + start_flush(impl); +done: + impl->count++; +} + +static const struct pw_context_driver_events context_events = { + PW_VERSION_CONTEXT_DRIVER_EVENTS, + .start = context_start, +}; + +static int do_stop(struct spa_loop *loop, + bool async, uint32_t seq, const void *data, size_t size, void *user_data) +{ + struct impl *impl = user_data; + spa_hook_remove(&impl->context_listener); + return 0; +} + +static void stop_listener(struct impl *impl) +{ + if (impl->listening) { + pw_loop_invoke(impl->context->data_loop, + do_stop, SPA_ID_INVALID, NULL, 0, true, impl); + impl->listening = false; + } +} + +static void resource_destroy(void *data) +{ + struct impl *impl = data; + if (--impl->busy == 0) { + pw_log_info(NAME" %p: stopping profiler", impl); + stop_listener(impl); + } +} + +static const struct pw_resource_events resource_events = { + PW_VERSION_RESOURCE_EVENTS, + .destroy = resource_destroy, +}; + +static int +do_start(struct spa_loop *loop, + bool async, uint32_t seq, const void *data, size_t size, void *user_data) +{ + struct impl *impl = user_data; + spa_hook_list_append(&impl->context->driver_listener_list, + &impl->context_listener, + &context_events, impl); + return 0; +} +static int +global_bind(void *_data, struct pw_impl_client *client, uint32_t permissions, + uint32_t version, uint32_t id) +{ + struct impl *impl = _data; + struct pw_global *global = impl->global; + struct pw_resource *resource; + struct resource_data *data; + + resource = pw_resource_new(client, id, permissions, + PW_TYPE_INTERFACE_Profiler, version, sizeof(*data)); + if (resource == NULL) + return -errno; + + data = pw_resource_get_user_data(resource); + data->impl = impl; + data->resource = resource; + pw_global_add_resource(global, resource); + + pw_resource_add_listener(resource, &data->resource_listener, + &resource_events, impl); + + if (++impl->busy == 1) { + pw_log_info(NAME" %p: starting profiler", impl); + pw_loop_invoke(impl->context->data_loop, + do_start, SPA_ID_INVALID, NULL, 0, false, impl); + impl->listening = true; + } + return 0; +} + +static void module_destroy(void *data) +{ + struct impl *impl = data; + + pw_global_destroy(impl->global); + + spa_hook_remove(&impl->module_listener); + + if (impl->properties) + pw_properties_free(impl->properties); + + free(impl); +} + +static const struct pw_impl_module_events module_events = { + PW_VERSION_IMPL_MODULE_EVENTS, + .destroy = module_destroy, +}; + +SPA_EXPORT +int pipewire__module_init(struct pw_impl_module *module, const char *args) +{ + struct pw_context *context = pw_impl_module_get_context(module); + struct pw_properties *props; + struct impl *impl; + struct pw_loop *main_loop = pw_context_get_main_loop(context); + + impl = calloc(1, sizeof(struct impl)); + if (impl == NULL) + return -errno; + + pw_protocol_native_ext_profiler_init(context); + + pw_log_debug("module %p: new %s", impl, args); + + if (args) + props = pw_properties_new_string(args); + else + props = pw_properties_new(NULL, NULL); + + impl->context = context; + impl->properties = props; + + spa_ringbuffer_init(&impl->buffer); + + impl->global = pw_global_new(context, + PW_TYPE_INTERFACE_Profiler, + PW_VERSION_PROFILER, + pw_properties_copy(props), + global_bind, impl); + if (impl->global == NULL) { + free(impl); + return -errno; + } + + impl->flush_timeout = pw_loop_add_timer(main_loop, flush_timeout, impl); + + pw_impl_module_add_listener(module, &impl->module_listener, &module_events, impl); + + pw_impl_module_update_properties(module, &SPA_DICT_INIT_ARRAY(module_props)); + + pw_global_register(impl->global); + + return 0; +} diff --git a/src/modules/module-profiler/protocol-native.c b/src/modules/module-profiler/protocol-native.c new file mode 100644 index 000000000..5a6166a79 --- /dev/null +++ b/src/modules/module-profiler/protocol-native.c @@ -0,0 +1,125 @@ +/* PipeWire + * + * Copyright © 2019 Wim Taymans + * + * Permission is hereby granted, free of charge, to any person obtaining a + * copy of this software and associated documentation files (the "Software"), + * to deal in the Software without restriction, including without limitation + * the rights to use, copy, modify, merge, publish, distribute, sublicense, + * and/or sell copies of the Software, and to permit persons to whom the + * Software is furnished to do so, subject to the following conditions: + * + * The above copyright notice and this permission notice (including the next + * paragraph) shall be included in all copies or substantial portions of the + * Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + * DEALINGS IN THE SOFTWARE. + */ + +#include + +#include +#include +#include + +#include + +#include +#include + +static int profiler_proxy_marshal_add_listener(void *object, + struct spa_hook *listener, + const struct pw_profiler_events *events, + void *data) +{ + struct pw_proxy *proxy = object; + pw_proxy_add_object_listener(proxy, listener, events, data); + return 0; +} + +static int profiler_demarshal_add_listener(void *object, + const struct pw_protocol_native_message *msg) +{ + return -ENOTSUP; +} + +static int profiler_resource_marshal_profile(void *object, const struct spa_pod *pod) +{ + struct pw_resource *resource = object; + struct spa_pod_builder *b; + + b = pw_protocol_native_begin_resource(resource, PW_PROFILER_EVENT_PROFILE, NULL); + + spa_pod_builder_add_struct(b, SPA_POD_Pod(pod)); + + return pw_protocol_native_end_resource(resource, b); +} + +static int profiler_proxy_demarshal_profile(void *object, + const struct pw_protocol_native_message *msg) +{ + struct pw_proxy *proxy = object; + struct spa_pod_parser prs; + struct spa_pod *pod; + + spa_pod_parser_init(&prs, msg->data, msg->size); + + if (spa_pod_parser_get_struct(&prs, SPA_POD_Pod(&pod)) < 0) + return -EINVAL; + + pw_proxy_notify(proxy, struct pw_profiler_events, profile, 0, pod); + return 0; +} + + +static const struct pw_profiler_methods pw_protocol_native_profiler_client_method_marshal = { + PW_VERSION_PROFILER_METHODS, + .add_listener = &profiler_proxy_marshal_add_listener, +}; + +static const struct pw_protocol_native_demarshal +pw_protocol_native_profiler_server_method_demarshal[PW_PROFILER_METHOD_NUM] = +{ + [PW_PROFILER_METHOD_ADD_LISTENER] = { &profiler_demarshal_add_listener, 0 }, +}; + +static const struct pw_profiler_events pw_protocol_native_profiler_server_event_marshal = { + PW_VERSION_PROFILER_EVENTS, + .profile = &profiler_resource_marshal_profile, +}; + +static const struct pw_protocol_native_demarshal +pw_protocol_native_profiler_client_event_demarshal[PW_PROFILER_EVENT_NUM] = +{ + [PW_PROFILER_EVENT_PROFILE] = { &profiler_proxy_demarshal_profile, 0 }, +}; + +static const struct pw_protocol_marshal pw_protocol_native_profiler_marshal = { + PW_TYPE_INTERFACE_Profiler, + PW_VERSION_PROFILER, + 0, + PW_PROFILER_METHOD_NUM, + PW_PROFILER_EVENT_NUM, + .client_marshal = &pw_protocol_native_profiler_client_method_marshal, + .server_demarshal = pw_protocol_native_profiler_server_method_demarshal, + .server_marshal = &pw_protocol_native_profiler_server_event_marshal, + .client_demarshal = pw_protocol_native_profiler_client_event_demarshal, +}; + +int pw_protocol_native_ext_profiler_init(struct pw_context *context) +{ + struct pw_protocol *protocol; + + protocol = pw_context_find_protocol(context, PW_TYPE_INFO_PROTOCOL_Native); + if (protocol == NULL) + return -EPROTO; + + pw_protocol_add_marshal(protocol, &pw_protocol_native_profiler_marshal); + return 0; +} diff --git a/src/tools/meson.build b/src/tools/meson.build index 2df7b602a..dcd116aca 100644 --- a/src/tools/meson.build +++ b/src/tools/meson.build @@ -17,6 +17,13 @@ executable('pw-dot', dependencies : [pipewire_dep], ) +executable('pw-profiler', + 'pw-profiler.c', + c_args : [ '-D_GNU_SOURCE' ], + install: true, + dependencies : [pipewire_dep], +) + if get_option('pw-cat') and sndfile_dep.found() pwcat_sources = [ diff --git a/src/tools/pw-profiler.c b/src/tools/pw-profiler.c new file mode 100644 index 000000000..120073c00 --- /dev/null +++ b/src/tools/pw-profiler.c @@ -0,0 +1,515 @@ +/* PipeWire + * + * Copyright © 2020 Wim Taymans + * + * Permission is hereby granted, free of charge, to any person obtaining a + * copy of this software and associated documentation files (the "Software"), + * to deal in the Software without restriction, including without limitation + * the rights to use, copy, modify, merge, publish, distribute, sublicense, + * and/or sell copies of the Software, and to permit persons to whom the + * Software is furnished to do so, subject to the following conditions: + * + * The above copyright notice and this permission notice (including the next + * paragraph) shall be included in all copies or substantial portions of the + * Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + * DEALINGS IN THE SOFTWARE. + */ + +#include +#include + +#include +#include +#include + +#include +#include + +#define MAX_NAME 128 +#define MAX_FOLLOWERS 64 +#define DEFAULT_FILENAME "profiler.log" + +struct follower { + uint32_t id; + char name[MAX_NAME]; +}; + +struct data { + struct pw_main_loop *loop; + struct pw_context *context; + + struct pw_core *core; + struct spa_hook core_listener; + + struct pw_registry *registry; + struct spa_hook registry_listener; + + const char *filename; + FILE *output; + + int n_followers; + struct follower followers[MAX_FOLLOWERS]; +}; + +struct proxy_data { + struct data *data; + struct pw_proxy *proxy; + struct spa_hook object_listener; +}; + +struct measurement { + int64_t period; + int32_t status; + int64_t prev_signal; + int64_t signal; + int64_t awake; + int64_t finish; +}; + +struct point { + float period_usecs; + struct measurement driver; + struct measurement follower[MAX_FOLLOWERS]; +}; + +static void process_driver_block(struct data *d, const struct spa_pod *pod, struct point *point) +{ + union { + int64_t l; + int32_t i; + char *s; + float f; + double d; + struct spa_fraction F; + } dummy; + struct spa_io_clock clock; + + spa_pod_parse_struct(pod, + SPA_POD_Long(&dummy.l), + SPA_POD_Int(&dummy.i), + SPA_POD_String(&dummy.s), + SPA_POD_Float(&dummy.f), + SPA_POD_Float(&dummy.f), + SPA_POD_Float(&dummy.f), + SPA_POD_Long(&clock.nsec), + SPA_POD_Fraction(&clock.rate), + SPA_POD_Long(&clock.position), + SPA_POD_Long(&clock.duration), + SPA_POD_Long(&clock.delay), + SPA_POD_Double(&clock.rate_diff), + SPA_POD_Long(&clock.next_nsec), + SPA_POD_Long(&point->driver.prev_signal), + SPA_POD_Long(&point->driver.signal), + SPA_POD_Long(&point->driver.awake), + SPA_POD_Long(&point->driver.finish), + SPA_POD_Int(&point->driver.status)); + + point->period_usecs = clock.duration * (float)SPA_USEC_PER_SEC / (clock.rate.denom * clock.rate_diff); +} + +static int find_follower(struct data *d, uint32_t id, const char *name) +{ + int i; + for (i = 0; i < d->n_followers; i++) { + if (d->followers[i].id == id && strcmp(d->followers[i].name, name) == 0) + return i; + } + return -1; +} +static int add_follower(struct data *d, uint32_t id, const char *name) +{ + int idx = d->n_followers; + + if (idx == MAX_FOLLOWERS) + return -1; + + d->n_followers++; + + strncpy(d->followers[idx].name, name, MAX_NAME); + d->followers[idx].name[MAX_NAME-1] = '\0'; + d->followers[idx].id = id; + + return idx; +} + +static void process_follower_block(struct data *d, const struct spa_pod *pod, struct point *point) +{ + uint32_t id; + const char *name; + struct measurement m; + int idx; + + spa_zero(m); + spa_pod_parse_struct(pod, + SPA_POD_Int(&id), + SPA_POD_String(&name), + SPA_POD_Long(&m.signal), + SPA_POD_Long(&m.awake), + SPA_POD_Long(&m.finish), + SPA_POD_Int(&m.status)); + + if ((idx = find_follower(d, id, name)) < 0) { + if ((idx = add_follower(d, id, name)) < 0) { + pw_log_warn("too many followers"); + return; + } + } + point->follower[idx] = m; +} + +static void dump_point(struct data *d, struct point *point) +{ + int i; + int64_t d1, d2; + + d1 = (point->driver.signal - point->driver.prev_signal) / 1000; + d2 = (point->driver.finish - point->driver.signal) / 1000; + + if (d1 > point->period_usecs * 1.3 || + d2 > point->period_usecs * 1.3) + d1 = d2 = point->period_usecs * 1.4; + + fprintf(d->output, "%"PRIi64"\t%"PRIi64"\t", d1 > 0 ? d1 : 0, d2 > 0 ? d2 : 0); + + for (i = 0; i < MAX_FOLLOWERS; i++) { + if (point->follower[i].status == 0) { + fprintf(d->output, " \t \t \t \t \t \t \t"); + } else { + int64_t d4 = (point->follower[i].signal - point->driver.signal) / 1000; + int64_t d5 = (point->follower[i].awake - point->driver.signal) / 1000; + int64_t d6 = (point->follower[i].finish - point->driver.signal) / 1000; + + fprintf(d->output, "%u\t%"PRIi64"\t%"PRIi64"\t%"PRIi64"\t%"PRIi64"\t%"PRIi64"\t%d\t", + d->followers[i].id, + d4 > 0 ? d4 : 0, + d5 > 0 ? d5 : 0, + d6 > 0 ? d6 : 0, + (d5 > 0 && d4 > 0) ? d5 - d4 : 0, + (d6 > 0 && d5 > 0) ? d6 - d5 : 0, + point->follower[i].status); + } + } + fprintf(d->output, "\n"); +} + +static void dump_scripts(struct data *d) +{ + FILE *out; + int i; + + out = fopen("Timing1.plot", "w"); + if (out == NULL) { + pw_log_error("Can't open Timing1.plot: %m"); + } else { + fprintf(out, + "set output 'Timing1.svg\n" + "set terminal svg\n" + "set grid\n" + "set title \"Audio driver timing\"\n" + "set xlabel \"audio cycles\"\n" + "set ylabel \"usec\"\n" + "plot \"%s\" using 1 title \"Audio period\" with lines \n" + "unset output\n", d->filename); + fclose(out); + } + + out = fopen("Timing2.plot", "w"); + if (out == NULL) { + pw_log_error("Can't open Timing2.plot: %m"); + } else { + fprintf(out, + "set output 'Timing2.svg\n" + "set terminal svg\n" + "set grid\n" + "set title \"Driver end date\"\n" + "set xlabel \"audio cycles\"\n" + "set ylabel \"usec\"\n" + "plot \"%s\" using 2 title \"Driver end date\" with lines \n" + "unset output\n", d->filename); + fclose(out); + } + + out = fopen("Timing3.plot", "w"); + if (out == NULL) { + pw_log_error("Can't open Timing3.plot: %m"); + } else { + fprintf(out, + "set output 'Timing3.svg\n" + "set terminal svg\n" + "set multiplot\n" + "set grid\n" + "set title \"Clients end date\"\n" + "set xlabel \"audio cycles\"\n" + "set ylabel \"usec\"\n" + "plot " + "\"%s\" using 1 title \"Audio period\" with lines%s", + d->filename, + d->n_followers > 0 ? ", " : ""); + + for (i = 0; i < d->n_followers; i++) { + fprintf(out, + "\"%s\" using %d title \"%s/%u\" with lines%s", + d->filename, ((i + 1) * 7) - 1, + d->followers[i].name, d->followers[i].id, + i+1 < d->n_followers ? ", " : ""); + } + fprintf(out, + "\nunset multiplot\n" + "unset output\n"); + fclose(out); + } + + out = fopen("Timing4.plot", "w"); + if (out == NULL) { + pw_log_error("Can't open Timing4.plot: %m"); + } else { + fprintf(out, + "set output 'Timing4.svg\n" + "set terminal svg\n" + "set multiplot\n" + "set grid\n" + "set title \"Clients scheduling latency\"\n" + "set xlabel \"audio cycles\"\n" + "set ylabel \"usec\"\n" + "plot "); + + for (i = 0; i < d->n_followers; i++) { + fprintf(out, + "\"%s\" using %d title \"%s/%u\" with lines%s", + d->filename, ((i + 1) * 7), + d->followers[i].name, d->followers[i].id, + i+1 < d->n_followers ? ", " : ""); + } + fprintf(out, + "\nunset multiplot\n" + "unset output\n"); + fclose(out); + } + + out = fopen("Timing5.plot", "w"); + if (out == NULL) { + pw_log_error("Can't open Timing5.plot: %m"); + } else { + fprintf(out, + "set output 'Timing5.svg\n" + "set terminal svg\n" + "set multiplot\n" + "set grid\n" + "set title \"Clients duration\"\n" + "set xlabel \"audio cycles\"\n" + "set ylabel \"usec\"\n" + "plot "); + + for (i = 0; i < d->n_followers; i++) { + fprintf(out, + "\"%s\" using %d title \"%s/%u\" with lines%s", + d->filename, ((i + 1) * 7) + 1, + d->followers[i].name, d->followers[i].id, + i+1 < d->n_followers ? ", " : ""); + } + fprintf(out, + "\nunset multiplot\n" + "unset output\n"); + fclose(out); + } + out = fopen("Timings.html", "w"); + if (out == NULL) { + pw_log_error("Can't open Timings.html: %m"); + } else { + fprintf(out, + "\n" + "\n" + "\n" + " \n" + " PipeWire profiling\n" + " \n" + " \n" + " \n" + " \n" + "

PipeWire profiling

\n" + "
Timing1
" + "
Timing2
" + "
Timing3
" + "
Timing4
" + "
Timing5
" + " \n" + "\n"); + fclose(out); + } + + out = fopen("generate_timings.sh", "w"); + if (out == NULL) { + pw_log_error("Can't open generate_timings.sh: %m"); + } else { + fprintf(out, + "gnuplot -persist Timing1.plot\n" + "gnuplot -persist Timing2.plot\n" + "gnuplot -persist Timing3.plot\n" + "gnuplot -persist Timing4.plot\n" + "gnuplot -persist Timing5.plot\n"); + fclose(out); + } +} + +static void profiler_profile(void *data, const struct spa_pod *pod) +{ + struct data *d = data; + struct spa_pod *o; + struct spa_pod_prop *p; + struct point point; + + SPA_POD_STRUCT_FOREACH(pod, o) { + if (!spa_pod_is_object_type(o, SPA_TYPE_OBJECT_Profiler)) + continue; + + spa_zero(point); + SPA_POD_OBJECT_FOREACH((struct spa_pod_object*)o, p) { + switch(p->key) { + case SPA_PROFILER_driverBlock: + process_driver_block(d, &p->value, &point); + break; + case SPA_PROFILER_followerBlock: + process_follower_block(d, &p->value, &point); + break; + default: + break; + } + } + dump_point(d, &point); + } +} + +static const struct pw_profiler_events profiler_events = { + PW_VERSION_PROFILER_EVENTS, + .profile = profiler_profile, +}; + +static void registry_event_global(void *data, uint32_t id, + uint32_t permissions, const char *type, uint32_t version, + const struct spa_dict *props) +{ + struct data *d = data; + struct pw_proxy *proxy; + struct proxy_data *pd; + + if (strcmp(type, PW_TYPE_INTERFACE_Profiler) != 0) + return; + + proxy = pw_registry_bind(d->registry, id, type, + PW_VERSION_PROFILER, sizeof(struct proxy_data)); + if (proxy == NULL) + goto no_mem; + + pd = pw_proxy_get_user_data(proxy); + pd->data = d; + pd->proxy = proxy; + + pw_proxy_add_object_listener(proxy, &pd->object_listener, &profiler_events, d); + + return; + +no_mem: + pw_log_error("failed to create proxy"); + return; +} + +static const struct pw_registry_events registry_events = { + PW_VERSION_REGISTRY_EVENTS, + .global = registry_event_global, +}; + +static void on_core_error(void *_data, uint32_t id, int seq, int res, const char *message) +{ + struct data *data = _data; + + pw_log_error("error id:%u seq:%d res:%d (%s): %s", + id, seq, res, spa_strerror(res), message); + if (id == 0) { + pw_main_loop_quit(data->loop); + } +} + +static const struct pw_core_events core_events = { + PW_VERSION_CORE_EVENTS, + .error = on_core_error, +}; + +static void do_quit(void *data, int signal_number) +{ + struct data *d = data; + pw_main_loop_quit(d->loop); +} + +int main(int argc, char *argv[]) +{ + struct data data = { 0 }; + struct pw_loop *l; + struct pw_properties *props = NULL; + + pw_init(&argc, &argv); + + data.loop = pw_main_loop_new(NULL); + if (data.loop == NULL) { + fprintf(stderr, "Can't create data loop: %m"); + return -1; + } + + l = pw_main_loop_get_loop(data.loop); + pw_loop_add_signal(l, SIGINT, do_quit, &data); + pw_loop_add_signal(l, SIGTERM, do_quit, &data); + + data.context = pw_context_new(l, NULL, 0); + if (data.context == NULL) { + fprintf(stderr, "Can't create context: %m"); + return -1; + } + + pw_context_load_module(data.context, PW_EXTENSION_MODULE_PROFILER, NULL, NULL); + + if (argc > 1) + props = pw_properties_new(PW_KEY_REMOTE_NAME, argv[1], NULL); + + data.core = pw_context_connect(data.context, props, 0); + if (data.core == NULL) { + fprintf(stderr, "Can't connect: %m"); + return -1; + } + + data.filename = DEFAULT_FILENAME; + + data.output = fopen(data.filename, "w"); + if (data.output == NULL) { + fprintf(stderr, "Can't open file %s: %m", data.filename); + return -1; + } + + pw_core_add_listener(data.core, + &data.core_listener, + &core_events, &data); + data.registry = pw_core_get_registry(data.core, + PW_VERSION_REGISTRY, 0); + pw_registry_add_listener(data.registry, + &data.registry_listener, + ®istry_events, &data); + + pw_main_loop_run(data.loop); + + pw_context_destroy(data.context); + pw_main_loop_destroy(data.loop); + + fclose(data.output); + + dump_scripts(&data); + + return 0; +}