Add libcare-stresstest logging to files

-change some printfs to logging

Author: Roman Rashchupkin

src/kpatch_log.c

@@ -5,16 +5,28 @@
 #include <errno.h>
 
 #include "kpatch_log.h"
+#ifdef STRESS_TEST
+#include "kpatch_user.h"
+#endif
 
 int log_level = LOG_INFO;
 int log_indent;
+static FILE *log_file;
 
 static void __valog(int level, const char *prefix, const char *fmt, va_list va)
 {
 	FILE *f = level <= LOG_WARN ? stderr : stdout;
 	if (prefix)
 		fprintf(f, "%s", prefix);
 
+	if (log_file) {
+		va_list vaf;
+		va_copy(vaf, va);
+		if (prefix)
+			fprintf(log_file, "%s", prefix);
+		vfprintf(log_file, fmt, vaf);
+		fflush(log_file);
+	}
 	vfprintf(f, fmt, va);
 }
 
@@ -100,3 +112,20 @@ void _kpfatalerror(const char *file, int line, const char *fmt, ...)
 
 	exit(EXIT_FAILURE);
 }
+
+int log_file_init(char *fname)
+{
+	if (!fname)
+		return -1;
+	log_file = fopen(fname, "a");
+	if (!log_file)
+		return -1;
+	return 0;
+}
+
+void log_file_free()
+{
+	if (log_file)
+		fclose(log_file);
+	log_file = NULL;
+}

src/kpatch_log.h

@@ -33,4 +33,7 @@ void _kplogerror(const char *filename, int line, const char *fmt, ...)
 #define LOG_DEBUG	3
 #define LOG_TRACE	5
 
+int log_file_init(char *fname);
+void log_file_free();
+
 #endif

src/kpatch_patch.c

@@ -437,7 +437,7 @@ object_unapply_old_patch(struct object_file *o)
 		return 1;
 	}
 
-	printf("%s: replacing patch level %d with level %d\n",
+	kpinfo("%s: replacing patch level %d with level %d\n",
 	       o->name,
 	       kpatch_applied->user_level,
 	       kpatch_storage->user_level);
@@ -565,12 +565,12 @@ int process_patch(int pid, void *_data)
 
 out:
 	if (ret < 0) {
-		printf("Failed to apply patch '%s'\n", storage->path);
+		kpinfo("Failed to apply patch '%s'\n", storage->path);
 		kperr("Failed to apply patch '%s'\n", storage->path);
 	} else if (ret == 0)
-		printf("No patch(es) applicable to PID '%d' have been found\n", pid);
+		kpinfo("No patch(es) applicable to PID '%d' have been found\n", pid);
 	else {
-		printf("%d patch hunk(s) have been successfully applied to PID '%d'\n", ret, pid);
+		kpinfo("%d patch hunk(s) have been successfully applied to PID '%d'\n", ret, pid);
 		ret = 0;
 	}
 
@@ -750,11 +750,11 @@ int process_unpatch(int pid, void *_data)
 	kpatch_process_free(proc);
 
 	if (ret < 0)
-		printf("Failed to cancel patches for %d\n", pid);
+		kpinfo("Failed to cancel patches for %d\n", pid);
 	else if (ret == 0)
-		printf("No patch(es) cancellable from PID '%d' were found\n", pid);
+		kpinfo("No patch(es) cancellable from PID '%d' were found\n", pid);
 	else
-		printf("%d patch hunk(s) were successfully cancelled from PID '%d'\n", ret, pid);
+		kpinfo("%d patch hunk(s) were successfully cancelled from PID '%d'\n", ret, pid);
 
 	return ret;
 }

src/kpatch_process.c

@@ -746,9 +746,9 @@ process_print_cmdline(kpatch_process_t *proc)
 
 		for (i = 0; i < rv; i++) {
 			if (buf[i] != '\n' && isprint(buf[i]))
-				putchar(buf[i]);
+				kpinfo("%c", buf[i]);
 			else
-				printf("\\x%02x", (unsigned char)buf[i]);
+				kpinfo("\\x%02x", (unsigned char)buf[i]);
 		}
 	}
 
@@ -860,9 +860,9 @@ kpatch_process_kickstart_execve_wrapper(kpatch_process_t *proc)
 	if (ret < 0)
 		return -1;
 
-	printf("kpatch_ctl real cmdline=\"");
+	kpinfo("kpatch_ctl real cmdline=\"");
 	process_print_cmdline(proc);
-	printf("\"\n");
+	kpinfo("\"\n");
 
 	return 0;
 }
