[PATCH v2 0/2] kselftest/alsa: Diagnostic improvements

[PATCH v2 0/2] kselftest/alsa: Diagnostic improvements

[Mark Brown]

The first patch fixes unstable naming of tests due to probe ordering not
being stable, the second just provides a bit more information.

Signed-off-by: Mark Brown <broonie@kernel.org>
---
Changes in v2:
- Switch to using ID rather than longame.
- Log the PCM ID too.
- Link to v1: https://lore.kernel.org/r/20240711-alsa-kselftest-board-name-v1-1-ab5cf2dbbea6@kernel.org

---
Mark Brown (2):
      kselftest/alsa: Use card name rather than number in test names
      kselftest/alsa: Log the PCM ID in pcm-test

 tools/testing/selftests/alsa/mixer-test.c | 98 +++++++++++++++++++------------
 tools/testing/selftests/alsa/pcm-test.c   | 68 +++++++++++++++------
 2 files changed, 108 insertions(+), 58 deletions(-)
---
base-commit: f2661062f16b2de5d7b6a5c42a9a5c96326b8454
change-id: 20240711-alsa-kselftest-board-name-e4a1add4cfa0

Best regards,
-- 
Mark Brown <broonie@kernel.org>

[PATCH v2 1/2] kselftest/alsa: Use card name rather than number in test names

[Mark Brown]

Currently for the PCM and mixer tests we report test names which identify
the card being tested with the card number. This ensures we have unique
names but since card numbers are dynamically assigned at runtime the names
we end up with will often not be stable on systems with multiple cards
especially where those cards are provided by separate modules loeaded at
runtime. This makes it difficult for automated systems and UIs to relate
test results between runs on affected platforms.

Address this by replacing our use of card numbers with card names which are
more likely to be stable across runs. We use the card ID since it is
guaranteed to be unique by default, unlike the long name. There is still
some vulnerability to ordering issues if multiple cards with the same base
ID are present in the system but have separate dependencies but not all
drivers put distinguishing information in their long names.

Signed-off-by: Mark Brown <broonie@kernel.org>
---
 tools/testing/selftests/alsa/mixer-test.c | 98 +++++++++++++++++++------------
 tools/testing/selftests/alsa/pcm-test.c   | 64 ++++++++++++++------
 2 files changed, 104 insertions(+), 58 deletions(-)

diff --git a/tools/testing/selftests/alsa/mixer-test.c b/tools/testing/selftests/alsa/mixer-test.c
index 1c04e5f638a0..ba437f789768 100644
--- a/tools/testing/selftests/alsa/mixer-test.c
+++ b/tools/testing/selftests/alsa/mixer-test.c
@@ -33,6 +33,8 @@
 struct card_data {
 	snd_ctl_t *handle;
 	int card;
+	snd_ctl_card_info_t *info;
+	const char *card_name;
 	struct pollfd pollfd;
 	int num_ctls;
 	snd_ctl_elem_list_t *ctls;
@@ -91,8 +93,26 @@ static void find_controls(void)
 		err = snd_card_get_longname(card, &card_longname);
 		if (err != 0)
 			card_longname = "Unknown";
-		ksft_print_msg("Card %d - %s (%s)\n", card,
-			       card_name, card_longname);
+
+		err = snd_ctl_card_info_malloc(&card_data->info);
+		if (err != 0)
+			ksft_exit_fail_msg("Failed to allocate card info: %d\n",
+				err);
+
+		err = snd_ctl_card_info(card_data->handle, card_data->info);
+		if (err == 0) {
+			card_data->card_name = snd_ctl_card_info_get_id(card_data->info);
+			if (!card_data->card_name)
+				ksft_print_msg("Failed to get card ID\n");
+		} else {
+			ksft_print_msg("Failed to get card info: %d\n", err);
+		}
+
+		if (!card_data->card_name)
+			card_data->card_name = "Unknown";
+
+		ksft_print_msg("Card %d/%s - %s (%s)\n", card,
+			       card_data->card_name, card_name, card_longname);
 
 		/* Count controls */
 		snd_ctl_elem_list_malloc(&card_data->ctls);
@@ -389,16 +409,16 @@ 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_test_result_skip("get_value.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("get_value.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	/* 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_test_result_skip("get_value.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("get_value.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
@@ -413,8 +433,8 @@ static void test_ctl_get_value(struct ctl_data *ctl)
 		err = -EINVAL;
 
 out:
-	ksft_test_result(err >= 0, "get_value.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(err >= 0, "get_value.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 static bool strend(const char *haystack, const char *needle)
@@ -431,7 +451,7 @@ static void test_ctl_name(struct ctl_data *ctl)
 {
 	bool name_ok = true;
 
-	ksft_print_msg("%d.%d %s\n", ctl->card->card, ctl->elem,
+	ksft_print_msg("%s.%d %s\n", ctl->card->card_name, ctl->elem,
 		       ctl->name);
 
 	/* Only boolean controls should end in Switch */
@@ -453,8 +473,8 @@ static void test_ctl_name(struct ctl_data *ctl)
 		}
 	}
 
