Introduce a single general purpose logcat monitor

jni/daemon/bootstages.c

@@ -28,10 +28,6 @@ static int seperate_vendor = 0;
 
 extern char **environ;
 
-#ifdef MAGISK_DEBUG
-static int debug_log_pid, debug_log_fd;
-#endif
-
 /******************
  * Node structure *
  ******************/
@@ -599,15 +595,8 @@ void post_fs_data(int client) {
 	if (!check_data())
 		goto unblock;
 
-	// Start log monitor
+	// Start the debug log
-	monitor_logs();
+	start_debug_full_log();
-
-#ifdef MAGISK_DEBUG
-	// Log everything initially
-	debug_log_fd = xopen(DEBUG_LOG, O_WRONLY | O_CREAT | O_CLOEXEC | O_TRUNC, 0644);
-	xwrite(debug_log_fd, "Boot logs:\n", 11);
-	debug_log_pid = exec_command(0, &debug_log_fd, NULL, "logcat", "-v", "thread", NULL);
-#endif
 
 	LOGI("** post-fs-data mode running\n");
 
@@ -804,12 +793,5 @@ core_only:
 	buf = buf2 = NULL;
 	vec_deep_destroy(&module_list);
 
-#ifdef MAGISK_DEBUG
+	stop_debug_full_log();
-	// Stop recording the boot logcat after every boot task is done
-	kill(debug_log_pid, SIGTERM);
-	waitpid(debug_log_pid, NULL, 0);
-	// Then start to log Magisk verbosely
-	xwrite(debug_log_fd, "\nVerbose logs:\n", 15);
-	debug_log_pid = exec_command(0, &debug_log_fd, NULL, "logcat", "-v", "thread", "-s", "Magisk", NULL);
-#endif
 }

jni/daemon/daemon.c

