| Message ID | 8598037d-0e24-9bc1-3f2c-a2751ec8e871@gmail.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | selftests: alsa: Better error messages | expand |
On Fri, 13 May 2022 15:40:57 +0200, Siddh Raman Pant wrote: > > This allows for potentially better machine-parsing due to an > expected / fixed format. Also because of eyecandy reasons. > > Whenever possible, errors will start with the name of the > offending card/control, separated by the error with colons. > > Whenever there is a description of an error given, the generated > error string from snd_strerror will be (mostly) enclosed in > parentheses at the end. > > Clarity of error messages have been (hopefully) improved. > > Signed-off-by: Siddh Raman Pant <siddhpant.gh@gmail.com> Thanks for the patch. But, honestly speaking, I'm not sure whether it worth. Although it's possibly a bit more consistent over all texts, I don't see significant improvement by this change. But I'm fine to apply it, so keep this pending and would like to hear from others. thanks, Takashi > --- > tools/testing/selftests/alsa/mixer-test.c | 94 +++++++++++------------ > 1 file changed, 47 insertions(+), 47 deletions(-) > > diff --git a/tools/testing/selftests/alsa/mixer-test.c b/tools/testing/selftests/alsa/mixer-test.c > index a38b89c28..4719b12a5 100644 > --- a/tools/testing/selftests/alsa/mixer-test.c > +++ b/tools/testing/selftests/alsa/mixer-test.c > @@ -114,7 +114,7 @@ static void find_controls(void) > > err = snd_config_load_string(&config, alsa_config, strlen(alsa_config)); > if (err < 0) { > - ksft_print_msg("Unable to parse custom alsa-lib configuration: %s\n", > + ksft_print_msg("Unable to parse custom alsa-lib configuration (%s)\n", > snd_strerror(err)); > ksft_exit_fail(); > } > @@ -128,7 +128,7 @@ static void find_controls(void) > > err = snd_ctl_open_lconf(&card_data->handle, name, 0, config); > if (err < 0) { > - ksft_print_msg("Failed to get hctl for card %d: %s\n", > + ksft_print_msg("Card %d: Failed to get hctl (%s)\n", > card, snd_strerror(err)); > goto next_card; > } > @@ -177,9 +177,8 @@ static void find_controls(void) > err = snd_ctl_elem_info(card_data->handle, > ctl_data->info); > if (err < 0) { > - ksft_print_msg("%s getting info for %d\n", > - snd_strerror(err), > - ctl_data->name); > + ksft_print_msg("%s : %s while getting info\n", > + ctl_data->name, snd_strerror(err)); > } > > snd_ctl_elem_value_set_id(ctl_data->def_val, > @@ -192,20 +191,20 @@ static void find_controls(void) > /* Set up for events */ > err = snd_ctl_subscribe_events(card_data->handle, true); > if (err < 0) { > - ksft_exit_fail_msg("snd_ctl_subscribe_events() failed for card %d: %d\n", > + ksft_exit_fail_msg("Card %d : snd_ctl_subscribe_events() failed (%d)\n", > card, err); > } > > err = snd_ctl_poll_descriptors_count(card_data->handle); > if (err != 1) { > - ksft_exit_fail_msg("Unexpected descriptor count %d for card %d\n", > - err, card); > + ksft_exit_fail_msg("Card %d : Unexpected descriptor count %d\n", > + card, err); > } > > err = snd_ctl_poll_descriptors(card_data->handle, > &card_data->pollfd, 1); > if (err != 1) { > - ksft_exit_fail_msg("snd_ctl_poll_descriptors() failed for %d\n", > + ksft_exit_fail_msg("Card %d : snd_ctl_poll_descriptors() failed (%d)\n", > card, err); > } > > @@ -236,8 +235,8 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) > do { > err = poll(&(ctl->card->pollfd), 1, timeout); > if (err < 0) { > - ksft_print_msg("poll() failed for %s: %s (%d)\n", > - ctl->name, strerror(errno), errno); > + ksft_print_msg("%s : poll() failed (%d - %s)\n", > + ctl->name, errno, strerror(errno)); > return -1; > } > /* Timeout */ > @@ -248,12 +247,12 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) > &(ctl->card->pollfd), > 1, &revents); > if (err < 0) { > - ksft_print_msg("snd_ctl_poll_descriptors_revents() failed for %s: %d\n", > + ksft_print_msg("%s : snd_ctl_poll_descriptors_revents() failed (%d)\n", > ctl->name, err); > return err; > } > if (revents & POLLERR) { > - ksft_print_msg("snd_ctl_poll_descriptors_revents() reported POLLERR for %s\n", > + ksft_print_msg("%s : snd_ctl_poll_descriptors_revents() reported POLLERR\n", > ctl->name); > return -1; > } > @@ -265,7 +264,7 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) > > err = snd_ctl_read(ctl->card->handle, event); > if (err < 0) { > - ksft_print_msg("snd_ctl_read() failed for %s: %d\n", > + ksft_print_msg("%s : snd_ctl_read() failed (%d)\n", > ctl->name, err); > return err; > } > @@ -283,7 +282,7 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) > } > > if ((mask & SND_CTL_EVENT_MASK_REMOVE) == SND_CTL_EVENT_MASK_REMOVE) { > - ksft_print_msg("Removal event for %s\n", > + ksft_print_msg("%s : Removal event\n", > ctl->name); > return -1; > } > @@ -301,7 +300,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > > switch (snd_ctl_elem_info_get_type(ctl->info)) { > case SND_CTL_ELEM_TYPE_NONE: > - ksft_print_msg("%s.%d Invalid control type NONE\n", > + ksft_print_msg("%s.%d : Invalid control type NONE\n", > ctl->name, index); > return false; > > @@ -312,7 +311,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > case 1: > break; > default: > - ksft_print_msg("%s.%d Invalid boolean value %ld\n", > + ksft_print_msg("%s.%d : Invalid boolean value %ld\n", > ctl->name, index, int_val); > return false; > } > @@ -322,14 +321,14 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > int_val = snd_ctl_elem_value_get_integer(val, index); > > if (int_val < snd_ctl_elem_info_get_min(ctl->info)) { > - ksft_print_msg("%s.%d value %ld less than minimum %ld\n", > + ksft_print_msg("%s.%d : Value %ld is less than the minimum (%ld)\n", > ctl->name, index, int_val, > snd_ctl_elem_info_get_min(ctl->info)); > return false; > } > > if (int_val > snd_ctl_elem_info_get_max(ctl->info)) { > - ksft_print_msg("%s.%d value %ld more than maximum %ld\n", > + ksft_print_msg("%s.%d : Value %ld is more than the maximum (%ld)\n", > ctl->name, index, int_val, > snd_ctl_elem_info_get_max(ctl->info)); > return false; > @@ -339,7 +338,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > if (snd_ctl_elem_info_get_step(ctl->info) && > (int_val - snd_ctl_elem_info_get_min(ctl->info) % > snd_ctl_elem_info_get_step(ctl->info))) { > - ksft_print_msg("%s.%d value %ld invalid for step %ld minimum %ld\n", > + ksft_print_msg("%s.%d : Value %ld is invalid for step %ld, minimum %ld\n", > ctl->name, index, int_val, > snd_ctl_elem_info_get_step(ctl->info), > snd_ctl_elem_info_get_min(ctl->info)); > @@ -351,14 +350,14 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > int64_val = snd_ctl_elem_value_get_integer64(val, index); > > if (int64_val < snd_ctl_elem_info_get_min64(ctl->info)) { > - ksft_print_msg("%s.%d value %lld less than minimum %lld\n", > + ksft_print_msg("%s.%d : Value %lld is less than the minimum (%lld)\n", > ctl->name, index, int64_val, > snd_ctl_elem_info_get_min64(ctl->info)); > return false; > } > > if (int64_val > snd_ctl_elem_info_get_max64(ctl->info)) { > - ksft_print_msg("%s.%d value %lld more than maximum %lld\n", > + ksft_print_msg("%s.%d : Value %lld is more than the maximum (%lld)\n", > ctl->name, index, int64_val, > snd_ctl_elem_info_get_max(ctl->info)); > return false; > @@ -368,7 +367,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > if (snd_ctl_elem_info_get_step64(ctl->info) && > (int64_val - snd_ctl_elem_info_get_min64(ctl->info)) % > snd_ctl_elem_info_get_step64(ctl->info)) { > - ksft_print_msg("%s.%d value %lld invalid for step %lld minimum %lld\n", > + ksft_print_msg("%s.%d : Value %lld is invalid for step %lld, minimum %lld\n", > ctl->name, index, int64_val, > snd_ctl_elem_info_get_step64(ctl->info), > snd_ctl_elem_info_get_min64(ctl->info)); > @@ -380,13 +379,13 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, > int_val = snd_ctl_elem_value_get_enumerated(val, index); > > if (int_val < 0) { > - ksft_print_msg("%s.%d negative value %ld for enumeration\n", > + ksft_print_msg("%s.%d : Negative value %ld for enumeration\n", > ctl->name, index, int_val); > return false; > } > > if (int_val >= snd_ctl_elem_info_get_items(ctl->info)) { > - ksft_print_msg("%s.%d value %ld more than item count %ld\n", > + ksft_print_msg("%s.%d : Value %ld is more than item count (%ld)\n", > ctl->name, index, int_val, > snd_ctl_elem_info_get_items(ctl->info)); > return false; > @@ -427,7 +426,7 @@ static void test_ctl_get_value(struct ctl_data *ctl) > > /* If the control is turned off let's be polite */ > if (snd_ctl_elem_info_is_inactive(ctl->info)) { > - ksft_print_msg("%s is inactive\n", ctl->name); > + ksft_print_msg("%s : Inactive\n", ctl->name); > ksft_test_result_skip("get_value.%d.%d\n", > ctl->card->card, ctl->elem); > return; > @@ -435,7 +434,7 @@ static void test_ctl_get_value(struct ctl_data *ctl) > > /* Can't test reading on an unreadable control */ > if (!snd_ctl_elem_info_is_readable(ctl->info)) { > - ksft_print_msg("%s is not readable\n", ctl->name); > + ksft_print_msg("%s : Not readable\n", ctl->name); > ksft_test_result_skip("get_value.%d.%d\n", > ctl->card->card, ctl->elem); > return; > @@ -443,7 +442,7 @@ static void test_ctl_get_value(struct ctl_data *ctl) > > err = snd_ctl_elem_read(ctl->card->handle, ctl->def_val); > if (err < 0) { > - ksft_print_msg("snd_ctl_elem_read() failed: %s\n", > + ksft_print_msg("snd_ctl_elem_read() failed (%s)\n", > snd_strerror(err)); > goto out; > } > @@ -474,7 +473,7 @@ static void test_ctl_name(struct ctl_data *ctl) > /* Only boolean controls should end in Switch */ > if (strend(ctl->name, " Switch")) { > if (snd_ctl_elem_info_get_type(ctl->info) != SND_CTL_ELEM_TYPE_BOOLEAN) { > - ksft_print_msg("%d.%d %s ends in Switch but is not boolean\n", > + ksft_print_msg("%d.%d %s : Not a boolean, but name ends in Switch\n", > ctl->card->card, ctl->elem, ctl->name); > name_ok = false; > } > @@ -484,7 +483,7 @@ static void test_ctl_name(struct ctl_data *ctl) > if (snd_ctl_elem_info_get_type(ctl->info) == SND_CTL_ELEM_TYPE_BOOLEAN && > snd_ctl_elem_info_is_writable(ctl->info)) { > if (!strend(ctl->name, " Switch")) { > - ksft_print_msg("%d.%d %s is a writeable boolean but not a Switch\n", > + ksft_print_msg("%d.%d %s : Not a Switch despite being a writeable boolean\n", > ctl->card->card, ctl->elem, ctl->name); > name_ok = false; > } > @@ -542,11 +541,12 @@ static bool show_mismatch(struct ctl_data *ctl, int index, > /* > * NOTE: The volatile attribute means that the hardware > * can voluntarily change the state of control element > - * independent of any operation by software. > + * independent of any operation by software. > */ > bool is_volatile = snd_ctl_elem_info_is_volatile(ctl->info); > - ksft_print_msg("%s.%d expected %lld but read %lld, is_volatile %d\n", > - ctl->name, index, expected_int, read_int, is_volatile); > + ksft_print_msg("%s.%d : Expected %lld, but read %lld (%s)\n", > + ctl->name, index, expected_int, read_int, > + (is_volatile ? "Volatile" : "Non-volatile")); > return !is_volatile; > } else { > return false; > @@ -590,7 +590,7 @@ static int write_and_verify(struct ctl_data *ctl, > > err = snd_ctl_elem_read(ctl->card->handle, initial_val); > if (err < 0) { > - ksft_print_msg("snd_ctl_elem_read() failed: %s\n", > + ksft_print_msg("snd_ctl_elem_read() failed (%s)\n", > snd_strerror(err)); > return err; > } > @@ -602,7 +602,7 @@ static int write_and_verify(struct ctl_data *ctl, > */ > err = snd_ctl_elem_write(ctl->card->handle, w_val); > if (err < 0 && !error_expected) { > - ksft_print_msg("snd_ctl_elem_write() failed: %s\n", > + ksft_print_msg("snd_ctl_elem_write() failed (%s)\n", > snd_strerror(err)); > return err; > } > @@ -615,7 +615,7 @@ static int write_and_verify(struct ctl_data *ctl, > > err = snd_ctl_elem_read(ctl->card->handle, read_val); > if (err < 0) { > - ksft_print_msg("snd_ctl_elem_read() failed: %s\n", > + ksft_print_msg("snd_ctl_elem_read() failed (%s)\n", > snd_strerror(err)); > return err; > } > @@ -631,13 +631,13 @@ static int write_and_verify(struct ctl_data *ctl, > err = wait_for_event(ctl, 0); > if (snd_ctl_elem_value_compare(initial_val, read_val)) { > if (err < 1) { > - ksft_print_msg("No event generated for %s\n", > + ksft_print_msg("%s : No event generated\n", > ctl->name); > ctl->event_missing++; > } > } else { > if (err != 0) { > - ksft_print_msg("Spurious event generated for %s\n", > + ksft_print_msg("%s : Spurious event generated\n", > ctl->name); > ctl->event_spurious++; > } > @@ -658,7 +658,7 @@ static int write_and_verify(struct ctl_data *ctl, > mismatch_shown = true; > > if (!mismatch_shown) > - ksft_print_msg("%s read and written values differ\n", > + ksft_print_msg("%s : Read and written values differ\n", > ctl->name); > > return -1; > @@ -674,14 +674,14 @@ static void test_ctl_write_default(struct ctl_data *ctl) > > /* If the control is turned off let's be polite */ > if (snd_ctl_elem_info_is_inactive(ctl->info)) { > - ksft_print_msg("%s is inactive\n", ctl->name); > + ksft_print_msg("%s : Inactive\n", ctl->name); > ksft_test_result_skip("write_default.%d.%d\n", > ctl->card->card, ctl->elem); > return; > } > > if (!snd_ctl_elem_info_is_writable(ctl->info)) { > - ksft_print_msg("%s is not writeable\n", ctl->name); > + ksft_print_msg("%s : Not writeable\n", ctl->name); > ksft_test_result_skip("write_default.%d.%d\n", > ctl->card->card, ctl->elem); > return; > @@ -689,7 +689,7 @@ static void test_ctl_write_default(struct ctl_data *ctl) > > /* No idea what the default was for unreadable controls */ > if (!snd_ctl_elem_info_is_readable(ctl->info)) { > - ksft_print_msg("%s couldn't read default\n", ctl->name); > + ksft_print_msg("%s : Couldn't read default\n", ctl->name); > ksft_test_result_skip("write_default.%d.%d\n", > ctl->card->card, ctl->elem); > return; > @@ -808,14 +808,14 @@ static void test_ctl_write_valid(struct ctl_data *ctl) > > /* If the control is turned off let's be polite */ > if (snd_ctl_elem_info_is_inactive(ctl->info)) { > - ksft_print_msg("%s is inactive\n", ctl->name); > + ksft_print_msg("%s : Inactive\n", ctl->name); > ksft_test_result_skip("write_valid.%d.%d\n", > ctl->card->card, ctl->elem); > return; > } > > if (!snd_ctl_elem_info_is_writable(ctl->info)) { > - ksft_print_msg("%s is not writeable\n", ctl->name); > + ksft_print_msg("%s : Not writeable\n", ctl->name); > ksft_test_result_skip("write_valid.%d.%d\n", > ctl->card->card, ctl->elem); > return; > @@ -868,7 +868,7 @@ static bool test_ctl_write_invalid_value(struct ctl_data *ctl, > /* ...but some devices will clamp to an in range value */ > err = snd_ctl_elem_read(ctl->card->handle, val); > if (err < 0) { > - ksft_print_msg("%s failed to read: %s\n", > + ksft_print_msg("%s : Failed to read (%s)\n", > ctl->name, snd_strerror(err)); > return true; > } > @@ -1026,14 +1026,14 @@ static void test_ctl_write_invalid(struct ctl_data *ctl) > > /* If the control is turned off let's be polite */ > if (snd_ctl_elem_info_is_inactive(ctl->info)) { > - ksft_print_msg("%s is inactive\n", ctl->name); > + ksft_print_msg("%s : Inactive\n", ctl->name); > ksft_test_result_skip("write_invalid.%d.%d\n", > ctl->card->card, ctl->elem); > return; > } > > if (!snd_ctl_elem_info_is_writable(ctl->info)) { > - ksft_print_msg("%s is not writeable\n", ctl->name); > + ksft_print_msg("%s : Not writeable\n", ctl->name); > ksft_test_result_skip("write_invalid.%d.%d\n", > ctl->card->card, ctl->elem); > return; > -- > 2.35.1 >
On Mon, May 16, 2022 at 09:49:04AM +0200, Takashi Iwai wrote: > On Fri, 13 May 2022 15:40:57 +0200, > Siddh Raman Pant wrote: > > This allows for potentially better machine-parsing due to an > > expected / fixed format. Also because of eyecandy reasons. > > Whenever possible, errors will start with the name of the > > offending card/control, separated by the error with colons. > > Whenever there is a description of an error given, the generated > > error string from snd_strerror will be (mostly) enclosed in > > parentheses at the end. > > Clarity of error messages have been (hopefully) improved. > But, honestly speaking, I'm not sure whether it worth. > Although it's possibly a bit more consistent over all texts, I > don't see significant improvement by this change. > But I'm fine to apply it, so keep this pending and would like to > hear from others. Some of it is probably fine but there's a lot of different changes for a lot of different styles in here, not all of which look great to me.
On Fri, May 13, 2022 at 07:10:57PM +0530, Siddh Raman Pant wrote: > This allows for potentially better machine-parsing due to an > expected / fixed format. Also because of eyecandy reasons. As I said in reply to Takashi's mail I'm not convinced about all the changes in here, a lot of it's really bikesheddy at the best of times and to be honest there's more here that I don't like than do. The changes aren't entirely consistent in the final style either so presumably not great if there is any machine parsing going on. It'd be much better to split this up into separate commits for separate changes, that'd be a lot easier to review if nothing else. > if (err < 0) { > - ksft_print_msg("Unable to parse custom alsa-lib configuration: %s\n", > + ksft_print_msg("Unable to parse custom alsa-lib configuration (%s)\n", > snd_strerror(err)); I'm really unconvinced that replacing : with () is helping either people or machines - the form we have at the minute is probably more common for command line tools? > - ksft_print_msg("%s getting info for %d\n", > - snd_strerror(err), > - ctl_data->name); > + ksft_print_msg("%s : %s while getting info\n", > + ctl_data->name, snd_strerror(err)); Why add the space before the : here? That really is not idiomatic for Unix stuff, or just natural language. > @@ -542,11 +541,12 @@ static bool show_mismatch(struct ctl_data *ctl, int index, > /* > * NOTE: The volatile attribute means that the hardware > * can voluntarily change the state of control element > - * independent of any operation by software. > + * independent of any operation by software. > */ This should definitely be a separate commit. > bool is_volatile = snd_ctl_elem_info_is_volatile(ctl->info); > - ksft_print_msg("%s.%d expected %lld but read %lld, is_volatile %d\n", > - ctl->name, index, expected_int, read_int, is_volatile); > + ksft_print_msg("%s.%d : Expected %lld, but read %lld (%s)\n", > + ctl->name, index, expected_int, read_int, > + (is_volatile ? "Volatile" : "Non-volatile")); I don't understand the comma here?
Thank you very much, Takashi, and Mark, for reviewing the patch. Helps me getting the hang of kernel development coding styles and conventions while starting out. The particular motivation for this was that this test tends to potentially generate a very long list of warnings/errors. On Mon, May 16, 2022 At 20:32:30 +0530, Mark Brown wrote: >> if (err < 0) { >> - ksft_print_msg("Unable to parse custom alsa-lib configuration: %s\n", >> + ksft_print_msg("Unable to parse custom alsa-lib configuration (%s)\n", >> snd_strerror(err)); > > I'm really unconvinced that replacing : with () is helping either people > or machines - the form we have at the minute is probably more common for > command line tools? The intent was to separate card and error with the colon. While it may not affect parsing, you are right, the colon separator is seemingly the standard. Apologies. > Why add the space before the : here? That really is not idiomatic for > Unix stuff, or just natural language. > ... > This should definitely be a separate commit. You are right. Again, apologies for this. >> bool is_volatile = snd_ctl_elem_info_is_volatile(ctl->info); >> - ksft_print_msg("%s.%d expected %lld but read %lld, is_volatile %d\n", >> - ctl->name, index, expected_int, read_int, is_volatile); >> + ksft_print_msg("%s.%d : Expected %lld, but read %lld (%s)\n", >> + ctl->name, index, expected_int, read_int, >> + (is_volatile ? "Volatile" : "Non-volatile")); > > I don't understand the comma here? Those are independent clauses, hence used a comma. Looking back, the "but" can probably be removed here for brevity. Please let me know if there are any other things which bugs you, and whether or not should I send a v2 with the issues addressed. Thanks for the reviews, Siddh
diff --git a/tools/testing/selftests/alsa/mixer-test.c b/tools/testing/selftests/alsa/mixer-test.c index a38b89c28..4719b12a5 100644 --- a/tools/testing/selftests/alsa/mixer-test.c +++ b/tools/testing/selftests/alsa/mixer-test.c @@ -114,7 +114,7 @@ static void find_controls(void) err = snd_config_load_string(&config, alsa_config, strlen(alsa_config)); if (err < 0) { - ksft_print_msg("Unable to parse custom alsa-lib configuration: %s\n", + ksft_print_msg("Unable to parse custom alsa-lib configuration (%s)\n", snd_strerror(err)); ksft_exit_fail(); } @@ -128,7 +128,7 @@ static void find_controls(void) err = snd_ctl_open_lconf(&card_data->handle, name, 0, config); if (err < 0) { - ksft_print_msg("Failed to get hctl for card %d: %s\n", + ksft_print_msg("Card %d: Failed to get hctl (%s)\n", card, snd_strerror(err)); goto next_card; } @@ -177,9 +177,8 @@ static void find_controls(void) err = snd_ctl_elem_info(card_data->handle, ctl_data->info); if (err < 0) { - ksft_print_msg("%s getting info for %d\n", - snd_strerror(err), - ctl_data->name); + ksft_print_msg("%s : %s while getting info\n", + ctl_data->name, snd_strerror(err)); } snd_ctl_elem_value_set_id(ctl_data->def_val, @@ -192,20 +191,20 @@ static void find_controls(void) /* Set up for events */ err = snd_ctl_subscribe_events(card_data->handle, true); if (err < 0) { - ksft_exit_fail_msg("snd_ctl_subscribe_events() failed for card %d: %d\n", + ksft_exit_fail_msg("Card %d : snd_ctl_subscribe_events() failed (%d)\n", card, err); } err = snd_ctl_poll_descriptors_count(card_data->handle); if (err != 1) { - ksft_exit_fail_msg("Unexpected descriptor count %d for card %d\n", - err, card); + ksft_exit_fail_msg("Card %d : Unexpected descriptor count %d\n", + card, err); } err = snd_ctl_poll_descriptors(card_data->handle, &card_data->pollfd, 1); if (err != 1) { - ksft_exit_fail_msg("snd_ctl_poll_descriptors() failed for %d\n", + ksft_exit_fail_msg("Card %d : snd_ctl_poll_descriptors() failed (%d)\n", card, err); } @@ -236,8 +235,8 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) do { err = poll(&(ctl->card->pollfd), 1, timeout); if (err < 0) { - ksft_print_msg("poll() failed for %s: %s (%d)\n", - ctl->name, strerror(errno), errno); + ksft_print_msg("%s : poll() failed (%d - %s)\n", + ctl->name, errno, strerror(errno)); return -1; } /* Timeout */ @@ -248,12 +247,12 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) &(ctl->card->pollfd), 1, &revents); if (err < 0) { - ksft_print_msg("snd_ctl_poll_descriptors_revents() failed for %s: %d\n", + ksft_print_msg("%s : snd_ctl_poll_descriptors_revents() failed (%d)\n", ctl->name, err); return err; } if (revents & POLLERR) { - ksft_print_msg("snd_ctl_poll_descriptors_revents() reported POLLERR for %s\n", + ksft_print_msg("%s : snd_ctl_poll_descriptors_revents() reported POLLERR\n", ctl->name); return -1; } @@ -265,7 +264,7 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) err = snd_ctl_read(ctl->card->handle, event); if (err < 0) { - ksft_print_msg("snd_ctl_read() failed for %s: %d\n", + ksft_print_msg("%s : snd_ctl_read() failed (%d)\n", ctl->name, err); return err; } @@ -283,7 +282,7 @@ static int wait_for_event(struct ctl_data *ctl, int timeout) } if ((mask & SND_CTL_EVENT_MASK_REMOVE) == SND_CTL_EVENT_MASK_REMOVE) { - ksft_print_msg("Removal event for %s\n", + ksft_print_msg("%s : Removal event\n", ctl->name); return -1; } @@ -301,7 +300,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, switch (snd_ctl_elem_info_get_type(ctl->info)) { case SND_CTL_ELEM_TYPE_NONE: - ksft_print_msg("%s.%d Invalid control type NONE\n", + ksft_print_msg("%s.%d : Invalid control type NONE\n", ctl->name, index); return false; @@ -312,7 +311,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, case 1: break; default: - ksft_print_msg("%s.%d Invalid boolean value %ld\n", + ksft_print_msg("%s.%d : Invalid boolean value %ld\n", ctl->name, index, int_val); return false; } @@ -322,14 +321,14 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, int_val = snd_ctl_elem_value_get_integer(val, index); if (int_val < snd_ctl_elem_info_get_min(ctl->info)) { - ksft_print_msg("%s.%d value %ld less than minimum %ld\n", + ksft_print_msg("%s.%d : Value %ld is less than the minimum (%ld)\n", ctl->name, index, int_val, snd_ctl_elem_info_get_min(ctl->info)); return false; } if (int_val > snd_ctl_elem_info_get_max(ctl->info)) { - ksft_print_msg("%s.%d value %ld more than maximum %ld\n", + ksft_print_msg("%s.%d : Value %ld is more than the maximum (%ld)\n", ctl->name, index, int_val, snd_ctl_elem_info_get_max(ctl->info)); return false; @@ -339,7 +338,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, if (snd_ctl_elem_info_get_step(ctl->info) && (int_val - snd_ctl_elem_info_get_min(ctl->info) % snd_ctl_elem_info_get_step(ctl->info))) { - ksft_print_msg("%s.%d value %ld invalid for step %ld minimum %ld\n", + ksft_print_msg("%s.%d : Value %ld is invalid for step %ld, minimum %ld\n", ctl->name, index, int_val, snd_ctl_elem_info_get_step(ctl->info), snd_ctl_elem_info_get_min(ctl->info)); @@ -351,14 +350,14 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, int64_val = snd_ctl_elem_value_get_integer64(val, index); if (int64_val < snd_ctl_elem_info_get_min64(ctl->info)) { - ksft_print_msg("%s.%d value %lld less than minimum %lld\n", + ksft_print_msg("%s.%d : Value %lld is less than the minimum (%lld)\n", ctl->name, index, int64_val, snd_ctl_elem_info_get_min64(ctl->info)); return false; } if (int64_val > snd_ctl_elem_info_get_max64(ctl->info)) { - ksft_print_msg("%s.%d value %lld more than maximum %lld\n", + ksft_print_msg("%s.%d : Value %lld is more than the maximum (%lld)\n", ctl->name, index, int64_val, snd_ctl_elem_info_get_max(ctl->info)); return false; @@ -368,7 +367,7 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, if (snd_ctl_elem_info_get_step64(ctl->info) && (int64_val - snd_ctl_elem_info_get_min64(ctl->info)) % snd_ctl_elem_info_get_step64(ctl->info)) { - ksft_print_msg("%s.%d value %lld invalid for step %lld minimum %lld\n", + ksft_print_msg("%s.%d : Value %lld is invalid for step %lld, minimum %lld\n", ctl->name, index, int64_val, snd_ctl_elem_info_get_step64(ctl->info), snd_ctl_elem_info_get_min64(ctl->info)); @@ -380,13 +379,13 @@ static bool ctl_value_index_valid(struct ctl_data *ctl, int_val = snd_ctl_elem_value_get_enumerated(val, index); if (int_val < 0) { - ksft_print_msg("%s.%d negative value %ld for enumeration\n", + ksft_print_msg("%s.%d : Negative value %ld for enumeration\n", ctl->name, index, int_val); return false; } if (int_val >= snd_ctl_elem_info_get_items(ctl->info)) { - ksft_print_msg("%s.%d value %ld more than item count %ld\n", + ksft_print_msg("%s.%d : Value %ld is more than item count (%ld)\n", ctl->name, index, int_val, snd_ctl_elem_info_get_items(ctl->info)); return false; @@ -427,7 +426,7 @@ static void test_ctl_get_value(struct ctl_data *ctl) /* If the control is turned off let's be polite */ if (snd_ctl_elem_info_is_inactive(ctl->info)) { - ksft_print_msg("%s is inactive\n", ctl->name); + ksft_print_msg("%s : Inactive\n", ctl->name); ksft_test_result_skip("get_value.%d.%d\n", ctl->card->card, ctl->elem); return; @@ -435,7 +434,7 @@ static void test_ctl_get_value(struct ctl_data *ctl) /* Can't test reading on an unreadable control */ if (!snd_ctl_elem_info_is_readable(ctl->info)) { - ksft_print_msg("%s is not readable\n", ctl->name); + ksft_print_msg("%s : Not readable\n", ctl->name); ksft_test_result_skip("get_value.%d.%d\n", ctl->card->card, ctl->elem); return; @@ -443,7 +442,7 @@ static void test_ctl_get_value(struct ctl_data *ctl) err = snd_ctl_elem_read(ctl->card->handle, ctl->def_val); if (err < 0) { - ksft_print_msg("snd_ctl_elem_read() failed: %s\n", + ksft_print_msg("snd_ctl_elem_read() failed (%s)\n", snd_strerror(err)); goto out; } @@ -474,7 +473,7 @@ static void test_ctl_name(struct ctl_data *ctl) /* Only boolean controls should end in Switch */ if (strend(ctl->name, " Switch")) { if (snd_ctl_elem_info_get_type(ctl->info) != SND_CTL_ELEM_TYPE_BOOLEAN) { - ksft_print_msg("%d.%d %s ends in Switch but is not boolean\n", + ksft_print_msg("%d.%d %s : Not a boolean, but name ends in Switch\n", ctl->card->card, ctl->elem, ctl->name); name_ok = false; } @@ -484,7 +483,7 @@ static void test_ctl_name(struct ctl_data *ctl) if (snd_ctl_elem_info_get_type(ctl->info) == SND_CTL_ELEM_TYPE_BOOLEAN && snd_ctl_elem_info_is_writable(ctl->info)) { if (!strend(ctl->name, " Switch")) { - ksft_print_msg("%d.%d %s is a writeable boolean but not a Switch\n", + ksft_print_msg("%d.%d %s : Not a Switch despite being a writeable boolean\n", ctl->card->card, ctl->elem, ctl->name); name_ok = false; } @@ -542,11 +541,12 @@ static bool show_mismatch(struct ctl_data *ctl, int index, /* * NOTE: The volatile attribute means that the hardware * can voluntarily change the state of control element - * independent of any operation by software. + * independent of any operation by software. */ bool is_volatile = snd_ctl_elem_info_is_volatile(ctl->info); - ksft_print_msg("%s.%d expected %lld but read %lld, is_volatile %d\n", - ctl->name, index, expected_int, read_int, is_volatile); + ksft_print_msg("%s.%d : Expected %lld, but read %lld (%s)\n", + ctl->name, index, expected_int, read_int, + (is_volatile ? "Volatile" : "Non-volatile")); return !is_volatile; } else { return false; @@ -590,7 +590,7 @@ static int write_and_verify(struct ctl_data *ctl, err = snd_ctl_elem_read(ctl->card->handle, initial_val); if (err < 0) { - ksft_print_msg("snd_ctl_elem_read() failed: %s\n", + ksft_print_msg("snd_ctl_elem_read() failed (%s)\n", snd_strerror(err)); return err; } @@ -602,7 +602,7 @@ static int write_and_verify(struct ctl_data *ctl, */ err = snd_ctl_elem_write(ctl->card->handle, w_val); if (err < 0 && !error_expected) { - ksft_print_msg("snd_ctl_elem_write() failed: %s\n", + ksft_print_msg("snd_ctl_elem_write() failed (%s)\n", snd_strerror(err)); return err; } @@ -615,7 +615,7 @@ static int write_and_verify(struct ctl_data *ctl, err = snd_ctl_elem_read(ctl->card->handle, read_val); if (err < 0) { - ksft_print_msg("snd_ctl_elem_read() failed: %s\n", + ksft_print_msg("snd_ctl_elem_read() failed (%s)\n", snd_strerror(err)); return err; } @@ -631,13 +631,13 @@ static int write_and_verify(struct ctl_data *ctl, err = wait_for_event(ctl, 0); if (snd_ctl_elem_value_compare(initial_val, read_val)) { if (err < 1) { - ksft_print_msg("No event generated for %s\n", + ksft_print_msg("%s : No event generated\n", ctl->name); ctl->event_missing++; } } else { if (err != 0) { - ksft_print_msg("Spurious event generated for %s\n", + ksft_print_msg("%s : Spurious event generated\n", ctl->name); ctl->event_spurious++; } @@ -658,7 +658,7 @@ static int write_and_verify(struct ctl_data *ctl, mismatch_shown = true; if (!mismatch_shown) - ksft_print_msg("%s read and written values differ\n", + ksft_print_msg("%s : Read and written values differ\n", ctl->name); return -1; @@ -674,14 +674,14 @@ static void test_ctl_write_default(struct ctl_data *ctl) /* If the control is turned off let's be polite */ if (snd_ctl_elem_info_is_inactive(ctl->info)) { - ksft_print_msg("%s is inactive\n", ctl->name); + ksft_print_msg("%s : Inactive\n", ctl->name); ksft_test_result_skip("write_default.%d.%d\n", ctl->card->card, ctl->elem); return; } if (!snd_ctl_elem_info_is_writable(ctl->info)) { - ksft_print_msg("%s is not writeable\n", ctl->name); + ksft_print_msg("%s : Not writeable\n", ctl->name); ksft_test_result_skip("write_default.%d.%d\n", ctl->card->card, ctl->elem); return; @@ -689,7 +689,7 @@ static void test_ctl_write_default(struct ctl_data *ctl) /* No idea what the default was for unreadable controls */ if (!snd_ctl_elem_info_is_readable(ctl->info)) { - ksft_print_msg("%s couldn't read default\n", ctl->name); + ksft_print_msg("%s : Couldn't read default\n", ctl->name); ksft_test_result_skip("write_default.%d.%d\n", ctl->card->card, ctl->elem); return; @@ -808,14 +808,14 @@ static void test_ctl_write_valid(struct ctl_data *ctl) /* If the control is turned off let's be polite */ if (snd_ctl_elem_info_is_inactive(ctl->info)) { - ksft_print_msg("%s is inactive\n", ctl->name); + ksft_print_msg("%s : Inactive\n", ctl->name); ksft_test_result_skip("write_valid.%d.%d\n", ctl->card->card, ctl->elem); return; } if (!snd_ctl_elem_info_is_writable(ctl->info)) { - ksft_print_msg("%s is not writeable\n", ctl->name); + ksft_print_msg("%s : Not writeable\n", ctl->name); ksft_test_result_skip("write_valid.%d.%d\n", ctl->card->card, ctl->elem); return; @@ -868,7 +868,7 @@ static bool test_ctl_write_invalid_value(struct ctl_data *ctl, /* ...but some devices will clamp to an in range value */ err = snd_ctl_elem_read(ctl->card->handle, val); if (err < 0) { - ksft_print_msg("%s failed to read: %s\n", + ksft_print_msg("%s : Failed to read (%s)\n", ctl->name, snd_strerror(err)); return true; } @@ -1026,14 +1026,14 @@ static void test_ctl_write_invalid(struct ctl_data *ctl) /* If the control is turned off let's be polite */ if (snd_ctl_elem_info_is_inactive(ctl->info)) { - ksft_print_msg("%s is inactive\n", ctl->name); + ksft_print_msg("%s : Inactive\n", ctl->name); ksft_test_result_skip("write_invalid.%d.%d\n", ctl->card->card, ctl->elem); return; } if (!snd_ctl_elem_info_is_writable(ctl->info)) { - ksft_print_msg("%s is not writeable\n", ctl->name); + ksft_print_msg("%s : Not writeable\n", ctl->name); ksft_test_result_skip("write_invalid.%d.%d\n", ctl->card->card, ctl->elem); return;
This allows for potentially better machine-parsing due to an expected / fixed format. Also because of eyecandy reasons. Whenever possible, errors will start with the name of the offending card/control, separated by the error with colons. Whenever there is a description of an error given, the generated error string from snd_strerror will be (mostly) enclosed in parentheses at the end. Clarity of error messages have been (hopefully) improved. Signed-off-by: Siddh Raman Pant <siddhpant.gh@gmail.com> --- tools/testing/selftests/alsa/mixer-test.c | 94 +++++++++++------------ 1 file changed, 47 insertions(+), 47 deletions(-)