@@ -1137,11 +1137,11 @@ kpatch_process_init(kpatch_process_t *proc,
 void
 kpatch_process_print_short(kpatch_process_t *proc)
 {
-	printf("kpatch_ctl targeting pid %d\n", proc->pid);
+	kpinfo("kpatch_ctl targeting pid %d\n", proc->pid);
 	if (proc->send_fd == -1) {
-		printf("kpatch_ctl cmdline=\"");
+		kpinfo("kpatch_ctl cmdline=\"");
 		process_print_cmdline(proc);
-		printf("\"\n");
+		kpinfo("\"\n");
 	}
 }
 

src/kpatch_user.c

@@ -11,6 +11,7 @@
 #include <sys/socket.h>
 #include <sys/un.h>
 #include <sys/wait.h>
+#include <sys/types.h>
 
 #include <gelf.h>
 #include <libunwind.h>
@@ -566,7 +567,11 @@ cmd_update(int argc, char *argv[])
 
 #ifdef STRESS_TEST
 
-struct test_data {
+static int process_pid = -1;
+static char test_log_base[PATH_MAX-sizeof("-4194304")];
+static char test_log_name[PATH_MAX];
+
+static struct test_data {
 	int option_period;
 	int stat_cycle_num;
 } test_info = { .option_period = 0, .stat_cycle_num = 0 };
@@ -581,26 +586,20 @@ server_wait(int pid, int period)
 	for (i=0; i<period; i++) {
 		nanosleep(&req, &rem);
 		if (kill(pid, 0) != 0) {
-			fprintf(stderr, "Process %d terminated.\n", pid);
+			kpinfo("Process %d terminated.\n", pid);
 			return -1;
 		}
 	}
 	return 0;
 }
 
 static int
-server_stress_test(int fd, int argc, char *argv[])
+server_stress_test(int fd, int pid)
 {
-	int pid;
 	int delay;
 	test_info.stat_cycle_num = 0;
 	srand(time(NULL));
 
-	if (sscanf(argv[1], "%d", &pid) != 1) {
-		kperr("Can't parse pid from %s\n", argv[1]);
-		return -1;
-	}
-
 	while (1) {
 		while (patch_user(storage_dir, pid, 0, fd) < 0)
 			if (server_wait(pid, 1) < 0)
@@ -627,11 +626,44 @@ server_stress_test(int fd, int argc, char *argv[])
 	return 0;
 }
 
+static int stress_test_log_init(int is_base_process)
+{
+	if (!strlen(test_log_base))
+		return 0;
+	if (is_base_process) {
+		if (snprintf(test_log_name, PATH_MAX, "%s-base", test_log_base) >= PATH_MAX) {
+			kplogerror("Can't initialize log \'%s\'-<PID>\n", test_log_base);
+			return -1;
+		}
+	} else
+		if (snprintf(test_log_name, PATH_MAX, "%s-%d", test_log_base, getpid()) >= PATH_MAX) {
+			kplogerror("Can't initialize log \'%s\'-<PID>\n", test_log_base);
+			return -1;
+		}
+	if (log_file_init(test_log_name)) {
+		kplogerror("Can't open log file \'%s\'\n", test_log_name);
+		return -1;
+	}
+	return 0;
+}
+
 static int cmd_stress_test(int fd, int argc, char *argv[])
 {
+	if (sscanf(argv[1], "%d", &process_pid) != 1) {
+		kplogerror("Can't parse pid from %s\n", argv[1]);
+		return -1;
+	}
+	kpinfo("Spawning child to patch pid %d\n", process_pid);
+
 	int child = fork();
 	if (child == 0) {
-		int rv = server_stress_test(fd, argc, argv);
+		log_file_free();
+		if (stress_test_log_init(0))
+			kpfatal("Can't initialize log.\n");
+
+		int rv = server_stress_test(fd, process_pid);
+
+		log_file_free();
 		exit(rv);
 	}
 	close(fd);
@@ -640,7 +672,11 @@ static int cmd_stress_test(int fd, int argc, char *argv[])
 
 static int usage_stresstest()
 {
-	fprintf(stderr, "usage: libcare-stresstest PERIOD(ms, 0 - only patch) <UNIX socket> [STORAGE ROOT]\n");
+	fprintf(stderr, "usage: libcare-stresstest [args] PERIOD(ms, 0 - only patch) <UNIX socket> [STORAGE ROOT]\n");
+	fprintf(stderr, "\nOptions:\n");
+	fprintf(stderr, "  -v          - verbose mode\n");
+	fprintf(stderr, "  -l <BASE>   - log file name <BASE>-PID\n");
+	fprintf(stderr, "  -h          - this message\n");
 	return -1;
 }
 
@@ -828,9 +864,11 @@ cmd_server(int argc, char *argv[])
 	}
 
 #ifdef STRESS_TEST
-	if (sscanf(argv[0], "%d", &test_info.option_period) != 1) {
+	if (stress_test_log_init(1))
+		kpfatal("Can't initialize log.\n");
+	if (sscanf(argv[0], "%d", &test_info.option_period) != 1)
 		kplogerror("Can't parse period from %s\n", argv[0]);
-	}
+	kpinfo("Starting libcare-stresstest: period=%d\n", test_info.option_period);
 #endif
 
 	sfd = server_bind_socket(argv[1]);
@@ -954,13 +992,23 @@ int main(int argc, char *argv[])
 {
 	int opt;
 
-	while ((opt = getopt(argc, argv, "+vh")) != EOF) {
+	while ((opt = getopt(argc, argv, "+vl:h")) != EOF) {
 		switch (opt) {
 			case 'v':
 				log_level += 1;
 				break;
 			case 'h':
 				return usage(NULL);
+			case 'l':
+#ifdef STRESS_TEST
+				strncpy(test_log_base, optarg, sizeof(test_log_base));
+				if (test_log_base[sizeof(test_log_base)-1]) {
+					usage_stresstest();
+					kpfatal("Can't initialize log\n");
+					break;
+				}
+				break;
+#endif
 			default:
 				return usage("unknown option");
 		}