From 77d3beb0ee82b0db15f81a8c73ab15be61f50aae Mon Sep 17 00:00:00 2001 From: Tanu Kaskinen Date: Thu, 28 Dec 2017 12:09:19 +0200 Subject: [PATCH] sink, source: improve suspend cause logging Previously the suspend cause was logged as a hexadecimal number, now it's logged as a human-friendly string. Also, the command line interface handled only a subset of causes when printing them, now all suspend causes are printed. Change-Id: I4388ae2a49c784fbd82318b82cf0793d121e68a7 Signed-off-by: Sangchul Lee --- src/pulsecore/cli-text.c | 16 ++++++---------- src/pulsecore/core.c | 41 +++++++++++++++++++++++++++++++++++++++++ src/pulsecore/core.h | 12 +++++++++++- src/pulsecore/sink.c | 13 +++++++++++-- src/pulsecore/source.c | 13 +++++++++++-- 5 files changed, 80 insertions(+), 15 deletions(-) diff --git a/src/pulsecore/cli-text.c b/src/pulsecore/cli-text.c index 794f51c..474f336 100644 --- a/src/pulsecore/cli-text.c +++ b/src/pulsecore/cli-text.c @@ -212,6 +212,7 @@ char *pa_sink_list_to_string(pa_core *c) { v[PA_VOLUME_SNPRINT_VERBOSE_MAX], cm[PA_CHANNEL_MAP_SNPRINT_MAX], *t; const char *cmn; + char suspend_cause_buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]; cmn = pa_channel_map_to_pretty_name(&sink->channel_map); @@ -222,7 +223,7 @@ char *pa_sink_list_to_string(pa_core *c) { "\tdriver: <%s>\n" "\tflags: %s%s%s%s%s%s%s%s\n" "\tstate: %s\n" - "\tsuspend cause: %s%s%s%s\n" + "\tsuspend cause: %s\n" "\tpriority: %u\n" "\tvolume: %s\n" "\t balance %0.2f\n" @@ -250,10 +251,7 @@ char *pa_sink_list_to_string(pa_core *c) { sink->flags & PA_SINK_FLAT_VOLUME ? "FLAT_VOLUME " : "", sink->flags & PA_SINK_DYNAMIC_LATENCY ? "DYNAMIC_LATENCY" : "", pa_sink_state_to_string(pa_sink_get_state(sink)), - sink->suspend_cause & PA_SUSPEND_USER ? "USER " : "", - sink->suspend_cause & PA_SUSPEND_APPLICATION ? "APPLICATION " : "", - sink->suspend_cause & PA_SUSPEND_IDLE ? "IDLE " : "", - sink->suspend_cause & PA_SUSPEND_SESSION ? "SESSION" : "", + pa_suspend_cause_to_string(sink->suspend_cause, suspend_cause_buf), sink->priority, pa_cvolume_snprint_verbose(cv, sizeof(cv), @@ -328,6 +326,7 @@ char *pa_source_list_to_string(pa_core *c) { v[PA_VOLUME_SNPRINT_VERBOSE_MAX], cm[PA_CHANNEL_MAP_SNPRINT_MAX], *t; const char *cmn; + char suspend_cause_buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]; cmn = pa_channel_map_to_pretty_name(&source->channel_map); @@ -338,7 +337,7 @@ char *pa_source_list_to_string(pa_core *c) { "\tdriver: <%s>\n" "\tflags: %s%s%s%s%s%s%s\n" "\tstate: %s\n" - "\tsuspend cause: %s%s%s%s\n" + "\tsuspend cause: %s\n" "\tpriority: %u\n" "\tvolume: %s\n" "\t balance %0.2f\n" @@ -363,10 +362,7 @@ char *pa_source_list_to_string(pa_core *c) { source->flags & PA_SOURCE_LATENCY ? "LATENCY " : "", source->flags & PA_SOURCE_DYNAMIC_LATENCY ? "DYNAMIC_LATENCY" : "", pa_source_state_to_string(pa_source_get_state(source)), - source->suspend_cause & PA_SUSPEND_USER ? "USER " : "", - source->suspend_cause & PA_SUSPEND_APPLICATION ? "APPLICATION " : "", - source->suspend_cause & PA_SUSPEND_IDLE ? "IDLE " : "", - source->suspend_cause & PA_SUSPEND_SESSION ? "SESSION" : "", + pa_suspend_cause_to_string(source->suspend_cause, suspend_cause_buf), source->priority, pa_cvolume_snprint_verbose(cv, sizeof(cv), diff --git a/src/pulsecore/core.c b/src/pulsecore/core.c index 22dcd75..c26cc9b 100644 --- a/src/pulsecore/core.c +++ b/src/pulsecore/core.c @@ -509,3 +509,44 @@ void pa_core_rttime_restart(pa_core *c, pa_time_event *e, pa_usec_t usec) { c->mainloop->time_restart(e, pa_timeval_rtstore(&tv, usec, true)); } + +/* Helper macro to reduce repetition in pa_suspend_cause_to_string(). + * Parameters: + * char *p: the current position in the write buffer + * bool first: is cause_to_check the first cause to be written? + * pa_suspend_cause_t cause_bitfield: the causes given to pa_suspend_cause_to_string() + * pa_suspend_cause_t cause_to_check: the cause whose presence in cause_bitfield is to be checked + */ +#define CHECK_CAUSE(p, first, cause_bitfield, cause_to_check) \ + if (cause_bitfield & PA_SUSPEND_##cause_to_check) { \ + size_t len = sizeof(#cause_to_check) - 1; \ + if (!first) { \ + *p = '|'; \ + p++; \ + } \ + first = false; \ + memcpy(p, #cause_to_check, len); \ + p += len; \ + } + +const char *pa_suspend_cause_to_string(pa_suspend_cause_t cause_bitfield, char buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]) { + char *p = buf; + bool first = true; + + CHECK_CAUSE(p, first, cause_bitfield, USER); + CHECK_CAUSE(p, first, cause_bitfield, APPLICATION); + CHECK_CAUSE(p, first, cause_bitfield, IDLE); + CHECK_CAUSE(p, first, cause_bitfield, SESSION); + CHECK_CAUSE(p, first, cause_bitfield, PASSTHROUGH); + CHECK_CAUSE(p, first, cause_bitfield, INTERNAL); + CHECK_CAUSE(p, first, cause_bitfield, UNAVAILABLE); + + if (p == buf) { + memcpy(p, "(none)", 6); + p += 6; + } + + *p = 0; + + return buf; +} diff --git a/src/pulsecore/core.h b/src/pulsecore/core.h index d6f250c..03f0885 100644 --- a/src/pulsecore/core.h +++ b/src/pulsecore/core.h @@ -26,7 +26,10 @@ #include /* This is a bitmask that encodes the cause why a sink/source is - * suspended. */ + * suspended. + * + * When adding new causes, remember to update pa_suspend_cause_to_string() and + * PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE! */ typedef enum pa_suspend_cause { PA_SUSPEND_USER = 1, /* Exposed to the user via some protocol */ PA_SUSPEND_APPLICATION = 2, /* Used by the device reservation logic */ @@ -297,4 +300,11 @@ void pa_core_maybe_vacuum(pa_core *c); pa_time_event* pa_core_rttime_new(pa_core *c, pa_usec_t usec, pa_time_event_cb_t cb, void *userdata); void pa_core_rttime_restart(pa_core *c, pa_time_event *e, pa_usec_t usec); +static const size_t PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE = + sizeof("USER|APPLICATION|IDLE|SESSION|PASSTHROUGH|INTERNAL|UNAVAILABLE"); + +/* Converts the given suspend cause to a string. The string is written to the + * provided buffer. The same buffer is the return value of this function. */ +const char *pa_suspend_cause_to_string(pa_suspend_cause_t cause, char buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]); + #endif diff --git a/src/pulsecore/sink.c b/src/pulsecore/sink.c index 045bf3a..f47a170 100644 --- a/src/pulsecore/sink.c +++ b/src/pulsecore/sink.c @@ -929,11 +929,17 @@ void pa_sink_set_mixer_dirty(pa_sink *s, bool is_dirty) { /* Called from main context */ int pa_sink_suspend(pa_sink *s, bool suspend, pa_suspend_cause_t cause) { + pa_suspend_cause_t old_cause; + char old_cause_buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]; + char new_cause_buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]; + pa_sink_assert_ref(s); pa_assert_ctl_context(); pa_assert(PA_SINK_IS_LINKED(s->state)); pa_assert(cause != 0); + old_cause = s->suspend_cause; + if (suspend) { s->suspend_cause |= cause; s->monitor_source->suspend_cause |= cause; @@ -942,6 +948,11 @@ int pa_sink_suspend(pa_sink *s, bool suspend, pa_suspend_cause_t cause) { s->monitor_source->suspend_cause &= ~cause; } + if (s->suspend_cause != old_cause) { + pa_log_debug("%s: suspend_cause: %s -> %s", s->name, pa_suspend_cause_to_string(old_cause, old_cause_buf), + pa_suspend_cause_to_string(s->suspend_cause, new_cause_buf)); + } + if (!(s->suspend_cause & PA_SUSPEND_SESSION) && (pa_atomic_load(&s->mixer_dirty) != 0)) { /* This might look racy but isn't: If somebody sets mixer_dirty exactly here, it'll be handled just fine. */ @@ -966,8 +977,6 @@ int pa_sink_suspend(pa_sink *s, bool suspend, pa_suspend_cause_t cause) { if ((pa_sink_get_state(s) == PA_SINK_SUSPENDED) == !!s->suspend_cause) return 0; - pa_log_debug("Suspend cause of sink %s is 0x%04x, %s", s->name, s->suspend_cause, s->suspend_cause ? "suspending" : "resuming"); - if (s->suspend_cause) return sink_set_state(s, PA_SINK_SUSPENDED); else diff --git a/src/pulsecore/source.c b/src/pulsecore/source.c index b838fa3..7633ede 100644 --- a/src/pulsecore/source.c +++ b/src/pulsecore/source.c @@ -849,6 +849,10 @@ void pa_source_set_mixer_dirty(pa_source *s, bool is_dirty) { /* Called from main context */ int pa_source_suspend(pa_source *s, bool suspend, pa_suspend_cause_t cause) { + pa_suspend_cause_t old_cause; + char old_cause_buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]; + char new_cause_buf[PA_SUSPEND_CAUSE_TO_STRING_BUF_SIZE]; + pa_source_assert_ref(s); pa_assert_ctl_context(); pa_assert(PA_SOURCE_IS_LINKED(s->state)); @@ -857,11 +861,18 @@ int pa_source_suspend(pa_source *s, bool suspend, pa_suspend_cause_t cause) { if (s->monitor_of && cause != PA_SUSPEND_PASSTHROUGH) return -PA_ERR_NOTSUPPORTED; + old_cause = s->suspend_cause; + if (suspend) s->suspend_cause |= cause; else s->suspend_cause &= ~cause; + if (s->suspend_cause != old_cause) { + pa_log_debug("%s: suspend_cause: %s -> %s", s->name, pa_suspend_cause_to_string(old_cause, old_cause_buf), + pa_suspend_cause_to_string(s->suspend_cause, new_cause_buf)); + } + if (!(s->suspend_cause & PA_SUSPEND_SESSION) && (pa_atomic_load(&s->mixer_dirty) != 0)) { /* This might look racy but isn't: If somebody sets mixer_dirty exactly here, it'll be handled just fine. */ @@ -886,8 +897,6 @@ int pa_source_suspend(pa_source *s, bool suspend, pa_suspend_cause_t cause) { if ((pa_source_get_state(s) == PA_SOURCE_SUSPENDED) == !!s->suspend_cause) return 0; - pa_log_debug("Suspend cause of source %s is 0x%04x, %s", s->name, s->suspend_cause, s->suspend_cause ? "suspending" : "resuming"); - if (s->suspend_cause) return source_set_state(s, PA_SOURCE_SUSPENDED); else -- 2.7.4