dm: add dm log to kmsg for profiling

Collect the dm log to dmesg for profiing.
These mesage will be easy to profile when dm booting.

Tracked-On: #2336
Signed-off-by: Wei Liu <weix.w.liu@intel.com>
Reviewed-by: Yin Fengwei <fengwei.yin@intel.com>

devicemodel/Makefile

@@ -59,6 +59,7 @@ LIBS += -lacrn-mngr
 
 # lib
 SRCS += lib/dm_string.c
+SRCS += lib/dm_kmsg.c
 
 # hw
 SRCS += hw/block_if.c

devicemodel/core/main.c

@@ -292,7 +292,6 @@ add_cpu(struct vmctx *ctx, int guest_ncpus)
 
 	error = pthread_create(&mt_vmm_info[0].mt_thr, NULL,
 	    start_thread, &mt_vmm_info[0]);
-
 	return error;
 }
 
@@ -902,6 +901,7 @@ dm_run(int argc, char *argv[])
 	vmname = argv[0];
 
 	for (;;) {
+		write_kmsg("%s vm_create begin---\n", KMSG_FMT);
 		ctx = vm_create(vmname, (unsigned long)vhm_req_buf);
 		if (!ctx) {
 			perror("vm_open");
@@ -913,6 +913,7 @@ dm_run(int argc, char *argv[])
 				guest_ncpus);
 			goto fail;
 		}
+		write_kmsg("%s vm_create end---\n", KMSG_FMT);
 
 		max_vcpus = num_vcpus_allowed(ctx);
 		if (guest_ncpus > max_vcpus) {
@@ -920,12 +921,14 @@ dm_run(int argc, char *argv[])
 				guest_ncpus, max_vcpus);
 			goto fail;
 		}
+		write_kmsg("%s num_vpcpu_allowed end---\n", KMSG_FMT);
 
 		err = vm_setup_memory(ctx, memsize);
 		if (err) {
 			fprintf(stderr, "Unable to setup memory (%d)\n", errno);
 			goto fail;
 		}
+		write_kmsg("%s vm_setup_memory end---\n", KMSG_FMT);
 
 		err = mevent_init();
 		if (err) {
@@ -933,11 +936,13 @@ dm_run(int argc, char *argv[])
 				errno);
 			goto mevent_fail;
 		}
+		write_kmsg("%s mevent_init end---\n", KMSG_FMT);
 
 		if (vm_init_vdevs(ctx) < 0) {
 			fprintf(stderr, "Unable to init vdev (%d)\n", errno);
 			goto dev_fail;
 		}
+		write_kmsg("%s vm_init_vdevs end---\n", KMSG_FMT);
 
 		/*
 		 * build the guest tables, MP etc.
@@ -948,20 +953,25 @@ dm_run(int argc, char *argv[])
 				goto vm_fail;
 			}
 		}
+		write_kmsg("%s mptable_build end---\n", KMSG_FMT);
 
 		error = smbios_build(ctx);
 		if (error)
 			goto vm_fail;
 
+		write_kmsg("%s smbios_build end---\n", KMSG_FMT);
+
 		if (acpi) {
 			error = acpi_build(ctx, guest_ncpus);
 			if (error)
 				goto vm_fail;
 		}
+		write_kmsg("%s acpi_build end---\n", KMSG_FMT);
 
 		error = acrn_sw_load(ctx);
 		if (error)
 			goto vm_fail;
+		write_kmsg("%s acrn_sw_load end---\n", KMSG_FMT);
 
 		/*
 		 * Change the proc title to include the VM name.
@@ -971,10 +981,11 @@ dm_run(int argc, char *argv[])
 		/*
 		 * Add CPU 0
 		 */
+		write_kmsg("%s add_cpu begin---\n", KMSG_FMT);
 		error = add_cpu(ctx, guest_ncpus);
 		if (error)
 			goto vm_fail;
-
+		write_kmsg("%s add_cpu end---\n", KMSG_FMT);
 		/* Make a copy for ctx */
 		_ctx = ctx;
 

devicemodel/include/dm.h

@@ -33,6 +33,7 @@
 #include "types.h"
 #include "vmm.h"
 #include "dm_string.h"
+#include "dm_kmsg.h"
 
 struct vmctx;
 extern int guest_ncpus;

devicemodel/include/dm_kmsg.h

