Commit 8597aa5a authored by Curt Bruns's avatar Curt Bruns Committed by Tomasz Zawadzki
Browse files

test: optimize the print statements in aer test 



The aer test print statements were overly complicated for multi
process mode, so a macro was created to simplify them. The macro
will prepend "[Child]" to the child process print statements to
make it easier to see which process is doing the printouts.

Signed-off-by: default avatarCurt Bruns <curt.e.bruns@gmail.com>
Change-Id: I0ecc5e2526b156fa7f98d44c745408ba922ebeff
Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/12881


Community-CI: Broadcom CI <spdk-ci.pdl@broadcom.com>
Tested-by: default avatarSPDK CI Jenkins <sys_sgci@intel.com>
Reviewed-by: default avatarPaul Luse <paul.e.luse@intel.com>
Reviewed-by: default avatarJim Harris <james.r.harris@intel.com>
Reviewed-by: default avatarShuhei Matsumoto <smatsumoto@nvidia.com>
parent fb12887f

test/nvme/aer/aer.c

+79 −77
Original line number Diff line number Diff line
@@ -28,6 +28,10 @@ static int g_num_devs = 0; 


#define foreach_dev(iter) \

	for (iter = g_devs; iter - g_devs < g_num_devs; iter++)

#define AER_PRINTF(format, ...) printf("%s" format, g_parent_process ? "" : "[Child] ", \

	##__VA_ARGS__)

#define AER_FPRINTF(f, format, ...) fprintf(f, "%s" format, g_parent_process ? \

	"" : "[Child] ", ##__VA_ARGS__)



static int g_outstanding_commands = 0;

static int g_aer_done = 0;
@@ -42,7 +46,7 @@ static int g_enable_temp_test = 0; 
static uint32_t g_expected_ns_test = 0;

/* For multi-process test */

static int g_multi_process_test = 0;

static bool g_parent_process;

static bool g_parent_process = true;

static const char *g_sem_init_name = "/init";

static const char *g_sem_child_name = "/child";

static sem_t *g_sem_init_id;
@@ -56,7 +60,7 @@ set_temp_completion(void *cb_arg, const struct spdk_nvme_cpl *cpl) 
	g_outstanding_commands--;



	if (spdk_nvme_cpl_is_error(cpl)) {

		printf("%s: set feature (temp threshold) failed\n", dev->name);

		AER_PRINTF("%s: set feature (temp threshold) failed\n", dev->name);

		g_failed = 1;

		return;

	}
@@ -80,8 +84,7 @@ set_temp_threshold(struct dev *dev, uint32_t temp) 
	if (rc == 0) {

		g_outstanding_commands++;

	} else {

		fprintf(stderr, "Submitting Admin cmd failed with rc: %d (%s)\n", \

			rc, (g_parent_process ? "Parent" : "Child"));

		AER_FPRINTF(stderr, "Submitting Admin cmd failed with rc: %d\n", rc);

	}



	return rc;
