spa: sprinkle more log topics into spa

This commit is contained in:
Peter Hutterer 2021-09-27 15:31:35 +10:00 committed by Wim Taymans
parent e3b216c026
commit b3646743c1
3 changed files with 43 additions and 34 deletions

View file

@ -42,7 +42,9 @@
#include <spa/utils/names.h> #include <spa/utils/names.h>
#include <spa/utils/string.h> #include <spa/utils/string.h>
#define NAME "cpu" static struct spa_log_topic log_topic = SPA_LOG_TOPIC(0, "spa.cpu");
#undef SPA_LOG_TOPIC_DEFAULT
#define SPA_LOG_TOPIC_DEFAULT &log_topic
struct impl { struct impl {
struct spa_handle handle; struct spa_handle handle;
@ -250,6 +252,7 @@ impl_init(const struct spa_handle_factory *factory,
&impl_cpu, this); &impl_cpu, this);
this->log = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_Log); this->log = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_Log);
spa_log_topic_init(this->log, &log_topic);
this->flags = 0; this->flags = 0;
this->force = SPA_CPU_FORCE_AUTODETECT; this->force = SPA_CPU_FORCE_AUTODETECT;
@ -264,7 +267,7 @@ impl_init(const struct spa_handle_factory *factory,
this->vm_type = atoi(str); this->vm_type = atoi(str);
} }
spa_log_debug(this->log, NAME " %p: count:%d align:%d flags:%08x", spa_log_debug(this->log, "%p: count:%d align:%d flags:%08x",
this, this->count, this->max_align, this->flags); this, this->count, this->max_align, this->flags);
return 0; return 0;

View file

