DM: use log macro/func to output log info

also add logs for some key entries.

Tracked-On: #3012
Signed-off-by: Minggui Cao <minggui.cao@intel.com>
Acked-by: Yin Fengwei <fengwei.yin@intel.com>

devicemodel/core/main.c

@@ -947,51 +947,52 @@ dm_run(int argc, char *argv[])
 		usage(1);
 
 	if (!check_hugetlb_support()) {
-		fprintf(stderr, "check_hugetlb_support failed\n");
+		pr_err("check_hugetlb_support failed\n");
 		exit(1);
 	}
 
 	vmname = argv[0];
 	if (strnlen(vmname, MAX_VM_OS_NAME_LEN) >= MAX_VM_OS_NAME_LEN) {
-		fprintf(stderr, "vmname size exceed %u\n",MAX_VM_OS_NAME_LEN);
+		pr_err("vmname size exceed %u\n", MAX_VM_OS_NAME_LEN);
 		exit(1);
 	}
 
 	for (;;) {
+		pr_notice("vm_create: %s\n", vmname);
 		ctx = vm_create(vmname, (unsigned long)vhm_req_buf);
 		if (!ctx) {
-			perror("vm_open");
+			pr_err("vm_create failed");
 			exit(1);
 		}
 
 		if (guest_ncpus < 1) {
-			fprintf(stderr, "Invalid guest vCPUs (%d)\n",
+			pr_err("Invalid guest vCPUs (%d)\n", guest_ncpus);
-				guest_ncpus);
 			goto fail;
 		}
 
 		max_vcpus = num_vcpus_allowed(ctx);
 		if (guest_ncpus > max_vcpus) {
-			fprintf(stderr, "%d vCPUs requested but %d available\n",
+			pr_err("%d vCPUs requested but %d available\n",
 				guest_ncpus, max_vcpus);
 			goto fail;
 		}
 
+		pr_notice("vm_setup_memory: size=0x%lx\n", memsize);
 		err = vm_setup_memory(ctx, memsize);
 		if (err) {
-			fprintf(stderr, "Unable to setup memory (%d)\n", errno);
+			pr_err("Unable to setup memory (%d)\n", errno);
 			goto fail;
 		}
 
 		err = mevent_init();
 		if (err) {
-			fprintf(stderr, "Unable to initialize mevent (%d)\n",
+			pr_err("Unable to initialize mevent (%d)\n", errno);
-				errno);
 			goto mevent_fail;
 		}
 
+		pr_notice("vm_init_vdevs\n");
 		if (vm_init_vdevs(ctx) < 0) {
-			fprintf(stderr, "Unable to init vdev (%d)\n", errno);
+			pr_err("Unable to init vdev (%d)\n", errno);
 			goto dev_fail;
 		}
 
@@ -1007,13 +1008,18 @@ dm_run(int argc, char *argv[])
 
 		if (acpi) {
 			error = acpi_build(ctx, guest_ncpus);
-			if (error)
+			if (error) {
+				pr_err("acpi_build failed, error=%d\n", error);
 				goto vm_fail;
 			}
+		}
 
+		pr_notice("acrn_sw_load\n");
 		error = acrn_sw_load(ctx);
-		if (error)
+		if (error) {
+			pr_err("acrn_sw_load failed, error=%d\n", error);
 			goto vm_fail;
+		}
 
 		/*
 		 * Change the proc title to include the VM name.
@@ -1023,9 +1029,12 @@ dm_run(int argc, char *argv[])
 		/*
 		 * Add CPU 0
 		 */
+		pr_notice("add_cpu\n");
 		error = add_cpu(ctx, guest_ncpus);
-		if (error)
+		if (error) {
+			pr_err("add_cpu failed, error=%d\n", error);
 			goto vm_fail;
+		}
 
 		/* Make a copy for ctx */
 		_ctx = ctx;

devicemodel/core/monitor.c

@@ -23,6 +23,7 @@
 #include "acrn_mngr.h"
 #include "pm.h"
 #include "vmmapi.h"
+#include "log.h"
 
 #define INTR_STORM_MONITOR_PERIOD	10 /* 10 seconds */
 #define INTR_STORM_THRESHOLD	100000 /* 10K times per second */
@@ -117,7 +118,7 @@ static void *intr_storm_monitor_thread(void *arg)
 		memset(hdr->buffer, 0, sizeof(uint64_t) * hdr->buf_cnt);
 		ret = vm_intr_monitor(ctx, hdr);
 		if (ret) {
-			DPRINTF("next get intr data failed, ret: %d\n", ret);
+			pr_err("next get intr data failed, ret: %d\n", ret);
 			intr_storm_monitor_pid = 0;
 			break;
 		}
@@ -147,7 +148,7 @@ static void *intr_storm_monitor_thread(void *arg)
 
 		/* storm detected, handle the intr abnormal status */
 		if (i < hdr->buf_cnt) {
-			DPRINTF("irq=%ld, delta=%ld\n", intr_cnt_buf[i], delta);
+			pr_notice("irq=%ld, delta=%ld\n", intr_cnt_buf[i], delta);
 
 			hdr->cmd = INTR_CMD_DELAY_INT;
 			hdr->buffer[0] = intr_monitor_setting.delay_time;
@@ -172,12 +173,12 @@ static void start_intr_storm_monitor(struct vmctx *ctx)
 	if (intr_monitor_setting.enable) {
 		int ret = pthread_create(&intr_storm_monitor_pid, NULL, intr_storm_monitor_thread, ctx);
 		if (ret) {
-			printf("failed %s %d\n", __func__, __LINE__);
+			pr_err("failed %s %d\n", __func__, __LINE__);
 			intr_storm_monitor_pid = 0;
 		}
 		pthread_setname_np(intr_storm_monitor_pid, "storm_monitor");
 
-		printf("start monitor interrupt data...\n");
+		pr_info("start monitor interrupt data...\n");
 	}
 }
 
@@ -210,9 +211,9 @@ int acrn_parse_intr_monitor(const char *opt)
 		(!dm_strtoui(cp + 1, &cp, 10, &period) && *cp == ',') &&
 		(!dm_strtoui(cp + 1, &cp, 10, &delay) && *cp == ',') &&
 		(!dm_strtoui(cp + 1, &cp, 10, &duration))) {
-		printf("interrupt storm monitor params: %d, %d, %d, %d\n", threshold, period, delay, duration);
+		pr_info("interrupt storm monitor params: %d, %d, %d, %d\n", threshold, period, delay, duration);
 	} else {
-		printf("%s: not correct, it should be like: --intr_monitor 10000,10,1,100, please check!\n", opt);
+		pr_err("%s: not correct, it should be like: --intr_monitor 10000,10,1,100, please check!\n", opt);
 		return -1;
 	}
 
@@ -263,7 +264,7 @@ int set_wakeup_timer(time_t t)
 	ret = mngr_send_msg(acrnd_fd, &req, &ack, 2);
 	mngr_close(acrnd_fd);
 	if (ret != sizeof(ack)) {
-		fprintf(stderr, "%s %d\r\n", __FUNCTION__, __LINE__);
+		pr_err("%s %d\r\n", __func__, __LINE__);
 		return -1;
 	}
 
@@ -279,13 +280,13 @@ int monitor_register_vm_ops(struct monitor_vm_ops *mops, void *arg,
 	struct vm_ops *ops;
 
 	if (!mops) {
-		fprintf(stderr, "%s %d\r\n", __FUNCTION__, __LINE__);
+		pr_err("%s %d\r\n", __func__, __LINE__);
 		return -1;
 	}
 
 	ops = calloc(1, sizeof(*ops));
 	if (!ops) {
-		perror("Alloc ops");
+		pr_err("Alloc ops");
 		return -1;
 	}
 
@@ -329,7 +330,7 @@ static void name(struct mngr_msg *msg, int client_fd, void *param)	\
 								\
 	if (!count) {						\
 		ack.data.err = -1;					\
-		fprintf(stderr, "No handler for id:%u\r\n", msg->msgid);	\
+		pr_err("No handler for id:%u\r\n", msg->msgid);	\
 	} else									\
 		ack.data.err = ret;							\
 										\
@@ -363,7 +364,7 @@ static void handle_resume(struct mngr_msg *msg, int client_fd, void *param)
 
 	if (!count) {
 		ack.data.err = -1;
-		fprintf(stderr, "No handler for id:%u\r\n", msg->msgid);
+		pr_err("No handler for id:%u\r\n", msg->msgid);
 	} else
 		ack.data.err = ret;
 
@@ -406,13 +407,13 @@ int monitor_init(struct vmctx *ctx)
 
 	ret = check_dir(ACRN_DM_BASE_PATH, CHK_CREAT);
 	if (ret) {
-		fprintf(stderr, "%s %d\r\n", __FUNCTION__, __LINE__);
+		pr_err("%s %d\r\n", __func__, __LINE__);
 		goto dir_err;
 	}
 
 	ret = check_dir(ACRN_DM_SOCK_PATH, CHK_CREAT);
 	if (ret) {
-		fprintf(stderr, "%s %d\r\n", __FUNCTION__, __LINE__);
+		pr_err("%s %d\r\n", __func__, __LINE__);
 		goto dir_err;
 	}
 
@@ -420,7 +421,7 @@ int monitor_init(struct vmctx *ctx)
 
 	monitor_fd = mngr_open_un(path, MNGR_SERVER);
 	if (monitor_fd < 0) {
-		fprintf(stderr, "%s %d\r\n", __FUNCTION__, __LINE__);
+		pr_err("%s %d\r\n", __func__, __LINE__);
 		goto server_err;
 	}
 
@@ -433,7 +434,7 @@ int monitor_init(struct vmctx *ctx)
 	ret += mngr_add_handler(monitor_fd, DM_QUERY, handle_query, NULL);
 
 	if (ret) {
-		fprintf(stderr, "%s %d\r\n", __FUNCTION__, __LINE__);
+		pr_err("%s %d\r\n", __func__, __LINE__);
 		goto handlers_err;
 	}
 

devicemodel/core/vmmapi.c

@@ -46,6 +46,7 @@
 
 #include "dm.h"
 #include "pci_core.h"
+#include "log.h"
 
 #define MAP_NOCORE 0
 #define MAP_ALIGNED_SUPER 0
@@ -68,17 +69,17 @@ check_api(int fd)
 
 	error = ioctl(fd, IC_GET_API_VERSION, &api_version);
 	if (error) {
-		fprintf(stderr, "failed to get vhm api version\n");
+		pr_err("failed to get vhm api version\n");
 		return -1;
 	}
 
 	if (api_version.major_version != SUPPORT_VHM_API_VERSION_MAJOR ||
 		api_version.minor_version != SUPPORT_VHM_API_VERSION_MINOR) {
-		fprintf(stderr, "not support vhm api version\n");
+		pr_err("not support vhm api version\n");
 		return -1;
 	}
 
-	printf("VHM api version %d.%d\n", api_version.major_version,
+	pr_info("VHM api version %d.%d\n", api_version.major_version,
 			api_version.minor_version);
 
 	return 0;
@@ -108,7 +109,7 @@ vm_create(const char *name, uint64_t req_buf)
 		devfd = -1;
 	}
 	if (devfd == -1) {
-		fprintf(stderr, "Could not open /dev/acrn_vhm\n");
+		pr_err("Could not open /dev/acrn_vhm\n");
 		goto err;
 	}
 
@@ -164,7 +165,7 @@ vm_create(const char *name, uint64_t req_buf)
 	}
 
 	if (error) {
-		fprintf(stderr, "failed to create VM %s\n", ctx->name);
+		pr_err("failed to create VM %s\n", ctx->name);
 		goto err;
 	}
 
@@ -197,7 +198,7 @@ vm_attach_ioreq_client(struct vmctx *ctx)
 	error = ioctl(ctx->fd, IC_ATTACH_IOREQ_CLIENT, ctx->ioreq_client);
 
 	if (error) {
-		fprintf(stderr, "attach ioreq client return %d "
+		pr_err("attach ioreq client return %d "
 			"(1 = destroying, could be triggered by Power State "
 				"change, others = error)\n", error);
 		return error;
@@ -219,7 +220,7 @@ vm_notify_request_done(struct vmctx *ctx, int vcpu)
 	error = ioctl(ctx->fd, IC_NOTIFY_REQUEST_FINISH, &notify);
 
 	if (error) {
-		fprintf(stderr, "failed: notify request finish\n");
+		pr_err("failed: notify request finish\n");
 		return -1;
 	}
 
@@ -422,6 +423,7 @@ static int suspend_mode = VM_SUSPEND_NONE;
 void
 vm_set_suspend_mode(enum vm_suspend_how how)
 {
+	pr_notice("vm mode changed from %d to:%d", suspend_mode, how);
 	suspend_mode = how;
 }
 

devicemodel/hw/pci/core.c

@@ -45,6 +45,7 @@
 #include "irq.h"
 #include "lpc.h"
 #include "sw_load.h"
+#include "log.h"
 
 #define CONF1_ADDR_PORT    0x0cf8
 #define CONF1_DATA_PORT    0x0cfc
@@ -1231,10 +1232,14 @@ init_pci(struct vmctx *ctx)
 					continue;
 				ops = pci_emul_finddev(fi->fi_name);
 				assert(ops != NULL);
+
+				pr_notice("pci init %s\r\n", fi->fi_name);
 				error = pci_emul_init(ctx, ops, bus, slot,
 				    func, fi);
-				if (error)
+				if (error) {
+					pr_err("pci %s init failed\n", fi->fi_name);
 					goto pci_emul_init_fail;
+				}
 				success_cnt++;
 			}
 		}
@@ -1406,6 +1411,8 @@ deinit_pci(struct vmctx *ctx)
 					continue;
 				ops = pci_emul_finddev(fi->fi_name);
 				assert(ops != NULL);
+
+				pr_notice("pci deinit %s\n", fi->fi_name);
 				pci_emul_deinit(ctx, ops, bus, slot,
 				    func, fi);
 			}