On Mon, Aug 13, 2018 at 4:57 AM, Tanu Kaskinen <tanuk at iki.fi> wrote:
> On Thu, 2018-07-26 at 13:57 -0700, João Paulo Rechi Vita wrote:
>> On Fri, Jun 29, 2018 at 5:02 AM, Tanu Kaskinen <tanuk at iki.fi> wrote:
>> > On Wed, 2018-06-27 at 15:01 -0700, João Paulo Rechi Vita wrote:
>> > > ---
>> > > src/pulsecore/card.c | 5 +++++
>> > > 1 file changed, 5 insertions(+)
>> > >
>> > > diff --git a/src/pulsecore/card.c b/src/pulsecore/card.c
>> > > index 0112cffb1..4ead3a606 100644
>> > > --- a/src/pulsecore/card.c
>> > > +++ b/src/pulsecore/card.c
>> > > @@ -204,7 +204,10 @@ void pa_card_choose_initial_profile(pa_card *card) {
>> > > * or if all profiles are unavailable, pick the profile with the highest
>> > > * priority regardless of its availability. */
>> > >
>> > > + pa_log_debug("Looking for an initial profile for card %s", card->name);
>> > > PA_HASHMAP_FOREACH(profile, card->profiles, state) {
>> > > + pa_log_debug("profile %s availability %s", profile->name, profile->available == PA_AVAILABLE_YES ? "yes" :
>> > > + profile->available == PA_AVAILABLE_NO ? "no" : "unknown");
>> > > if (profile->available == PA_AVAILABLE_NO)
>> > > continue;
>> > >
>> > > @@ -213,6 +216,7 @@ void pa_card_choose_initial_profile(pa_card *card) {
>> > > }
>> > >
>> > > if (!best) {
>> > > + pa_log_info("No profile with availability status 'yes' or 'unknown' found for card %s", card->name);
>> > > PA_HASHMAP_FOREACH(profile, card->profiles, state) {
>> > > if (!best || profile->priority > best->priority)
>> > > best = profile;
>> > > @@ -220,6 +224,7 @@ void pa_card_choose_initial_profile(pa_card *card) {
>> > > }
>> > > pa_assert(best);
>> > >
>> > > + pa_log_info("Initial profile %s chosen for card %s", best->name, card->name);
>> >
>> > This message belongs to pa_card_put(), because at this point the
>> > initial profile may still change, either in the CHOOSE_INITIAL_PROFILE
>> > hook or by the card implementation (at least module-alsa-card supports
>> > overriding the automatic policy). If you need to log a message at this
>> > point, the wording needs to be different (I couldn't immediately come
>> > up with a good example).
>> >
>>
>> (sorry it took me so long to reply to this)
>
> (slow replies continue)
>
>> Yes, I understand the initial profile may still change at this point,
>> but what I'm trying to log here is the whole logic to decide the
>> initial profile, starting from this point. Modules handling the
>> CHOOSE_INITIAL_PROFILE trigger should probably log a debug message
>> about it. The only two modules I've found that connect callbacks to
>> CHOOSE_INITIAL_PROFILE are module-card-restore and
>> module-bluetooth-policy, both of which log a message about it.
>>
>> About the module-alsa-card override, I think you are referring to when
>> it is loaded with the "profile" modarg, we would also get a message
>> from pa_card_set_profile.
>
> pa_card_set_profile() doesn't log anything before pa_card_put() has
> been called. If you want detailed logs about the profile
> initialization, I suppose we should change pa_card_set_profile() so
> that it logs changes always.
>
Ok.
>> But I understand your point of trying to be clear that this initial
>> choice is subject to change before the card is active and available.
>> Maybe something like ("Profile %s chosen during card %s creation",
>> best->name, card->name) would achieve it?
>
> That's better, I'd accept that. Here's another suggestion:
>
> pa_log_info("%s: active_profile: %s", card->name, card->active_profile->name);
>
> That would be somewhat similar to the format that I nowadays prefer to
> use for variable change messages (pa_card_set_profile() could be
> updated to use this too):
>
> pa_log_info("%s: variable: %s -> %s", object->name, old_value, new_value);
>
I'm all for consistency, so I went with your suggestions here.
Submitted an updated version through GitLab:
https://gitlab.freedesktop.org/pulseaudio/pulseaudio/merge_requests/3.
--
João Paulo Rechi Vita
http://about.me/jprvita