@@ -123,6 +123,9 @@ void start_daemon() {
 	xdup2(fd, STDERR_FILENO);
 	close(fd);
 
+	// Start the log monitor
+	monitor_logs();
+
 	// Patch selinux with medium patch before we do anything
 	load_policydb(SELINUX_POLICY);
 	sepol_med_rules();

jni/daemon/log_monitor.c

@@ -1,8 +1,8 @@
 /* log_monitor.c - New thread to monitor logcat
  *
- * Open a new thread to call logcat and get logs with tag "Magisk"
+ * A universal logcat monitor for many usages. Add listeners to the list,
- * Also, write the logs to a log file for debugging purpose
+ * and the pointer of the new log line will be sent through pipes to trigger
- *
+ * asynchronous events without polling
  */
 
 #include <stdio.h>
@@ -13,33 +13,150 @@
 
 #include "magisk.h"
 #include "utils.h"
-#include "daemon.h"
+
+int logcat_events[] = { -1, -1, -1 };
+
+static int is_restart = 0;
+
+#ifdef MAGISK_DEBUG
+static int debug_log_pid, debug_log_fd;
+#endif
 
 static void *logger_thread(void *args) {
 	// Setup error handler
 	err_handler = exit_thread;
 
-	rename(LOGFILE, LASTLOG);
+	int log_fd = -1, log_pid;
-	int log_fd, log_pid;
+	char line[4096];
-
-	log_fd = xopen(LOGFILE, O_WRONLY | O_CREAT | O_CLOEXEC | O_TRUNC, 0644);
 
 	while (1) {
+		// Clear buffer
+		exec_command_sync("logcat", "-b", "all", "-c", NULL);
 		// Start logcat
-		log_pid = exec_command(0, &log_fd, NULL, "logcat", "-v", "thread", "Magisk:I", "*:S", NULL);
+		log_pid = exec_command(0, &log_fd, NULL, "logcat", "-b", "events", "-b", "default", "-s", "am_proc_start", "Magisk", NULL);
-		if (log_pid > 0)
+		while (fdgets(line, sizeof(line), log_fd)) {
-			waitpid(log_pid, NULL, 0);
+			for (int i = 0; i < (sizeof(logcat_events) / sizeof(int)); ++i) {
-		// For some reason it went here, clear buffer and restart
+				if (logcat_events[i] > 0) {
-		exec_command_sync("logcat", "-c", NULL);
+					char *s = strdup(line);
+					xwrite(logcat_events[i], &s, sizeof(s));
+				}
+			}
+			if (kill(log_pid, 0))
+				break;
+		}
 	}
 
 	// Should never be here, but well...
 	return NULL;
 }
 
-/* Start a new thread to monitor logcat and dump to logfile */
+static void *magisk_log_thread(void *args) {
+	// Setup error handler
+	err_handler = exit_thread;
+
+	int have_data = 0;
+
+	// Temp buffer for logs before we have data access
+	struct vector logs;
+	vec_init(&logs);
+
+	FILE *log;
+	int pipefd[2];
+	if (xpipe2(pipefd, O_CLOEXEC) == -1)
+		return NULL;
+
+	// Register our listener
+	logcat_events[LOG_EVENT] = pipefd[1];
+
+	for (char *line; xxread(pipefd[0], &line, sizeof(line)) > 0; free(line)) {
+		char *ss;
+		if ((ss = strstr(line, " Magisk")) && (ss[-1] != 'D') && (ss[-1] != 'V')) {
+			if (!have_data) {
+				if ((have_data = check_data())) {
+					// Dump buffered logs to file
+					if (!is_restart)
+						rename(LOGFILE, LASTLOG);
+					log = xfopen(LOGFILE, "a");
+					setbuf(log, NULL);
+					char *tmp;
+					vec_for_each(&logs, tmp) {
+						fprintf(log, "%s", tmp);
+						free(tmp);
+					}
+					vec_destroy(&logs);
+				} else {
+					vec_push_back(&logs, line);
+				}
+			}
+			if (have_data)
+				fprintf(log, "%s", line);
+		}
+	}
+	return NULL;
+}
+
+static void *debug_magisk_log_thread(void *args) {
+	// Setup error handler
+	err_handler = exit_thread;
+
+	FILE *log = xfopen(DEBUG_LOG, "a");
+	setbuf(log, NULL);
+	int pipefd[2];
+	if (xpipe2(pipefd, O_CLOEXEC) == -1)
+		return NULL;
+
+	// Register our listener
+	logcat_events[DEBUG_EVENT] = pipefd[1];
+
+	for (char *line; xxread(pipefd[0], &line, sizeof(line)) > 0; free(line)) {
+		char *ss;
+		if ((ss = strstr(line, "Magisk")))
+			fprintf(log, "%s", line);
+	}
+	return NULL;
+}
+
+/* Start new threads to monitor logcat and dump to logfile */
 void monitor_logs() {
 	pthread_t thread;
-	xpthread_create(&thread, NULL, logger_thread, NULL);
+
+	is_restart = check_data();
+
+	// Start log file dumper before monitor
+	xpthread_create(&thread, NULL, magisk_log_thread, NULL);
+	pthread_detach(thread);
+
+#ifdef MAGISK_DEBUG
+	if (is_restart) {
+		// Restart debug logs
+		xpthread_create(&thread, NULL, debug_magisk_log_thread, NULL);
 		pthread_detach(thread);
 	}
+#endif
+
+	// Start logcat monitor
+	xpthread_create(&thread, NULL, logger_thread, NULL);
+	pthread_detach(thread);
+
+}
+
+void start_debug_full_log() {
+#ifdef MAGISK_DEBUG
+	// Log everything initially
+	debug_log_fd = xopen(DEBUG_LOG, O_WRONLY | O_CREAT | O_CLOEXEC | O_TRUNC, 0644);
+	debug_log_pid = exec_command(0, &debug_log_fd, NULL, "logcat", NULL);
+	close(debug_log_fd);
+#endif
+}
+
+void stop_debug_full_log() {
+#ifdef MAGISK_DEBUG
+	// Stop recording the boot logcat after every boot task is done
+	kill(debug_log_pid, SIGTERM);
+	waitpid(debug_log_pid, NULL, 0);
+	pthread_t thread;
+	// Start debug thread
+	xpthread_create(&thread, NULL, debug_magisk_log_thread, NULL);
+	pthread_detach(thread);
+#endif
+}

jni/include/daemon.h

@@ -50,10 +50,6 @@ void write_int(int fd, int val);
 char* read_string(int fd);
 void write_string(int fd, const char* val);
 
-// log_monitor.c
-
-void monitor_logs();
-
 /***************
  * Boot Stages *
  ***************/

jni/include/logging.h

@@ -34,6 +34,17 @@ static inline void do_nothing() {}
 
 #define PLOGE(fmt, args...) { LOGE(fmt " failed with %d: %s", ##args, errno, strerror(errno)); err_handler(); }
 
+enum {
+	HIDE_EVENT,
+	LOG_EVENT,
+	DEBUG_EVENT
+};
+extern int logcat_events[];
+
+void monitor_logs();
+void start_debug_full_log();
+void stop_debug_full_log();
+
 #else // IS_DAEMON
 
 #include <stdio.h>

jni/include/utils.h

@@ -90,6 +90,7 @@ void fclone_attr(const int sourcefd, const int targetfd);
 void clone_attr(const char *source, const char *target);
 void get_client_cred(int fd, struct ucred *cred);
 int switch_mnt_ns(int pid);
+int fork_dont_care();
 
 // img.c
 

jni/magiskhide/proc_monitor.c

@@ -19,27 +19,20 @@
 #include "utils.h"
 #include "magiskhide.h"
 
-static int zygote_num;
 static char init_ns[32], zygote_ns[2][32], cache_block[256];
-static int log_pid, log_fd, target_pid, has_cache = 1;
+static int zygote_num, has_cache = 1, pipefd[2] = { -1, -1 };
-static char *buffer;
 
 // Workaround for the lack of pthread_cancel
 static void quit_pthread(int sig) {
 	err_handler = do_nothing;
 	LOGD("proc_monitor: running cleanup\n");
 	destroy_list();
-	free(buffer);
 	hideEnabled = 0;
-	// Kill the logging if needed
+	// Unregister listener
-	if (log_pid > 0) {
+	logcat_events[HIDE_EVENT] = -1;
-		kill(log_pid, SIGTERM);
+	close(pipefd[0]);
-		waitpid(log_pid, NULL, 0);
+	close(pipefd[1]);
-		close(log_fd);
+	pipefd[0] = pipefd[1] = -1;
-	}
-	// Resume process if possible
-	if (target_pid > 0)
-		kill(target_pid, SIGCONT);
 	pthread_mutex_destroy(&hide_lock);
 	pthread_mutex_destroy(&file_lock);
 	LOGD("proc_monitor: terminating...\n");
@@ -47,7 +40,7 @@ static void quit_pthread(int sig) {
 }
 
 static void proc_monitor_err() {
-	LOGD("proc_monitor: error occured, stopping magiskhide services\n");
+	LOGE("proc_monitor: error occured, stopping magiskhide services\n");
 	quit_pthread(SIGUSR1);
 }
 
@@ -77,25 +70,24 @@ static void lazy_unmount(const char* mountpoint) {
 }
 
 static void hide_daemon_err() {
-	LOGD("hide_daemon: error occured, stopping magiskhide services\n");
+	LOGE("hide_daemon: error occured\n");
-	_exit(-1);
 }
 
 static void hide_daemon(int pid) {
 	LOGD("hide_daemon: start unmount for pid=[%d]\n", pid);
-	// When an error occurs, report its failure to main process
+	// When an error occurs, report its failure
 	err_handler = hide_daemon_err;
 
-	char *line;
+	char *line, buffer[PATH_MAX];
 	struct vector mount_list;
 
 	manage_selinux();
 	clean_magisk_props();
 
 	if (switch_mnt_ns(pid))
-		return;
+		goto exit;
 
-	snprintf(buffer, PATH_MAX, "/proc/%d/mounts", pid);
+	snprintf(buffer, sizeof(buffer), "/proc/%d/mounts", pid);
 	vec_init(&mount_list);
 	file_to_vector(buffer, &mount_list);
 
@@ -132,7 +124,7 @@ static void hide_daemon(int pid) {
 	vec_destroy(&mount_list);
 
 	// Re-read mount infos
-	snprintf(buffer, PATH_MAX, "/proc/%d/mounts", pid);
+	snprintf(buffer, sizeof(buffer), "/proc/%d/mounts", pid);
 	vec_init(&mount_list);
 	file_to_vector(buffer, &mount_list);
 
@@ -145,8 +137,12 @@ static void hide_daemon(int pid) {
 		free(line);
 	}
 
-	// Free uo memory
+exit:
+	// Send resume signal
+	kill(pid, SIGCONT);
+	// Free up memory
 	vec_destroy(&mount_list);
+	_exit(0);
 }
 
 void proc_monitor() {
@@ -158,9 +154,7 @@ void proc_monitor() {
 
 	// The error handler should stop magiskhide services
 	err_handler = proc_monitor_err;
-	log_pid = target_pid = -1;
 
-	buffer = xmalloc(PATH_MAX);
 	cache_block[0] = '\0';
 
 	// Get the mount namespace of init
@@ -188,20 +182,15 @@ void proc_monitor() {
 		break;
 	}
 
-	while (1) {
+	// Register our listener to logcat monitor
-		// Clear previous logcat buffer
+	xpipe2(pipefd, O_CLOEXEC);
-		exec_command_sync("logcat", "-b", "events", "-c", NULL);
+	logcat_events[HIDE_EVENT] = pipefd[1];
 
-		// Monitor am_proc_start
+	for (char *log, *line; xxread(pipefd[0], &log, sizeof(log)) > 0; free(log)) {
-		log_fd = -1;
+		char *ss;
-		log_pid = exec_command(0, &log_fd, NULL, "logcat", "-b", "events", "-v", "raw", "-s", "am_proc_start", NULL);
+		if ((ss = strstr(log, "am_proc_start")) && (ss = strchr(ss, '['))) {
-
-		if (log_pid < 0) continue;
-		if (kill(log_pid, 0)) continue;
-
-		while(fdgets(buffer, PATH_MAX, log_fd)) {
 			int pid, ret, comma = 0;
-			char *pos = buffer, *line, processName[256];
+			char *pos = ss, processName[256], ns[32];
 
 			while(1) {
 				pos = strchr(pos, ',');
@@ -212,9 +201,9 @@ void proc_monitor() {
 			}
 
 			if (comma == 6)
-				ret = sscanf(buffer, "[%*d %d %*d %*d %256s", &pid, processName);
+				ret = sscanf(ss, "[%*d %d %*d %*d %256s", &pid, processName);
 			else
-				ret = sscanf(buffer, "[%*d %d %*d %256s", &pid, processName);
+				ret = sscanf(ss, "[%*d %d %*d %256s", &pid, processName);
 
 			if(ret != 2)
 				continue;
@@ -225,12 +214,11 @@ void proc_monitor() {
 			pthread_mutex_lock(&hide_lock);
 			vec_for_each(hide_list, line) {
 				if (strcmp(processName, line) == 0) {
-					target_pid = pid;
 					while(1) {
 						ret = 1;
 						for (int i = 0; i < zygote_num; ++i) {
-							read_namespace(target_pid, buffer, 32);
+							read_namespace(pid, ns, sizeof(ns));
-							if (strcmp(buffer, zygote_ns[i]) == 0) {
+							if (strcmp(ns, zygote_ns[i]) == 0) {
 								usleep(50);
 								ret = 0;
 								break;
@@ -240,43 +228,21 @@ void proc_monitor() {
 					}
 
 					// Send pause signal ASAP
-					if (kill(target_pid, SIGSTOP) == -1) continue;
+					if (kill(pid, SIGSTOP) == -1) continue;
 
-					LOGI("proc_monitor: %s (PID=%d ns=%s)\n", processName, target_pid, buffer);
+					LOGI("proc_monitor: %s (PID=%d ns=%s)\n", processName, pid, ns);
 
 					/*
 					 * The setns system call do not support multithread processes
 					 * We have to fork a new process, setns, then do the unmounts
 					 */
-					int hide_pid = fork();
+					if (fork_dont_care() == 0)
-					switch(hide_pid) {
+						hide_daemon(pid);
-					case -1:
-						PLOGE("fork");
-						return;
-					case 0:
-						hide_daemon(target_pid);
-						_exit(0);
-					default:
-						break;
-					}
 
-					// Wait till the unmount process is done
-					waitpid(hide_pid, &ret, 0);
-					if (WEXITSTATUS(ret))
-						quit_pthread(SIGUSR1);
-
-					// All done, send resume signal
-					kill(target_pid, SIGCONT);
-					target_pid = -1;
 					break;
 				}
 			}
 			pthread_mutex_unlock(&hide_lock);
 		}
-
-		// For some reason it went here, restart logging
-		kill(log_pid, SIGTERM);
-		waitpid(log_pid, NULL, 0);
-		close(log_fd);
 	}
 }

jni/utils/misc.c

@@ -408,3 +408,14 @@ int switch_mnt_ns(int pid) {
 	close(fd);
 	return ret;
 }
+
+int fork_dont_care() {
+	int pid = fork();
+	if (pid) {
+		waitpid(pid, NULL, 0);
+		return pid;
+	} else if ((pid = fork())) {
+		exit(0);
+	}
+	return 0;
+}