@ -41,7 +41,9 @@
#include <spa/utils/ringbuffer.h> #include <spa/utils/ringbuffer.h>
#include <spa/utils/string.h> #include <spa/utils/string.h>
#define NAME "loop" static struct spa_log_topic log_topic = SPA_LOG_TOPIC(0, "spa.loop");
#undef SPA_LOG_TOPIC_DEFAULT
#define SPA_LOG_TOPIC_DEFAULT &log_topic
#define DATAS_SIZE (4096 * 8) #define DATAS_SIZE (4096 * 8)
@ -138,7 +140,7 @@ static void flush_items(struct impl *impl)
item = SPA_PTROFF(impl->buffer_data, index & (DATAS_SIZE - 1), struct invoke_item); item = SPA_PTROFF(impl->buffer_data, index & (DATAS_SIZE - 1), struct invoke_item);
block = item->block; block = item->block;
spa_log_trace(impl->log, NAME " %p: flush item %p", impl, item); spa_log_trace(impl->log, "%p: flush item %p", impl, item);
item->res = item->func ? item->func(&impl->loop, item->res = item->func ? item->func(&impl->loop,
true, item->seq, item->data, item->size, true, item->seq, item->data, item->size,
item->user_data) : 0; item->user_data) : 0;
@ -147,7 +149,7 @@ static void flush_items(struct impl *impl)
if (block) { if (block) {
if ((res = spa_system_eventfd_write(impl->system, impl->ack_fd, 1)) < 0) if ((res = spa_system_eventfd_write(impl->system, impl->ack_fd, 1)) < 0)
spa_log_warn(impl->log, NAME " %p: failed to write event fd: %s", spa_log_warn(impl->log, "%p: failed to write event fd: %s",
impl, spa_strerror(res)); impl, spa_strerror(res));
} }
} }
@ -188,12 +190,12 @@ loop_invoke(void *object,
filled = spa_ringbuffer_get_write_index(&impl->buffer, &idx); filled = spa_ringbuffer_get_write_index(&impl->buffer, &idx);
if (filled < 0 || filled > DATAS_SIZE) { if (filled < 0 || filled > DATAS_SIZE) {
spa_log_warn(impl->log, NAME " %p: queue xrun %d", impl, filled); spa_log_warn(impl->log, "%p: queue xrun %d", impl, filled);
return -EPIPE; return -EPIPE;
} }
avail = DATAS_SIZE - filled; avail = DATAS_SIZE - filled;
if (avail < sizeof(struct invoke_item)) { if (avail < sizeof(struct invoke_item)) {
spa_log_warn(impl->log, NAME " %p: queue full %d", impl, avail); spa_log_warn(impl->log, "%p: queue full %d", impl, avail);
return -EPIPE; return -EPIPE;
} }
offset = idx & (DATAS_SIZE - 1); offset = idx & (DATAS_SIZE - 1);
@ -210,7 +212,7 @@ loop_invoke(void *object,
item->user_data = user_data; item->user_data = user_data;
item->item_size = SPA_ROUND_UP_N(sizeof(struct invoke_item) + size, 8); item->item_size = SPA_ROUND_UP_N(sizeof(struct invoke_item) + size, 8);
spa_log_trace(impl->log, NAME " %p: add item %p filled:%d", impl, item, filled); spa_log_trace(impl->log, "%p: add item %p filled:%d", impl, item, filled);
if (l0 >= item->item_size) { if (l0 >= item->item_size) {
/* item + size fit in current ringbuffer idx */ /* item + size fit in current ringbuffer idx */
@ -227,7 +229,7 @@ loop_invoke(void *object,
item->item_size = SPA_ROUND_UP_N(l0 + size, 8); item->item_size = SPA_ROUND_UP_N(l0 + size, 8);
} }
if (avail < item->item_size) { if (avail < item->item_size) {
spa_log_warn(impl->log, NAME " %p: queue full %d, need %zd", impl, avail, spa_log_warn(impl->log, "%p: queue full %d, need %zd", impl, avail,
item->item_size); item->item_size);
return -EPIPE; return -EPIPE;
} }
@ -244,7 +246,7 @@ loop_invoke(void *object,
spa_loop_control_hook_before(&impl->hooks_list); spa_loop_control_hook_before(&impl->hooks_list);
if ((res = spa_system_eventfd_read(impl->system, impl->ack_fd, &count)) < 0) if ((res = spa_system_eventfd_read(impl->system, impl->ack_fd, &count)) < 0)
spa_log_warn(impl->log, NAME " %p: failed to read event fd: %s", spa_log_warn(impl->log, "%p: failed to read event fd: %s",
impl, spa_strerror(res)); impl, spa_strerror(res));
spa_loop_control_hook_after(&impl->hooks_list); spa_loop_control_hook_after(&impl->hooks_list);
@ -286,13 +288,13 @@ static void loop_enter(void *object)
{ {
struct impl *impl = object; struct impl *impl = object;
impl->thread = pthread_self(); impl->thread = pthread_self();
spa_log_trace(impl->log, NAME" %p: enter %lu", impl, impl->thread); spa_log_trace(impl->log, "%p: enter %lu", impl, impl->thread);
} }
static void loop_leave(void *object) static void loop_leave(void *object)
{ {
struct impl *impl = object; struct impl *impl = object;
spa_log_trace(impl->log, NAME" %p: leave %lu", impl, impl->thread); spa_log_trace(impl->log, "%p: leave %lu", impl, impl->thread);
impl->thread = 0; impl->thread = 0;
} }
@ -341,7 +343,7 @@ static int loop_iterate(void *object, int timeout)
static void source_io_func(struct spa_source *source) static void source_io_func(struct spa_source *source)
{ {
struct source_impl *impl = SPA_CONTAINER_OF(source, struct source_impl, source); struct source_impl *impl = SPA_CONTAINER_OF(source, struct source_impl, source);
spa_log_trace_fp(impl->impl->log, NAME" %p: io %08x", impl, source->rmask); spa_log_trace_fp(impl->impl->log, "%p: io %08x", impl, source->rmask);
impl->func.io(source->data, source->fd, source->rmask); impl->func.io(source->data, source->fd, source->rmask);
} }
@ -378,7 +380,7 @@ static struct spa_source *loop_add_io(void *object,
source->fallback = spa_loop_utils_add_idle(&impl->utils, source->fallback = spa_loop_utils_add_idle(&impl->utils,
mask & (SPA_IO_IN | SPA_IO_OUT) ? true : false, mask & (SPA_IO_IN | SPA_IO_OUT) ? true : false,
(spa_source_idle_func_t) source_io_func, source); (spa_source_idle_func_t) source_io_func, source);
spa_log_trace(impl->log, NAME" %p: adding fallback %p", impl, spa_log_trace(impl->log, "%p: adding fallback %p", impl,
source->fallback); source->fallback);
} }
@ -399,7 +401,7 @@ static int loop_update_io(void *object, struct spa_source *source, uint32_t mask
struct source_impl *s = SPA_CONTAINER_OF(source, struct source_impl, source); struct source_impl *s = SPA_CONTAINER_OF(source, struct source_impl, source);
int res; int res;
source->mask = mask; source->mask = mask;
spa_log_trace(impl->log, NAME" %p: update %08x", s, mask); spa_log_trace(impl->log, "%p: update %08x", s, mask);
if (s->fallback) if (s->fallback)
res = spa_loop_utils_enable_idle(&impl->utils, s->fallback, res = spa_loop_utils_enable_idle(&impl->utils, s->fallback,
mask & (SPA_IO_IN | SPA_IO_OUT) ? true : false); mask & (SPA_IO_IN | SPA_IO_OUT) ? true : false);
@ -421,12 +423,12 @@ static int loop_enable_idle(void *object, struct spa_source *source, bool enable
if (enabled && !impl->enabled) { if (enabled && !impl->enabled) {
if ((res = spa_system_eventfd_write(impl->impl->system, source->fd, 1)) < 0) if ((res = spa_system_eventfd_write(impl->impl->system, source->fd, 1)) < 0)
spa_log_warn(impl->impl->log, NAME " %p: failed to write idle fd %d: %s", spa_log_warn(impl->impl->log, "%p: failed to write idle fd %d: %s",
source, source->fd, spa_strerror(res)); source, source->fd, spa_strerror(res));
} else if (!enabled && impl->enabled) { } else if (!enabled && impl->enabled) {
uint64_t count; uint64_t count;
if ((res = spa_system_eventfd_read(impl->impl->system, source->fd, &count)) < 0) if ((res = spa_system_eventfd_read(impl->impl->system, source->fd, &count)) < 0)
spa_log_warn(impl->impl->log, NAME " %p: failed to read idle fd %d: %s", spa_log_warn(impl->impl->log, "%p: failed to read idle fd %d: %s",
source, source->fd, spa_strerror(res)); source, source->fd, spa_strerror(res));
} }
impl->enabled = enabled; impl->enabled = enabled;
@ -482,7 +484,7 @@ static void source_event_func(struct spa_source *source)
int res; int res;
if ((res = spa_system_eventfd_read(impl->impl->system, source->fd, &count)) < 0) if ((res = spa_system_eventfd_read(impl->impl->system, source->fd, &count)) < 0)
spa_log_warn(impl->impl->log, NAME " %p: failed to read event fd %d: %s", spa_log_warn(impl->impl->log, "%p: failed to read event fd %d: %s",
source, source->fd, spa_strerror(res)); source, source->fd, spa_strerror(res));
impl->func.event(source->data, count); impl->func.event(source->data, count);
@ -533,7 +535,7 @@ static int loop_signal_event(void *object, struct spa_source *source)
int res; int res;
if (SPA_UNLIKELY((res = spa_system_eventfd_write(impl->impl->system, source->fd, 1)) < 0)) if (SPA_UNLIKELY((res = spa_system_eventfd_write(impl->impl->system, source->fd, 1)) < 0))
spa_log_warn(impl->impl->log, NAME " %p: failed to write event fd %d: %s", spa_log_warn(impl->impl->log, "%p: failed to write event fd %d: %s",
source, source->fd, spa_strerror(res)); source, source->fd, spa_strerror(res));
return res; return res;
} }
@ -546,7 +548,7 @@ static void source_timer_func(struct spa_source *source)
if (SPA_UNLIKELY((res = spa_system_timerfd_read(impl->impl->system, if (SPA_UNLIKELY((res = spa_system_timerfd_read(impl->impl->system,
source->fd, &expirations)) < 0)) source->fd, &expirations)) < 0))
spa_log_warn(impl->impl->log, NAME " %p: failed to read timer fd %d: %s", spa_log_warn(impl->impl->log, "%p: failed to read timer fd %d: %s",
source, source->fd, spa_strerror(res)); source, source->fd, spa_strerror(res));
impl->func.timer(source->data, expirations); impl->func.timer(source->data, expirations);
@ -624,7 +626,7 @@ static void source_signal_func(struct spa_source *source)
int res, signal_number = 0; int res, signal_number = 0;
if ((res = spa_system_signalfd_read(impl->impl->system, source->fd, &signal_number)) < 0) if ((res = spa_system_signalfd_read(impl->impl->system, source->fd, &signal_number)) < 0)
spa_log_warn(impl->impl->log, NAME " %p: failed to read signal fd %d: %s", spa_log_warn(impl->impl->log, "%p: failed to read signal fd %d: %s",
source, source->fd, spa_strerror(res)); source, source->fd, spa_strerror(res));
impl->func.signal(source->data, signal_number); impl->func.signal(source->data, signal_number);
@ -675,7 +677,7 @@ static void loop_destroy_source(void *object, struct spa_source *source)
{ {
struct source_impl *impl = SPA_CONTAINER_OF(source, struct source_impl, source); struct source_impl *impl = SPA_CONTAINER_OF(source, struct source_impl, source);
spa_log_trace(impl->impl->log, NAME" %p ", impl); spa_log_trace(impl->impl->log, "%p ", impl);
spa_list_remove(&impl->link); spa_list_remove(&impl->link);
@ -801,16 +803,17 @@ impl_init(const struct spa_handle_factory *factory,
&impl_loop_utils, impl); &impl_loop_utils, impl);
impl->log = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_Log); impl->log = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_Log);
spa_log_topic_init(impl->log, &log_topic);
impl->system = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_System); impl->system = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_System);
if (impl->system == NULL) { if (impl->system == NULL) {
spa_log_error(impl->log, NAME " %p: a System is needed", impl); spa_log_error(impl->log, "%p: a System is needed", impl);
res = -EINVAL; res = -EINVAL;
goto error_exit; goto error_exit;
} }
if ((res = spa_system_pollfd_create(impl->system, SPA_FD_CLOEXEC)) < 0) { if ((res = spa_system_pollfd_create(impl->system, SPA_FD_CLOEXEC)) < 0) {
spa_log_error(impl->log, NAME " %p: can't create pollfd: %s", spa_log_error(impl->log, "%p: can't create pollfd: %s",
impl, spa_strerror(res)); impl, spa_strerror(res));
goto error_exit; goto error_exit;
} }
@ -826,18 +829,18 @@ impl_init(const struct spa_handle_factory *factory,
impl->wakeup = loop_add_event(impl, wakeup_func, impl); impl->wakeup = loop_add_event(impl, wakeup_func, impl);
if (impl->wakeup == NULL) { if (impl->wakeup == NULL) {
res = -errno; res = -errno;
spa_log_error(impl->log, NAME " %p: can't create wakeup event: %m", impl); spa_log_error(impl->log, "%p: can't create wakeup event: %m", impl);
goto error_exit_free_poll; goto error_exit_free_poll;
} }
if ((res = spa_system_eventfd_create(impl->system, if ((res = spa_system_eventfd_create(impl->system,
SPA_FD_EVENT_SEMAPHORE | SPA_FD_CLOEXEC)) < 0) { SPA_FD_EVENT_SEMAPHORE | SPA_FD_CLOEXEC)) < 0) {
spa_log_error(impl->log, NAME " %p: can't create ack event: %s", spa_log_error(impl->log, "%p: can't create ack event: %s",
impl, spa_strerror(res)); impl, spa_strerror(res));
goto error_exit_free_wakeup; goto error_exit_free_wakeup;
} }
impl->ack_fd = res; impl->ack_fd = res;
spa_log_debug(impl->log, NAME " %p: initialized", impl); spa_log_debug(impl->log, "%p: initialized", impl);
return 0; return 0;

View file

@ -41,7 +41,9 @@
#include <spa/utils/names.h> #include <spa/utils/names.h>
#include <spa/utils/string.h> #include <spa/utils/string.h>
#define NAME "system" static struct spa_log_topic log_topic = SPA_LOG_TOPIC(0, "spa.system");
#undef SPA_LOG_TOPIC_DEFAULT
#define SPA_LOG_TOPIC_DEFAULT &log_topic
#ifndef TFD_TIMER_CANCEL_ON_SET #ifndef TFD_TIMER_CANCEL_ON_SET
# define TFD_TIMER_CANCEL_ON_SET (1 << 1) # define TFD_TIMER_CANCEL_ON_SET (1 << 1)
@ -83,7 +85,7 @@ static int impl_close(void *object, int fd)
{ {
struct impl *impl = object; struct impl *impl = object;
int res = close(fd); int res = close(fd);
spa_log_debug(impl->log, NAME " %p: close fd:%d", impl, fd); spa_log_debug(impl->log, "%p: close fd:%d", impl, fd);
return res < 0 ? -errno : res; return res < 0 ? -errno : res;
} }
@ -110,7 +112,7 @@ static int impl_pollfd_create(void *object, int flags)
if (flags & SPA_FD_CLOEXEC) if (flags & SPA_FD_CLOEXEC)
fl |= EPOLL_CLOEXEC; fl |= EPOLL_CLOEXEC;
res = epoll_create1(fl); res = epoll_create1(fl);
spa_log_debug(impl->log, NAME " %p: new fd:%d", impl, res); spa_log_debug(impl->log, "%p: new fd:%d", impl, res);
return res < 0 ? -errno : res; return res < 0 ? -errno : res;
} }
@ -172,7 +174,7 @@ static int impl_timerfd_create(void *object, int clockid, int flags)
if (flags & SPA_FD_NONBLOCK) if (flags & SPA_FD_NONBLOCK)
fl |= TFD_NONBLOCK; fl |= TFD_NONBLOCK;
res = timerfd_create(clockid, fl); res = timerfd_create(clockid, fl);
spa_log_debug(impl->log, NAME " %p: new fd:%d", impl, res); spa_log_debug(impl->log, "%p: new fd:%d", impl, res);
return res < 0 ? -errno : res; return res < 0 ? -errno : res;
} }
@ -216,7 +218,7 @@ static int impl_eventfd_create(void *object, int flags)
if (flags & SPA_FD_EVENT_SEMAPHORE) if (flags & SPA_FD_EVENT_SEMAPHORE)
fl |= EFD_SEMAPHORE; fl |= EFD_SEMAPHORE;
res = eventfd(0, fl); res = eventfd(0, fl);
spa_log_debug(impl->log, NAME " %p: new fd:%d", impl, res); spa_log_debug(impl->log, "%p: new fd:%d", impl, res);
return res < 0 ? -errno : res; return res < 0 ? -errno : res;
} }
@ -250,7 +252,7 @@ static int impl_signalfd_create(void *object, int signal, int flags)
sigaddset(&mask, signal); sigaddset(&mask, signal);
res = signalfd(-1, &mask, fl); res = signalfd(-1, &mask, fl);
sigprocmask(SIG_BLOCK, &mask, NULL); sigprocmask(SIG_BLOCK, &mask, NULL);
spa_log_debug(impl->log, NAME " %p: new fd:%d", impl, res); spa_log_debug(impl->log, "%p: new fd:%d", impl, res);
return res < 0 ? -errno : res; return res < 0 ? -errno : res;
} }
@ -345,8 +347,9 @@ impl_init(const struct spa_handle_factory *factory,
&impl_system, impl); &impl_system, impl);
impl->log = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_Log); impl->log = spa_support_find(support, n_support, SPA_TYPE_INTERFACE_Log);
spa_log_topic_init(impl->log, &log_topic);
spa_log_debug(impl->log, NAME " %p: initialized", impl); spa_log_debug(impl->log, "%p: initialized", impl);
return 0; return 0;
} }