From 332e015608685a9696782bc75ce0ce7f72b22c48 Mon Sep 17 00:00:00 2001 From: Tanu Kaskinen Date: Fri, 27 Jan 2017 13:16:54 +0200 Subject: [PATCH] card: log the reason for profile changes --- src/modules/alsa/module-alsa-card.c | 2 +- src/modules/bluetooth/module-bluetooth-policy.c | 4 ++-- src/modules/bluetooth/module-bluez4-device.c | 10 +++++----- src/modules/bluetooth/module-bluez5-device.c | 8 ++++---- src/modules/dbus/iface-card.c | 8 +++++++- src/modules/module-card-restore.c | 4 ++-- src/modules/module-switch-on-port-available.c | 2 +- src/pulsecore/card.c | 11 ++++++++--- src/pulsecore/card.h | 2 +- src/pulsecore/cli-command.c | 2 +- src/pulsecore/play-memblockq.c | 11 ++++++++++- src/pulsecore/protocol-native.c | 6 +++++- src/pulsecore/sink-input.c | 5 +++++ 13 files changed, 52 insertions(+), 23 deletions(-) diff --git a/src/modules/alsa/module-alsa-card.c b/src/modules/alsa/module-alsa-card.c index 4f1236ecd..661f6f9da 100644 --- a/src/modules/alsa/module-alsa-card.c +++ b/src/modules/alsa/module-alsa-card.c @@ -865,7 +865,7 @@ int pa__init(pa_module *m) { goto fail; } - pa_card_set_profile(u->card, profile, false); + pa_card_set_profile(u->card, profile, false, "from module argument"); } pa_card_put(u->card); diff --git a/src/modules/bluetooth/module-bluetooth-policy.c b/src/modules/bluetooth/module-bluetooth-policy.c index df702cc32..5cd3a4e34 100644 --- a/src/modules/bluetooth/module-bluetooth-policy.c +++ b/src/modules/bluetooth/module-bluetooth-policy.c @@ -165,7 +165,7 @@ static void card_set_profile(struct userdata *u, pa_card *card, bool revert_to_a pa_log_debug("Setting card '%s' to profile '%s'", card->name, profile->name); - if (pa_card_set_profile(card, profile, false) != 0) { + if (pa_card_set_profile(card, profile, false, "module-bluetooth-policy magic") != 0) { pa_log_warn("Could not set profile '%s'", profile->name); continue; } @@ -372,7 +372,7 @@ static pa_hook_result_t profile_available_hook_callback(pa_core *c, pa_card_prof pa_log_debug("Setting card '%s' to profile '%s'", card->name, selected_profile->name); - if (pa_card_set_profile(card, selected_profile, false) != 0) + if (pa_card_set_profile(card, selected_profile, false, "module-bluetooth-policy magic") != 0) pa_log_warn("Could not set profile '%s'", selected_profile->name); return PA_HOOK_OK; diff --git a/src/modules/bluetooth/module-bluez4-device.c b/src/modules/bluetooth/module-bluez4-device.c index ac4ed63f0..49252b548 100644 --- a/src/modules/bluetooth/module-bluez4-device.c +++ b/src/modules/bluetooth/module-bluez4-device.c @@ -538,7 +538,7 @@ static int device_process_msg(pa_msgobject *obj, int code, void *data, int64_t o pa_log_debug("Switching the profile to off due to IO thread failure."); - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "IO thread failed") >= 0); break; } } @@ -1817,7 +1817,7 @@ static pa_hook_result_t transport_state_changed_cb(pa_bluez4_discovery *y, pa_bl pa_assert(u); if (t == u->transport && t->state == PA_BLUEZ4_TRANSPORT_STATE_DISCONNECTED) - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "transport disconnected") >= 0); if (t->device == u->device) handle_transport_state_change(u, t); @@ -2066,7 +2066,7 @@ static int card_set_profile(pa_card *c, pa_card_profile *new_profile) { off: stop_thread(u); - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "profile initialization failed") >= 0); return -PA_ERR_IO; } @@ -2351,7 +2351,7 @@ static int add_card(struct userdata *u) { return -1; } - pa_card_set_profile(u->card, profile, false); + pa_card_set_profile(u->card, profile, false, "from module argument"); } pa_card_put(u->card); @@ -2570,7 +2570,7 @@ int pa__init(pa_module *m) { off: stop_thread(u); - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "profile initialization failed") >= 0); return 0; diff --git a/src/modules/bluetooth/module-bluez5-device.c b/src/modules/bluetooth/module-bluez5-device.c index 065fcaa61..4bbafaa21 100644 --- a/src/modules/bluetooth/module-bluez5-device.c +++ b/src/modules/bluetooth/module-bluez5-device.c @@ -1891,7 +1891,7 @@ static int set_profile_cb(pa_card *c, pa_card_profile *new_profile) { off: stop_thread(u); - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "profile initialization failed") >= 0); return -PA_ERR_IO; } @@ -2076,7 +2076,7 @@ static pa_hook_result_t transport_state_changed_cb(pa_bluetooth_discovery *y, pa pa_assert(u); if (t == u->transport && t->state <= PA_BLUETOOTH_TRANSPORT_STATE_DISCONNECTED) - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "transport disconnected") >= 0); if (t->device == u->device) handle_transport_state_change(u, t); @@ -2143,7 +2143,7 @@ static int device_process_msg(pa_msgobject *obj, int code, void *data, int64_t o break; pa_log_debug("Switching the profile to off due to IO thread failure."); - pa_assert_se(pa_card_set_profile(m->card, pa_hashmap_get(m->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(m->card, pa_hashmap_get(m->card->profiles, "off"), false, "IO thread failed") >= 0); break; case BLUETOOTH_MESSAGE_STREAM_FD_HUP: if (u->transport->state > PA_BLUETOOTH_TRANSPORT_STATE_IDLE) @@ -2225,7 +2225,7 @@ int pa__init(pa_module* m) { off: stop_thread(u); - pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false) >= 0); + pa_assert_se(pa_card_set_profile(u->card, pa_hashmap_get(u->card->profiles, "off"), false, "profile initialization failed") >= 0); return 0; diff --git a/src/modules/dbus/iface-card.c b/src/modules/dbus/iface-card.c index 1b705ba7b..e1636d613 100644 --- a/src/modules/dbus/iface-card.c +++ b/src/modules/dbus/iface-card.c @@ -325,6 +325,8 @@ static void handle_set_active_profile(DBusConnection *conn, DBusMessage *msg, DB pa_dbusiface_card *c = userdata; const char *new_active_path; pa_dbusiface_card_profile *new_active; + pa_client *client; + char *reason; int r; pa_assert(conn); @@ -339,7 +341,11 @@ static void handle_set_active_profile(DBusConnection *conn, DBusMessage *msg, DB return; } - if ((r = pa_card_set_profile(c->card, pa_dbusiface_card_profile_get_profile(new_active), true)) < 0) { + client = pa_dbus_protocol_get_client(c->dbus_protocol, conn); + reason = pa_sprintf_malloc("requested by client #%u (%s)", client->index, pa_strnull(pa_proplist_gets(client->proplist, PA_PROP_APPLICATION_NAME))); + r = pa_card_set_profile(c->card, pa_dbusiface_card_profile_get_profile(new_active), true, reason); + pa_xfree(reason); + if (r < 0) { pa_dbus_send_error(conn, msg, DBUS_ERROR_FAILED, "Internal error in PulseAudio: pa_card_set_profile() failed with error code %i.", r); return; diff --git a/src/modules/module-card-restore.c b/src/modules/module-card-restore.c index 3c0307bee..9ff48a9a0 100644 --- a/src/modules/module-card-restore.c +++ b/src/modules/module-card-restore.c @@ -470,7 +470,7 @@ static pa_hook_result_t card_profile_added_callback(pa_core *c, pa_card_profile return PA_HOOK_OK; if (pa_safe_streq(entry->profile, profile->name)) { - if (pa_card_set_profile(profile->card, profile, true) >= 0) + if (pa_card_set_profile(profile->card, profile, true, "from card-restore database") >= 0) pa_log_info("Restored profile '%s' for card %s.", profile->name, profile->card->name); } @@ -562,7 +562,7 @@ static pa_hook_result_t card_choose_initial_profile_callback(pa_core *core, pa_c profile = pa_hashmap_get(card->profiles, e->profile); if (profile) { pa_log_info("Restoring profile '%s' for card %s.", card->active_profile->name, card->name); - pa_card_set_profile(card, profile, true); + pa_card_set_profile(card, profile, true, "from card-restore database"); } else { pa_log_debug("Tried to restore profile %s for card %s, but the card doesn't have such profile.", e->profile, card->name); diff --git a/src/modules/module-switch-on-port-available.c b/src/modules/module-switch-on-port-available.c index b9a0f3b3a..2cbfcc67c 100644 --- a/src/modules/module-switch-on-port-available.c +++ b/src/modules/module-switch-on-port-available.c @@ -168,7 +168,7 @@ static int try_to_switch_profile(pa_device_port *port) { return -1; } - if (pa_card_set_profile(port->card, best_profile, false) != 0) { + if (pa_card_set_profile(port->card, best_profile, false, "module-switch-on-port-available magic") != 0) { pa_log_debug("Could not set profile %s", best_profile->name); return -1; } diff --git a/src/pulsecore/card.c b/src/pulsecore/card.c index bc5b75b04..668803b7a 100644 --- a/src/pulsecore/card.c +++ b/src/pulsecore/card.c @@ -288,19 +288,24 @@ static void update_port_preferred_profile(pa_card *c) { pa_device_port_set_preferred_profile(source->active_port, profile_name_for_dir(c->active_profile, PA_DIRECTION_INPUT)); } -int pa_card_set_profile(pa_card *c, pa_card_profile *profile, bool save) { +int pa_card_set_profile(pa_card *c, pa_card_profile *profile, bool save, const char *reason) { + pa_card_profile *old_profile; int r; pa_assert(c); pa_assert(profile); pa_assert(profile->card == c); + pa_log_debug("XXX pa_card_set_profile() called with reason \"%s\".", reason); + if (!c->set_profile) { pa_log_debug("set_profile() operation not implemented for card %u \"%s\"", c->index, c->name); return -PA_ERR_NOTIMPLEMENTED; } - if (c->active_profile == profile) { + old_profile = c->active_profile; + + if (profile == old_profile) { if (save && !c->save_profile) { update_port_preferred_profile(c); c->save_profile = true; @@ -325,7 +330,7 @@ int pa_card_set_profile(pa_card *c, pa_card_profile *profile, bool save) { update_port_preferred_profile(c); if (c->linked) { - pa_log_info("Changed profile of card %u \"%s\" to %s", c->index, c->name, profile->name); + pa_log_info("%s: active_profile: %s -> %s (reason: %s)", c->name, old_profile->name, profile->name, reason); pa_hook_fire(&c->core->hooks[PA_CORE_HOOK_CARD_PROFILE_CHANGED], c); pa_subscription_post(c->core, PA_SUBSCRIPTION_EVENT_CARD|PA_SUBSCRIPTION_EVENT_CHANGE, c->index); } diff --git a/src/pulsecore/card.h b/src/pulsecore/card.h index 5699475d8..fd8636be0 100644 --- a/src/pulsecore/card.h +++ b/src/pulsecore/card.h @@ -136,7 +136,7 @@ void pa_card_free(pa_card *c); void pa_card_add_profile(pa_card *c, pa_card_profile *profile); -int pa_card_set_profile(pa_card *c, pa_card_profile *profile, bool save); +int pa_card_set_profile(pa_card *c, pa_card_profile *profile, bool save, const char *reason); void pa_card_set_preferred_port(pa_card *c, pa_direction_t direction, pa_device_port *port); diff --git a/src/pulsecore/cli-command.c b/src/pulsecore/cli-command.c index 9a7360582..ad713e4f1 100644 --- a/src/pulsecore/cli-command.c +++ b/src/pulsecore/cli-command.c @@ -1659,7 +1659,7 @@ static int pa_cli_command_card_profile(pa_core *c, pa_tokenizer *t, pa_strbuf *b return -1; } - if (pa_card_set_profile(card, profile, true) < 0) { + if (pa_card_set_profile(card, profile, true, "requested through cli-command") < 0) { pa_strbuf_printf(buf, "Failed to set card profile to '%s'.\n", p); return -1; } diff --git a/src/pulsecore/play-memblockq.c b/src/pulsecore/play-memblockq.c index e087047a6..61e529921 100644 --- a/src/pulsecore/play-memblockq.c +++ b/src/pulsecore/play-memblockq.c @@ -48,9 +48,14 @@ PA_DEFINE_PRIVATE_CLASS(memblockq_stream, pa_msgobject); static void memblockq_stream_unlink(memblockq_stream *u) { pa_assert(u); - if (!u->sink_input) + pa_log_debug("XXX memblockq_stream_unlink()"); + + if (!u->sink_input) { + pa_log_debug("XXX !u->sink_input"); return; + } + pa_log_debug("XXX u->sink_input->index = %u", (unsigned) u->sink_input->index); pa_sink_input_unlink(u->sink_input); pa_sink_input_unref(u->sink_input); u->sink_input = NULL; @@ -62,6 +67,8 @@ static void memblockq_stream_free(pa_object *o) { memblockq_stream *u = MEMBLOCKQ_STREAM(o); pa_assert(u); + pa_log_debug("XXX memblockq_stream_free()"); + if (u->memblockq) pa_memblockq_free(u->memblockq); @@ -88,6 +95,8 @@ static void sink_input_kill_cb(pa_sink_input *i) { u = MEMBLOCKQ_STREAM(i->userdata); memblockq_stream_assert_ref(u); + pa_log_debug("XXX sink_input_kill_cb()"); + memblockq_stream_unlink(u); } diff --git a/src/pulsecore/protocol-native.c b/src/pulsecore/protocol-native.c index 13f4f6238..19d17bf03 100644 --- a/src/pulsecore/protocol-native.c +++ b/src/pulsecore/protocol-native.c @@ -4692,6 +4692,7 @@ static void command_set_card_profile(pa_pdispatch *pd, uint32_t command, uint32_ const char *name = NULL, *profile_name = NULL; pa_card *card = NULL; pa_card_profile *profile; + char *reason; int ret; pa_native_connection_assert_ref(c); @@ -4721,7 +4722,10 @@ static void command_set_card_profile(pa_pdispatch *pd, uint32_t command, uint32_ CHECK_VALIDITY(c->pstream, profile, tag, PA_ERR_NOENTITY); - if ((ret = pa_card_set_profile(card, profile, true)) < 0) { + reason = pa_sprintf_malloc("requested by client %u (%s)", c->client->index, pa_strnull(pa_proplist_gets(c->client->proplist, PA_PROP_APPLICATION_NAME))); + ret = pa_card_set_profile(card, profile, true, reason); + pa_xfree(reason); + if (ret < 0) { pa_pstream_send_error(c->pstream, tag, -ret); return; } diff --git a/src/pulsecore/sink-input.c b/src/pulsecore/sink-input.c index e9694f21a..5fbeb855e 100644 --- a/src/pulsecore/sink-input.c +++ b/src/pulsecore/sink-input.c @@ -648,12 +648,15 @@ void pa_sink_input_unlink(pa_sink_input *i) { pa_sink_input_assert_ref(i); pa_assert_ctl_context(); + pa_log_debug("XXX pa_sink_input_unlink(%u)", (unsigned) i->index); + /* See pa_sink_unlink() for a couple of comments how this function * works */ pa_sink_input_ref(i); linked = PA_SINK_INPUT_IS_LINKED(i->state); + pa_log_debug("XXX linked = %s", linked ? "true" : "false"); if (linked) pa_hook_fire(&i->core->hooks[PA_CORE_HOOK_SINK_INPUT_UNLINK], i); @@ -682,6 +685,7 @@ void pa_sink_input_unlink(pa_sink_input *i) { update_n_corked(i, PA_SINK_INPUT_UNLINKED); i->state = PA_SINK_INPUT_UNLINKED; + pa_log_debug("XXX i->state = PA_SINK_INPUT_UNLINKED (i->index = %u)", (unsigned) i->index); if (linked && i->sink) { if (pa_sink_input_is_passthrough(i)) @@ -1835,6 +1839,7 @@ int pa_sink_input_finish_move(pa_sink_input *i, pa_sink *dest, bool save) { pa_sink_input_assert_ref(i); pa_assert_ctl_context(); + pa_log_debug("XXX pa_sink_input_finish_move(%u)", (unsigned) i->index); pa_assert(PA_SINK_INPUT_IS_LINKED(i->state)); pa_assert(!i->sink); pa_sink_assert_ref(dest); -- 2.11.0