@@ -95,13 +98,13 @@ get_temp_completion(void *cb_arg, const struct spdk_nvme_cpl *cpl) 
	g_outstanding_commands--;



	if (spdk_nvme_cpl_is_error(cpl)) {

		printf("%s: get feature (temp threshold) failed\n", dev->name);

		AER_PRINTF("%s: get feature (temp threshold) failed\n", dev->name);

		g_failed = 1;

		return;

	}



	dev->orig_temp_threshold = cpl->cdw0;

	printf("%s: original temperature threshold: %u Kelvin (%d Celsius)\n",

	AER_PRINTF("%s: original temperature threshold: %u Kelvin (%d Celsius)\n",

		   dev->name, dev->orig_temp_threshold, dev->orig_temp_threshold - 273);



	g_temperature_done++;
@@ -127,7 +130,7 @@ get_temp_threshold(struct dev *dev) 
static void

print_health_page(struct dev *dev, struct spdk_nvme_health_information_page *hip)

{

	printf("%s: Current Temperature:         %u Kelvin (%d Celsius)\n",

	AER_PRINTF("%s: Current Temperature:         %u Kelvin (%d Celsius)\n",

		   dev->name, hip->temperature, hip->temperature - 273);

}
@@ -139,7 +142,7 @@ get_health_log_page_completion(void *cb_arg, const struct spdk_nvme_cpl *cpl) 
	g_outstanding_commands--;



	if (spdk_nvme_cpl_is_error(cpl)) {

		printf("%s: get log page failed\n", dev->name);

		AER_PRINTF("%s: get log page failed\n", dev->name);

		g_failed = 1;

		return;

	}
@@ -154,7 +157,8 @@ get_health_log_page(struct dev *dev) 
	int rc;



	rc = spdk_nvme_ctrlr_cmd_get_log_page(dev->ctrlr, SPDK_NVME_LOG_HEALTH_INFORMATION,

					      SPDK_NVME_GLOBAL_NS_TAG, dev->health_page, sizeof(*dev->health_page), 0,

					      SPDK_NVME_GLOBAL_NS_TAG, dev->health_page,

					      sizeof(*dev->health_page), 0,

					      get_health_log_page_completion, dev);



	if (rc == 0) {
@@ -202,14 +206,13 @@ aer_cb(void *arg, const struct spdk_nvme_cpl *cpl) 
	log_page_id = aen_cpl.bits.log_page_identifier;



	if (spdk_nvme_cpl_is_error(cpl)) {

		fprintf(stderr, "%s: AER failed\n", dev->name);

		AER_FPRINTF(stderr, "%s: AER failed\n", dev->name);

		g_failed = 1;

		return;

	}



	printf("%s: aer_cb for log page %d, aen_event_type: 0x%02x, aen_event_info: 0x%02x (%s)\n", \

	       dev->name, log_page_id, aen_event_type, aen_event_info, \

	       (g_parent_process ? "Parent" : "Child"));

	AER_PRINTF("%s: aer_cb for log page %d, aen_event_type: 0x%02x, aen_event_info: 0x%02x\n",

		   dev->name, log_page_id, aen_event_type, aen_event_info);

	/* Temp Test: Verify proper EventType, Event Info and Log Page.

	 * NOTE: QEMU NVMe controllers return Spare Below Threshold Status event info

	 * instead of Temperate Threshold even info which is why it's used in the check
@@ -220,46 +223,43 @@ aer_cb(void *arg, const struct spdk_nvme_cpl *cpl) 
	    ((aen_event_info == SPDK_NVME_ASYNC_EVENT_TEMPERATURE_THRESHOLD) || \

	     (aen_event_info == SPDK_NVME_ASYNC_EVENT_SPARE_BELOW_THRESHOLD))) {

		/* Set the temperature threshold back to the original value to stop triggering  */

		printf("aer_cb - Resetting Temp Threshold for device: %s (%s)\n", \

		       dev->name, (g_parent_process ? "Parent" : "Child"));

		AER_PRINTF("aer_cb - Resetting Temp Threshold for device: %s\n", dev->name);

		set_temp_threshold(dev, dev->orig_temp_threshold);

		get_health_log_page(dev);

	} else if (log_page_id == SPDK_NVME_LOG_CHANGED_NS_LIST) {

		printf("aer_cb - Changed Namespace (%s)\n", \

		       (g_parent_process ? "Parent" : "Child"));

		AER_PRINTF("aer_cb - Changed Namespace\n");

		get_ns_state_test(dev, g_expected_ns_test);

		g_aer_done++;

	} else {

		printf("aer_cb - Unknown Log Page (%s)\n", \

		       (g_parent_process ? "Parent" : "Child"));

		AER_PRINTF("aer_cb - Unknown Log Page\n");

	}

}



static void

usage(const char *program_name)

{

	printf("%s [options]", program_name);

	printf("\n");

	printf("options:\n");

	printf(" -g         use single file descriptor for DPDK memory segments]\n");

	printf(" -T         enable temperature tests\n");

	printf(" -n         expected Namespace attribute notice ID\n");

	printf(" -t <file>  touch specified file when ready to receive AER\n");

	printf(" -r trid    remote NVMe over Fabrics target address\n");

	printf("    Format: 'key:value [key:value] ...'\n");

	printf("    Keys:\n");

	printf("     trtype      Transport type (e.g. RDMA)\n");

	printf("     adrfam      Address family (e.g. IPv4, IPv6)\n");

	printf("     traddr      Transport address (e.g. 192.168.100.8)\n");

	printf("     trsvcid     Transport service identifier (e.g. 4420)\n");

	printf("     subnqn      Subsystem NQN (default: %s)\n", SPDK_NVMF_DISCOVERY_NQN);

	printf("    Example: -r 'trtype:RDMA adrfam:IPv4 traddr:192.168.100.8 trsvcid:4420'\n");

	AER_PRINTF("%s [options]", program_name);

	AER_PRINTF("\n");

	AER_PRINTF("options:\n");

	AER_PRINTF(" -g         use single file descriptor for DPDK memory segments]\n");

	AER_PRINTF(" -T         enable temperature tests\n");

	AER_PRINTF(" -n         expected Namespace attribute notice ID\n");

	AER_PRINTF(" -t <file>  touch specified file when ready to receive AER\n");

	AER_PRINTF(" -r trid    remote NVMe over Fabrics target address\n");

	AER_PRINTF("    Format: 'key:value [key:value] ...'\n");

	AER_PRINTF("    Keys:\n");

	AER_PRINTF("     trtype      Transport type (e.g. RDMA)\n");

	AER_PRINTF("     adrfam      Address family (e.g. IPv4, IPv6)\n");

	AER_PRINTF("     traddr      Transport address (e.g. 192.168.100.8)\n");

	AER_PRINTF("     trsvcid     Transport service identifier (e.g. 4420)\n");

	AER_PRINTF("     subnqn      Subsystem NQN (default: %s)\n", SPDK_NVMF_DISCOVERY_NQN);

	AER_PRINTF("    Example: -r 'trtype:RDMA adrfam:IPv4 traddr:192.168.100.8 trsvcid:4420'\n");



	spdk_log_usage(stdout, "-L");



	printf(" -i <id>    shared memory group ID\n");

	printf(" -m         Multi-Process AER Test (only with Temp Test)\n");

	printf(" -H         show this usage\n");

	AER_PRINTF(" -i <id>    shared memory group ID\n");

	AER_PRINTF(" -m         Multi-Process AER Test (only with Temp Test)\n");

	AER_PRINTF(" -H         show this usage\n");

}



static int
@@ -276,7 +276,7 @@ parse_args(int argc, char **argv, struct spdk_env_opts *env_opts) 
		case 'n':

			val = spdk_strtol(optarg, 10);

			if (val < 0) {

				fprintf(stderr, "Invalid NS attribute notice ID\n");

				AER_FPRINTF(stderr, "Invalid NS attribute notice ID\n");

				return val;

			}

			g_expected_ns_test = (uint32_t)val;
@@ -286,7 +286,7 @@ parse_args(int argc, char **argv, struct spdk_env_opts *env_opts) 
			break;

		case 'r':

			if (spdk_nvme_transport_id_parse(&g_trid, optarg) != 0) {

				fprintf(stderr, "Error parsing transport address\n");

				AER_FPRINTF(stderr, "Error parsing transport address\n");

				return 1;

			}

			break;
@@ -296,7 +296,7 @@ parse_args(int argc, char **argv, struct spdk_env_opts *env_opts) 
		case 'L':

			rc = spdk_log_set_flag(optarg);

			if (rc < 0) {

				fprintf(stderr, "unknown flag\n");

				AER_FPRINTF(stderr, "unknown flag\n");

				usage(argv[0]);

				exit(EXIT_FAILURE);

			}
@@ -313,7 +313,7 @@ parse_args(int argc, char **argv, struct spdk_env_opts *env_opts) 
		case 'i':

			env_opts->shm_id = spdk_strtol(optarg, 10);

			if (env_opts->shm_id < 0) {

				fprintf(stderr, "Invalid shared memory ID\n");

				AER_FPRINTF(stderr, "Invalid shared memory ID\n");

				return env_opts->shm_id;

			}

			break;
@@ -333,7 +333,7 @@ static bool 
probe_cb(void *cb_ctx, const struct spdk_nvme_transport_id *trid,

	 struct spdk_nvme_ctrlr_opts *opts)

{

	printf("Attaching to %s\n", trid->traddr);

	AER_PRINTF("Attaching to %s\n", trid->traddr);



	return true;

}
@@ -352,12 +352,12 @@ attach_cb(void *cb_ctx, const struct spdk_nvme_transport_id *trid, 
	snprintf(dev->name, sizeof(dev->name), "%s",

		 trid->traddr);



	printf("Attached to %s\n", dev->name);

	AER_PRINTF("Attached to %s\n", dev->name);



	dev->health_page = spdk_zmalloc(sizeof(*dev->health_page), 4096, NULL, SPDK_ENV_LCORE_ID_ANY,

					SPDK_MALLOC_DMA);

	if (dev->health_page == NULL) {

		printf("Allocation error (health page)\n");

		AER_PRINTF("Allocation error (health page)\n");

		g_failed = 1;

	}

}
@@ -370,7 +370,7 @@ get_feature_test_cb(void *cb_arg, const struct spdk_nvme_cpl *cpl) 
	g_outstanding_commands--;



	if (spdk_nvme_cpl_is_error(cpl)) {

		printf("%s: get number of queues failed\n", dev->name);

		AER_PRINTF("%s: get number of queues failed\n", dev->name);

		g_failed = 1;

		return;

	}
@@ -394,7 +394,7 @@ get_feature_test(struct dev *dev) 
	cmd.cdw10_bits.get_features.fid = SPDK_NVME_FEAT_NUMBER_OF_QUEUES;

	if (spdk_nvme_ctrlr_cmd_admin_raw(dev->ctrlr, &cmd, NULL, 0,

					  get_feature_test_cb, dev) != 0) {

		printf("Failed to send Get Features command for dev=%p\n", dev);

		AER_PRINTF("Failed to send Get Features command for dev=%p\n", dev);

		g_failed = 1;

		return;

	}
@@ -407,8 +407,7 @@ spdk_aer_temperature_test(void) 
{

	struct dev *dev;



	printf("Getting orig temperature thresholds of all controllers (%s)\n",

	       (g_parent_process ? "Parent" : "Child"));

	AER_PRINTF("Getting orig temperature thresholds of all controllers\n");

	foreach_dev(dev) {

		/* Get the original temperature threshold */

		get_temp_threshold(dev);
@@ -441,13 +440,13 @@ spdk_aer_temperature_test(void) 
		if (g_multi_process_test) {

			sem_wait(g_sem_child_id);

		}

		printf("Setting all controllers temperature threshold low to trigger AER\n");

		AER_PRINTF("Setting all controllers temperature threshold low to trigger AER\n");

		foreach_dev(dev) {

			/* Set the temperature threshold to a low value */

			set_temp_threshold(dev, 200);

		}



		printf("Waiting for all controllers temperature threshold to be set lower\n");

		AER_PRINTF("Waiting for all controllers temperature threshold to be set lower\n");

		while (!g_failed && (g_temperature_done < g_num_devs)) {

			foreach_dev(dev) {

				spdk_nvme_ctrlr_process_admin_completions(dev->ctrlr);
@@ -460,8 +459,7 @@ spdk_aer_temperature_test(void) 
		}

	}



	printf("Waiting for all controllers to trigger AER and reset threshold (%s)\n",

	       (g_parent_process ? "Parent" : "Child"));

	AER_PRINTF("Waiting for all controllers to trigger AER and reset threshold\n");

	/* Let parent know init is done and it's okay to continue */

	if (!g_parent_process) {

		sem_post(g_sem_child_id);
@@ -487,7 +485,7 @@ spdk_aer_changed_ns_test(void) 


	g_aer_done = 0;



	printf("Starting namespace attribute notice tests for all controllers...\n");

	AER_PRINTF("Starting namespace attribute notice tests for all controllers...\n");



	foreach_dev(dev) {

		get_feature_test(dev);
@@ -520,12 +518,12 @@ setup_multi_process(void) 
	/* If AEN test was killed, remove named semaphore to start again */

	rc = sem_unlink(g_sem_init_name);

	if (rc < 0 && errno != ENOENT) {

		fprintf(stderr, "Init semaphore removal failure: %s", spdk_strerror(errno));

		AER_FPRINTF(stderr, "Init semaphore removal failure: %s", spdk_strerror(errno));

		return rc;

	}

	rc = sem_unlink(g_sem_child_name);

	if (rc < 0 && errno != ENOENT) {

		fprintf(stderr, "Child semaphore removal failure: %s", spdk_strerror(errno));

		AER_FPRINTF(stderr, "Child semaphore removal failure: %s", spdk_strerror(errno));

		return rc;

	}

	pid = fork();
@@ -533,12 +531,13 @@ setup_multi_process(void) 
		perror("Failed to fork\n");

		return -1;

	} else if (pid == 0) {

		printf("Child process pid: %d\n", getpid());

		AER_PRINTF("Child process pid: %d\n", getpid());

		g_parent_process = false;

		g_sem_init_id = sem_open(g_sem_init_name, O_CREAT, 0600, 0);

		g_sem_child_id = sem_open(g_sem_child_name, O_CREAT, 0600, 0);

		if ((g_sem_init_id == SEM_FAILED) || (g_sem_child_id == SEM_FAILED)) {

			fprintf(stderr, "Sem Open failed for child: %s\n", spdk_strerror(errno));

			AER_FPRINTF(stderr, "Sem Open failed for child: %s\n",

				    spdk_strerror(errno));

			return -1;

		}

	}
@@ -548,7 +547,8 @@ setup_multi_process(void) 
		g_sem_init_id = sem_open(g_sem_init_name, O_CREAT, 0600, 0);

		g_sem_child_id = sem_open(g_sem_child_name, O_CREAT, 0600, 0);

		if ((g_sem_init_id == SEM_FAILED) || (g_sem_child_id == SEM_FAILED)) {

			fprintf(stderr, "Sem Open failed for parent: %s\n", spdk_strerror(errno));

			AER_FPRINTF(stderr, "Sem Open failed for parent: %s\n",

				    spdk_strerror(errno));

			return -1;

		}

	}
@@ -571,16 +571,16 @@ int main(int argc, char **argv) 
	if (g_multi_process_test)  {

		/* Multi-Process test only available with Temp Test */

		if (!g_enable_temp_test) {

			fprintf(stderr, "Multi Process test only available with Temp Test (-T)\n");

			AER_FPRINTF(stderr, "Multi Process only available with Temp Test (-T)\n");

			return 1;

		}

		if (opts.shm_id < 0) {

			fprintf(stderr, "Multi Process requires shared memory id (-i <id>)\n");

			AER_FPRINTF(stderr, "Multi Process requires shared memory id (-i <id>)\n");

			return 1;

		}

		rc = setup_multi_process();

		if (rc != 0) {

			fprintf(stderr, "Multi Process test failed to setup\n");

			AER_FPRINTF(stderr, "Multi Process test failed to setup\n");

			return rc;

		}

	} else {
@@ -600,25 +600,24 @@ int main(int argc, char **argv) 
	 */

	if (!g_parent_process) {

		if (sem_wait(g_sem_init_id) < 0) {

			fprintf(stderr, "sem_wait failed for child process\n");

			AER_FPRINTF(stderr, "sem_wait failed for child process\n");

			return (-1);

		}

	}

	if (spdk_env_init(&opts) < 0) {

		fprintf(stderr, "Unable to initialize SPDK env\n");

		AER_FPRINTF(stderr, "Unable to initialize SPDK env\n");

		return 1;

	}



	printf("Asynchronous Event Request test (%s)\n",

	       (g_parent_process ? "Parent" : "Child"));

	AER_PRINTF("Asynchronous Event Request test\n");



	if (spdk_nvme_probe(&g_trid, NULL, probe_cb, attach_cb, NULL) != 0) {

		fprintf(stderr, "spdk_nvme_probe() failed\n");

		AER_FPRINTF(stderr, "spdk_nvme_probe() failed\n");

		return 1;

	}



	if (g_num_devs == 0) {

		fprintf(stderr, "No controllers found - exiting\n");

		AER_FPRINTF(stderr, "No controllers found - exiting\n");

		g_failed = 1;

	}

	if (g_failed) {
@@ -626,10 +625,10 @@ int main(int argc, char **argv) 
	}



	if (g_parent_process && g_enable_temp_test) {

		printf("Reset controller to setup AER completions for this process\n");

		AER_PRINTF("Reset controller to setup AER completions for this process\n");

		foreach_dev(dev) {

			if (spdk_nvme_ctrlr_reset(dev->ctrlr) < 0) {

				fprintf(stderr, "nvme reset failed.\n");

				AER_FPRINTF(stderr, "nvme reset failed.\n");

				return -1;

			}

		}
@@ -639,7 +638,7 @@ int main(int argc, char **argv) 
		sem_post(g_sem_init_id);

	}



	printf("Registering asynchronous event callbacks...\n");

	AER_PRINTF("Registering asynchronous event callbacks...\n");

	foreach_dev(dev) {

		spdk_nvme_ctrlr_register_aer_callback(dev->ctrlr, aer_cb, dev);

	}
@@ -649,7 +648,8 @@ int main(int argc, char **argv) 


		fd = open(g_touch_file, O_CREAT | O_EXCL | O_RDWR, S_IFREG);

		if (fd == -1) {

			fprintf(stderr, "Could not touch %s (%s).\n", g_touch_file, strerror(errno));

			AER_FPRINTF(stderr, "Could not touch %s (%s).\n", g_touch_file,

				    strerror(errno));

			g_failed = true;

			goto done;

		}
@@ -670,7 +670,7 @@ int main(int argc, char **argv) 
		}

	}



	printf("Cleaning up...(%s)\n", (g_parent_process ? "Parent" : "Child"));

	AER_PRINTF("Cleaning up...\n");



	while (g_outstanding_commands) {

		foreach_dev(dev) {
@@ -704,7 +704,8 @@ int main(int argc, char **argv) 
done:

	cleanup();



	/* Wait for child process to finish and verify it finished correctly before detaching resources */

	/* Wait for child process to finish and verify it finished correctly before detaching

	 * resources */

	if (g_multi_process_test && g_parent_process) {

		int status;

		sem_post(g_sem_init_id);
@@ -712,7 +713,8 @@ done: 
		if (WIFEXITED(status)) {

			/* Child ended normally */

			if (WEXITSTATUS(status) != 0) {

				fprintf(stderr, "Child Failed with status: %d.\n", (int8_t)(WEXITSTATUS(status)));

				AER_FPRINTF(stderr, "Child Failed with status: %d.\n",

					    (int8_t)(WEXITSTATUS(status)));

				g_failed = true;

			}

		}