-	ksft_test_result(name_ok, "name.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(name_ok, "name.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 static void show_values(struct ctl_data *ctl, snd_ctl_elem_value_t *orig_val,
@@ -682,30 +702,30 @@ 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_test_result_skip("write_default.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_default.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	if (!snd_ctl_elem_info_is_writable(ctl->info)) {
 		ksft_print_msg("%s is not writeable\n", ctl->name);
-		ksft_test_result_skip("write_default.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_default.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	/* 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_test_result_skip("write_default.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_default.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	err = write_and_verify(ctl, ctl->def_val, NULL);
 
-	ksft_test_result(err >= 0, "write_default.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(err >= 0, "write_default.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 static bool test_ctl_write_valid_boolean(struct ctl_data *ctl)
@@ -815,15 +835,15 @@ 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_test_result_skip("write_valid.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_valid.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	if (!snd_ctl_elem_info_is_writable(ctl->info)) {
 		ksft_print_msg("%s is not writeable\n", ctl->name);
-		ksft_test_result_skip("write_valid.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_valid.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
@@ -846,16 +866,16 @@ static void test_ctl_write_valid(struct ctl_data *ctl)
 
 	default:
 		/* No tests for this yet */
-		ksft_test_result_skip("write_valid.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_valid.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	/* Restore the default value to minimise disruption */
 	write_and_verify(ctl, ctl->def_val, NULL);
 
-	ksft_test_result(pass, "write_valid.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(pass, "write_valid.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 static bool test_ctl_write_invalid_value(struct ctl_data *ctl,
@@ -1027,15 +1047,15 @@ 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_test_result_skip("write_invalid.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_invalid.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	if (!snd_ctl_elem_info_is_writable(ctl->info)) {
 		ksft_print_msg("%s is not writeable\n", ctl->name);
-		ksft_test_result_skip("write_invalid.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_invalid.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
@@ -1058,28 +1078,28 @@ static void test_ctl_write_invalid(struct ctl_data *ctl)
 
 	default:
 		/* No tests for this yet */
-		ksft_test_result_skip("write_invalid.%d.%d\n",
-				      ctl->card->card, ctl->elem);
+		ksft_test_result_skip("write_invalid.%s.%d\n",
+				      ctl->card->card_name, ctl->elem);
 		return;
 	}
 
 	/* Restore the default value to minimise disruption */
 	write_and_verify(ctl, ctl->def_val, NULL);
 
-	ksft_test_result(pass, "write_invalid.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(pass, "write_invalid.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 static void test_ctl_event_missing(struct ctl_data *ctl)
 {
-	ksft_test_result(!ctl->event_missing, "event_missing.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(!ctl->event_missing, "event_missing.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 static void test_ctl_event_spurious(struct ctl_data *ctl)
 {
-	ksft_test_result(!ctl->event_spurious, "event_spurious.%d.%d\n",
-			 ctl->card->card, ctl->elem);
+	ksft_test_result(!ctl->event_spurious, "event_spurious.%s.%d\n",
+			 ctl->card->card_name, ctl->elem);
 }
 
 int main(void)
diff --git a/tools/testing/selftests/alsa/pcm-test.c b/tools/testing/selftests/alsa/pcm-test.c
index de664dedb541..7abb21845e10 100644
--- a/tools/testing/selftests/alsa/pcm-test.c
+++ b/tools/testing/selftests/alsa/pcm-test.c
@@ -24,6 +24,8 @@ typedef struct timespec timestamp_t;
 
 struct card_data {
 	int card;
+	snd_ctl_card_info_t *info;
+	const char *name;
 	pthread_t thread;
 	struct card_data *next;
 };
@@ -35,6 +37,7 @@ struct pcm_data {
 	int card;
 	int device;
 	int subdevice;
+	const char *card_name;
 	snd_pcm_stream_t stream;
 	snd_config_t *pcm_config;
 	struct pcm_data *next;
@@ -167,6 +170,10 @@ static void find_pcms(void)
 	config = get_alsalib_config();
 
 	while (card >= 0) {
+		card_data = calloc(1, sizeof(*card_data));
+		if (!card_data)
+			ksft_exit_fail_msg("Out of memory\n");
+
 		sprintf(name, "hw:%d", card);
 
 		err = snd_ctl_open_lconf(&handle, name, 0, config);
@@ -182,14 +189,29 @@ static void find_pcms(void)
 		err = snd_card_get_longname(card, &card_longname);
 		if (err != 0)
 			card_longname = "Unknown";
-		ksft_print_msg("Card %d - %s (%s)\n", card,
-			       card_name, card_longname);
+
+		err = snd_ctl_card_info_malloc(&card_data->info);
+		if (err != 0)
+			ksft_exit_fail_msg("Failed to allocate card info: %d\n",
+				err);
+
+		err = snd_ctl_card_info(handle, card_data->info);
+		if (err == 0) {
+			card_data->name = snd_ctl_card_info_get_id(card_data->info);
+			if (!card_data->name)
+				ksft_print_msg("Failed to get card ID\n");
+		} else {
+			ksft_print_msg("Failed to get card info: %d\n", err);
+		}
+
+		if (!card_data->name)
+			card_data->name = "Unknown";
+
+		ksft_print_msg("Card %d/%s - %s (%s)\n", card,
+			       card_data->name, card_name, card_longname);
 
 		card_config = conf_by_card(card);
 
-		card_data = calloc(1, sizeof(*card_data));
-		if (!card_data)
-			ksft_exit_fail_msg("Out of memory\n");
 		card_data->card = card;
 		card_data->next = card_list;
 		card_list = card_data;
@@ -232,6 +254,7 @@ static void find_pcms(void)
 					pcm_data->card = card;
 					pcm_data->device = dev;
 					pcm_data->subdevice = subdev;
+					pcm_data->card_name = card_data->name;
 					pcm_data->stream = stream;
 					pcm_data->pcm_config = conf_get_subtree(card_config, key, NULL);
 					pcm_data->next = pcm_list;
@@ -294,9 +317,9 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class,
 
 	desc = conf_get_string(pcm_cfg, "description", NULL, NULL);
 	if (desc)
-		ksft_print_msg("%s.%s.%d.%d.%d.%s - %s\n",
+		ksft_print_msg("%s.%s.%s.%d.%d.%s - %s\n",
 			       test_class_name, test_name,
-			       data->card, data->device, data->subdevice,
+			       data->card_name, data->device, data->subdevice,
 			       snd_pcm_stream_name(data->stream),
 			       desc);
 
@@ -352,9 +375,9 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class,
 			old_format = format;
 			format = snd_pcm_format_value(alt_formats[i]);
 			if (format != SND_PCM_FORMAT_UNKNOWN) {
-				ksft_print_msg("%s.%d.%d.%d.%s.%s format %s -> %s\n",
+				ksft_print_msg("%s.%s.%d.%d.%s.%s format %s -> %s\n",
 						 test_name,
-						 data->card, data->device, data->subdevice,
+						 data->card_name, data->device, data->subdevice,
 						 snd_pcm_stream_name(data->stream),
 						 snd_pcm_access_name(access),
 						 snd_pcm_format_name(old_format),
@@ -430,9 +453,9 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class,
 		goto __close;
 	}
 
-	ksft_print_msg("%s.%s.%d.%d.%d.%s hw_params.%s.%s.%ld.%ld.%ld.%ld sw_params.%ld\n",
+	ksft_print_msg("%s.%s.%s.%d.%d.%s hw_params.%s.%s.%ld.%ld.%ld.%ld sw_params.%ld\n",
 		         test_class_name, test_name,
-			 data->card, data->device, data->subdevice,
+			 data->card_name, data->device, data->subdevice,
 			 snd_pcm_stream_name(data->stream),
 			 snd_pcm_access_name(access),
 			 snd_pcm_format_name(format),
@@ -491,9 +514,10 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class,
 		 * Anything specified as specific to this system
 		 * should always be supported.
 		 */
-		ksft_test_result(!skip, "%s.%s.%d.%d.%d.%s.params\n",
+		ksft_test_result(!skip, "%s.%s.%s.%d.%d.%s.params\n",
 				 test_class_name, test_name,
-				 data->card, data->device, data->subdevice,
+				 data->card_name, data->device,
+				 data->subdevice,
 				 snd_pcm_stream_name(data->stream));
 		break;
 	default:
@@ -501,14 +525,16 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class,
 	}
 
 	if (!skip)
-		ksft_test_result(pass, "%s.%s.%d.%d.%d.%s\n",
+		ksft_test_result(pass, "%s.%s.%s.%d.%d.%s\n",
 				 test_class_name, test_name,
-				 data->card, data->device, data->subdevice,
+				 data->card_name, data->device,
+				 data->subdevice,
 				 snd_pcm_stream_name(data->stream));
 	else
-		ksft_test_result_skip("%s.%s.%d.%d.%d.%s\n",
+		ksft_test_result_skip("%s.%s.%s.%d.%d.%s\n",
 				 test_class_name, test_name,
-				 data->card, data->device, data->subdevice,
+				 data->card_name, data->device,
+				 data->subdevice,
 				 snd_pcm_stream_name(data->stream));
 
 	if (msg[0])
@@ -609,8 +635,8 @@ int main(void)
 					      conf->filename, conf->config_id);
 
 	for (pcm = pcm_missing; pcm != NULL; pcm = pcm->next) {
-		ksft_test_result(false, "test.missing.%d.%d.%d.%s\n",
-				 pcm->card, pcm->device, pcm->subdevice,
+		ksft_test_result(false, "test.missing.%s.%d.%d.%s\n",
+				 pcm->card_name, pcm->device, pcm->subdevice,
 				 snd_pcm_stream_name(pcm->stream));
 	}
 

-- 
2.39.2

[PATCH v2 2/2] kselftest/alsa: Log the PCM ID in pcm-test

[Mark Brown]

Drivers report a string with a name for each PCM, log it during startup of
pcm-test as a diagnostic aid.

Signed-off-by: Mark Brown <broonie@kernel.org>
---
 tools/testing/selftests/alsa/pcm-test.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/tools/testing/selftests/alsa/pcm-test.c b/tools/testing/selftests/alsa/pcm-test.c
index 7abb21845e10..70a96d64cbdc 100644
--- a/tools/testing/selftests/alsa/pcm-test.c
+++ b/tools/testing/selftests/alsa/pcm-test.c
@@ -240,6 +240,10 @@ static void find_pcms(void)
 				if (err < 0)
 					ksft_exit_fail_msg("snd_ctl_pcm_info: %d:%d:%d\n",
 							   dev, 0, stream);
+
+				ksft_print_msg("%s.0 - %s\n", card_data->name,
+					       snd_pcm_info_get_id(pcm_info));
+
 				count = snd_pcm_info_get_subdevices_count(pcm_info);
 				for (subdev = 0; subdev < count; subdev++) {
 					sprintf(key, "pcm.%d.%d.%s", dev, subdev, snd_pcm_stream_name(stream));

-- 
2.39.2

Re: [PATCH v2 0/2] kselftest/alsa: Diagnostic improvements

[Takashi Iwai]

On Tue, 16 Jul 2024 16:47:58 +0200,
Mark Brown wrote:
> 
> The first patch fixes unstable naming of tests due to probe ordering not
> being stable, the second just provides a bit more information.
> 
> Signed-off-by: Mark Brown <broonie@kernel.org>
> ---
> Changes in v2:
> - Switch to using ID rather than longame.
> - Log the PCM ID too.
> - Link to v1: https://lore.kernel.org/r/20240711-alsa-kselftest-board-name-v1-1-ab5cf2dbbea6@kernel.org
> 
> ---
> Mark Brown (2):
>       kselftest/alsa: Use card name rather than number in test names
>       kselftest/alsa: Log the PCM ID in pcm-test

Applied both patches now.  Thanks!


Takashi