@@ -0,0 +1,17 @@
+/*
+ * Copyright (C) 2018 Intel Corporation. All rights reserved.
+ *
+ * SPDX-License-Identifier: BSD-3-Clause
+ *
+ */
+
+#ifndef _DM_KMSG_H_
+#define _DM_KMSG_H_
+
+#define DM_BUF    4096
+#define KERN_NODE "/dev/kmsg"
+#define KMSG_FMT  "dm_run:"
+
+void write_kmsg(const char *log, ...);
+
+#endif /* _DM_KMSG_H_ */

devicemodel/lib/dm_kmsg.c

@@ -0,0 +1,69 @@
+/*
+ * Copyright (C) 2018 Intel Corporation. All rights reserved.
+ *
+ * SPDX-License-Identifier: BSD-3-Clause
+ *
+ */
+
+#include <stdio.h>
+#include <string.h>
+#include <unistd.h>
+#include <fcntl.h>
+#include <stdarg.h>
+#include "dm_kmsg.h"
+
+int  fd_kmsg;
+char dm_buf[DM_BUF];
+
+static int open_kmsg(void);
+static int close_kmsg(void);
+
+static int open_kmsg(void)
+{
+	int fd;
+
+	/* open /dev/kmsg */
+	fd = open(KERN_NODE, O_RDWR | O_APPEND | O_NONBLOCK);
+	if (fd < 0) {
+		perror(KMSG_FMT"open_kmsg");
+		return fd;
+	}
+
+	fd_kmsg = fd;
+	return fd;
+}
+
+static int close_kmsg(void)
+{
+	int err;
+
+	/* close /dev/kmsg */
+	err = close(fd_kmsg);
+	if (err == -1) {
+		perror(KMSG_FMT"close_kmsg");
+		return err;
+	}
+
+	return 0;
+}
+
+void write_kmsg(const char *fmt, ...)
+{
+	int write_cnt;
+	va_list args;
+
+	va_start(args, fmt);
+	vsnprintf(dm_buf, DM_BUF, fmt, args);
+	va_end(args);
+
+	open_kmsg();
+
+	/* write the fmt to the /dev/kmsg */
+	write_cnt = write(fd_kmsg, dm_buf, strlen(dm_buf));
+	if (write_cnt < 0) {
+		perror(KMSG_FMT"write_kmsg");
+	}
+
+	close_kmsg();
+	return;
+}

devicemodel/samples/apl-mrb/launch_uos.sh

@@ -181,6 +181,7 @@ mac=$(cat /sys/class/net/e*/address)
 vm_name=vm$1
 mac_seed=${mac:9:8}-${vm_name}
 
+echo "dm_run: before tap preparing" > /dev/kmsg
 # create a unique tap device for each VM
 tap=tap_$6
 tap_exist=$(ip a | grep acrn_"$tap" | awk '{print $1}')
@@ -198,6 +199,7 @@ if [ "$br_exist"x != "x" -a "$tap_exist"x = "x" ]; then
   ip link set dev acrn_"$tap" down
   ip link set dev acrn_"$tap" up
 fi
+echo "dm_run: after tap preparing" > /dev/kmsg
 
 #Use MMC name + serial for ADB serial no., same as native android
 mmc_name=`cat /sys/block/mmcblk1/device/name`
@@ -212,6 +214,7 @@ if [[ "$result" != "" ]]; then
   exit
 fi
 
+echo "dm_run: before passthru dev preparing" > /dev/kmsg
 #for VT-d device setting
 modprobe pci_stub
 echo "8086 5aaa" > /sys/bus/pci/drivers/pci-stub/new_id
@@ -346,6 +349,7 @@ else
   boot_GVT_option=''
   GVT_args=''
 fi
+echo "dm_run: after passthru dev preparing" > /dev/kmsg
 
  acrn-dm -A -m $mem_size -c $2$boot_GVT_option"$GVT_args" -s 0:0,hostbridge -s 1:0,lpc -l com1,stdio $npk_virt\
    -s 9,virtio-net,$tap \
@@ -435,6 +439,7 @@ if [ $launch_type == 6 ]; then
 	fi
 fi
 
+echo "dm_run: before offline cpu" > /dev/kmsg
 # offline SOS CPUs except BSP before launch UOS
 for i in `ls -d /sys/devices/system/cpu/cpu[1-99]`; do
         online=`cat $i/online`
@@ -452,6 +457,7 @@ for i in `ls -d /sys/devices/system/cpu/cpu[1-99]`; do
                 echo $idx > /sys/class/vhm/acrn_vhm/offline_cpu
         fi
 done
+echo "dm_run: after offline cpu" > /dev/kmsg
 
 case $launch_type in
 	1) echo "Launch clearlinux UOS"