From 7afcdb30596e471db980b86139a401ab6e7446e0 Mon Sep 17 00:00:00 2001 From: ShirkNeko <109797057+ShirkNeko@users.noreply.github.com> Date: Fri, 14 Nov 2025 12:29:55 +0800 Subject: [PATCH] kernel: Optimise sulog to prevent deadlocks caused by global lock contexts. --- kernel/sulog.c | 359 +++++++++++++++++-------------------------------- kernel/sulog.h | 35 +++-- 2 files changed, 153 insertions(+), 241 deletions(-) diff --git a/kernel/sulog.c b/kernel/sulog.c index 00104952..6442aeea 100644 --- a/kernel/sulog.c +++ b/kernel/sulog.c @@ -12,17 +12,16 @@ #include #include #include -#include #include "klog.h" #include "sulog.h" #include "ksu.h" #if __SULOG_GATE + struct dedup_entry dedup_tbl[SULOG_COMM_LEN]; -DEFINE_SPINLOCK(dedup_lock); +static DEFINE_SPINLOCK(dedup_lock); static LIST_HEAD(sulog_queue); -static DEFINE_MUTEX(sulog_mutex); static struct workqueue_struct *sulog_workqueue; static struct work_struct sulog_work; static bool sulog_enabled = true; @@ -33,65 +32,51 @@ static void get_timestamp(char *buf, size_t len) struct tm tm; ktime_get_real_ts64(&ts); - time64_to_tm(ts.tv_sec - sys_tz.tz_minuteswest * 60, 0, &tm); - snprintf(buf, len, - "%04ld-%02d-%02d %02d:%02d:%02d", - tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, - tm.tm_hour, tm.tm_min, tm.tm_sec); + snprintf(buf, len, "%04ld-%02d-%02d %02d:%02d:%02d", + tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, + tm.tm_hour, tm.tm_min, tm.tm_sec); } static void ksu_get_cmdline(char *full_comm, const char *comm, size_t buf_len) { - char *kbuf; - if (!full_comm || buf_len <= 0) return; if (comm && strlen(comm) > 0) { -#if LINUX_VERSION_CODE >= KERNEL_VERSION(4, 13, 0) - strscpy(full_comm, comm, buf_len); -#else - strlcpy(full_comm, comm, buf_len); -#endif - } else { - kbuf = kmalloc(buf_len, GFP_ATOMIC); - if (!kbuf) { - pr_err("sulog: failed to allocate memory for kbuf\n"); - return; - } - - int n = get_cmdline(current, kbuf, buf_len); - - if (n <= 0) { -#if LINUX_VERSION_CODE >= KERNEL_VERSION(4, 13, 0) - strscpy(full_comm, current->comm, buf_len); -#else - strlcpy(full_comm, current->comm, buf_len); -#endif - } else { - for (int i = 0; i < n; i++) { - if (kbuf[i] == '\0') kbuf[i] = ' '; - } - kbuf[n < buf_len ? n : buf_len - 1] = '\0'; -#if LINUX_VERSION_CODE >= KERNEL_VERSION(4, 13, 0) - strscpy(full_comm, kbuf, buf_len); -#else - strlcpy(full_comm, kbuf, buf_len); -#endif - } - - kfree(kbuf); + KSU_STRSCPY(full_comm, comm, buf_len); + return; } + + if (in_atomic() || in_interrupt() || irqs_disabled()) { + KSU_STRSCPY(full_comm, current->comm, buf_len); + return; + } + + if (!current->mm) { + KSU_STRSCPY(full_comm, current->comm, buf_len); + return; + } + + int n = get_cmdline(current, full_comm, buf_len); + if (n <= 0) { + KSU_STRSCPY(full_comm, current->comm, buf_len); + return; + } + + for (int i = 0; i < n && i < buf_len - 1; i++) { + if (full_comm[i] == '\0') + full_comm[i] = ' '; + } + full_comm[n < buf_len ? n : buf_len - 1] = '\0'; } -static bool dedup_should_print(uid_t uid, u8 type, - const char *content, size_t len) +static bool dedup_should_print(uid_t uid, u8 type, const char *content, size_t len) { struct dedup_key key = { - .crc = dedup_calc_hash(content, len), - .uid = uid, + .crc = dedup_calc_hash(content, len), + .uid = uid, .type = type, }; u64 now = ktime_get_ns(); @@ -121,37 +106,35 @@ static void sulog_work_handler(struct work_struct *work) struct sulog_entry *entry, *tmp; LIST_HEAD(local_queue); loff_t pos = 0; - - mutex_lock(&sulog_mutex); + unsigned long flags; + + spin_lock_irqsave(&dedup_lock, flags); list_splice_init(&sulog_queue, &local_queue); - mutex_unlock(&sulog_mutex); - + spin_unlock_irqrestore(&dedup_lock, flags); + if (list_empty(&local_queue)) return; - + fp = filp_open(SULOG_PATH, O_WRONLY | O_CREAT | O_APPEND, 0640); if (IS_ERR(fp)) { pr_err("sulog: failed to open log file: %ld\n", PTR_ERR(fp)); goto cleanup; } - + if (fp->f_inode->i_size > SULOG_MAX_SIZE) { - pr_info("sulog: log file exceeds maximum size, clearing...\n"); - if (vfs_truncate(&fp->f_path, 0)) { + if (vfs_truncate(&fp->f_path, 0)) pr_err("sulog: failed to truncate log file\n"); - } pos = 0; } else { pos = fp->f_inode->i_size; } - - list_for_each_entry(entry, &local_queue, list) { + + list_for_each_entry(entry, &local_queue, list) kernel_write(fp, entry->content, strlen(entry->content), &pos); - } - + vfs_fsync(fp, 0); filp_close(fp, 0); - + cleanup: list_for_each_entry_safe(entry, tmp, &local_queue, list) { list_del(&entry->list); @@ -159,215 +142,126 @@ cleanup: } } -static void sulog_add_entry(const char *content) +static void sulog_add_entry(char *log_buf, size_t len, uid_t uid, u8 dedup_type) { struct sulog_entry *entry; - - if (!sulog_enabled || !content) + unsigned long flags; + + if (!sulog_enabled || !log_buf || len == 0) return; - + + if (!dedup_should_print(uid, dedup_type, log_buf, len)) + return; + entry = kmalloc(sizeof(*entry), GFP_ATOMIC); - if (!entry) { - pr_err("sulog: failed to allocate memory for log entry\n"); + if (!entry) return; - } - -#if LINUX_VERSION_CODE >= KERNEL_VERSION(4, 13, 0) - strscpy(entry->content, content, SULOG_ENTRY_MAX_LEN - 1); -#else - strlcpy(entry->content, content, SULOG_ENTRY_MAX_LEN - 1); -#endif - - mutex_lock(&sulog_mutex); + + KSU_STRSCPY(entry->content, log_buf, SULOG_ENTRY_MAX_LEN); + + spin_lock_irqsave(&dedup_lock, flags); list_add_tail(&entry->list, &sulog_queue); - mutex_unlock(&sulog_mutex); - + spin_unlock_irqrestore(&dedup_lock, flags); + if (sulog_workqueue) queue_work(sulog_workqueue, &sulog_work); } void ksu_sulog_report_su_grant(uid_t uid, const char *comm, const char *method) { - char *timestamp, *full_comm, *log_buf; - + char log_buf[SULOG_ENTRY_MAX_LEN]; + char timestamp[32]; + char full_comm[SULOG_COMM_LEN]; + if (!sulog_enabled) return; - - timestamp = kmalloc(32, GFP_ATOMIC); - full_comm = kmalloc(SULOG_COMM_LEN, GFP_ATOMIC); - log_buf = kmalloc(SULOG_ENTRY_MAX_LEN, GFP_ATOMIC); - - if (!timestamp || !full_comm || !log_buf) { - pr_err("sulog: failed to allocate memory for su_grant log\n"); - goto cleanup; - } - - get_timestamp(timestamp, 32); - - ksu_get_cmdline(full_comm, comm, SULOG_COMM_LEN); - - snprintf(log_buf, SULOG_ENTRY_MAX_LEN, - "[%s] SU_GRANT: UID=%d COMM=%s METHOD=%s PID=%d\n", - timestamp, uid, full_comm, - method ? method : "unknown", current->pid); - if (!dedup_should_print(uid, DEDUP_SU_GRANT, log_buf, strlen(log_buf))) - goto cleanup; - - sulog_add_entry(log_buf); - -cleanup: - if (timestamp) kfree(timestamp); - if (full_comm) kfree(full_comm); - if (log_buf) kfree(log_buf); + get_timestamp(timestamp, sizeof(timestamp)); + ksu_get_cmdline(full_comm, comm, sizeof(full_comm)); + + snprintf(log_buf, sizeof(log_buf), + "[%s]SU_GRANT:UID=%d COMM=%s METHOD=%s PID=%d", + timestamp, uid, full_comm, method ? method : "unknown", current->pid); + + sulog_add_entry(log_buf, strlen(log_buf), uid, DEDUP_SU_GRANT); } void ksu_sulog_report_su_attempt(uid_t uid, const char *comm, const char *target_path, bool success) { - char *timestamp, *full_comm, *log_buf; - + char log_buf[SULOG_ENTRY_MAX_LEN]; + char timestamp[32]; + char full_comm[SULOG_COMM_LEN]; + if (!sulog_enabled) return; - - timestamp = kmalloc(32, GFP_ATOMIC); - full_comm = kmalloc(SULOG_COMM_LEN, GFP_ATOMIC); - log_buf = kmalloc(SULOG_ENTRY_MAX_LEN, GFP_ATOMIC); - - if (!timestamp || !full_comm || !log_buf) { - pr_err("sulog: failed to allocate memory for su_attempt log\n"); - goto cleanup; - } - - get_timestamp(timestamp, 32); - - ksu_get_cmdline(full_comm, comm, SULOG_COMM_LEN); - - snprintf(log_buf, SULOG_ENTRY_MAX_LEN, - "[%s] SU_EXEC: UID=%d COMM=%s TARGET=%s RESULT=%s PID=%d\n", - timestamp, uid, full_comm, - target_path ? target_path : "unknown", + + get_timestamp(timestamp, sizeof(timestamp)); + ksu_get_cmdline(full_comm, comm, sizeof(full_comm)); + + snprintf(log_buf, sizeof(log_buf), + "[%s]SU_EXEC:UID=%d COMM=%s TARGET=%s RESULT=%s PID=%d", + timestamp, uid, full_comm, target_path ? target_path : "unknown", success ? "SUCCESS" : "DENIED", current->pid); - if (!dedup_should_print(uid, DEDUP_SU_ATTEMPT, log_buf, strlen(log_buf))) - goto cleanup; - - sulog_add_entry(log_buf); - -cleanup: - if (timestamp) kfree(timestamp); - if (full_comm) kfree(full_comm); - if (log_buf) kfree(log_buf); + sulog_add_entry(log_buf, strlen(log_buf), uid, DEDUP_SU_ATTEMPT); } void ksu_sulog_report_permission_check(uid_t uid, const char *comm, bool allowed) { - char *timestamp, *full_comm, *log_buf; - + char log_buf[SULOG_ENTRY_MAX_LEN]; + char timestamp[32]; + char full_comm[SULOG_COMM_LEN]; + if (!sulog_enabled) return; - - timestamp = kmalloc(32, GFP_ATOMIC); - full_comm = kmalloc(SULOG_COMM_LEN, GFP_ATOMIC); - log_buf = kmalloc(SULOG_ENTRY_MAX_LEN, GFP_ATOMIC); - - if (!timestamp || !full_comm || !log_buf) { - pr_err("sulog: failed to allocate memory for permission_check log\n"); - goto cleanup; - } - - get_timestamp(timestamp, 32); - - ksu_get_cmdline(full_comm, comm, SULOG_COMM_LEN); - - snprintf(log_buf, SULOG_ENTRY_MAX_LEN, - "[%s] PERM_CHECK: UID=%d COMM=%s RESULT=%s PID=%d\n", - timestamp, uid, full_comm, - allowed ? "ALLOWED" : "DENIED", current->pid); - if (!dedup_should_print(uid, DEDUP_PERM_CHECK, log_buf, strlen(log_buf))) - goto cleanup; - - sulog_add_entry(log_buf); - -cleanup: - if (timestamp) kfree(timestamp); - if (full_comm) kfree(full_comm); - if (log_buf) kfree(log_buf); + get_timestamp(timestamp, sizeof(timestamp)); + ksu_get_cmdline(full_comm, comm, sizeof(full_comm)); + + snprintf(log_buf, sizeof(log_buf), + "[%s]PERM_CHECK:UID=%d COMM=%s RESULT=%s PID=%d", + timestamp, uid, full_comm, allowed ? "ALLOWED" : "DENIED", current->pid); + + sulog_add_entry(log_buf, strlen(log_buf), uid, DEDUP_PERM_CHECK); } void ksu_sulog_report_manager_operation(const char *operation, uid_t manager_uid, uid_t target_uid) { - char *timestamp, *full_comm, *log_buf; - + char log_buf[SULOG_ENTRY_MAX_LEN]; + char timestamp[32]; + char full_comm[SULOG_COMM_LEN]; + if (!sulog_enabled) return; - - timestamp = kmalloc(32, GFP_ATOMIC); - full_comm = kmalloc(SULOG_COMM_LEN, GFP_ATOMIC); - log_buf = kmalloc(SULOG_ENTRY_MAX_LEN, GFP_ATOMIC); - - if (!timestamp || !full_comm || !log_buf) { - pr_err("sulog: failed to allocate memory for manager_operation log\n"); - goto cleanup; - } - - get_timestamp(timestamp, 32); - ksu_get_cmdline(full_comm, NULL, SULOG_COMM_LEN); - - snprintf(log_buf, SULOG_ENTRY_MAX_LEN, - "[%s] MANAGER_OP: OP=%s MANAGER_UID=%d TARGET_UID=%d COMM=%s PID=%d\n", - timestamp, operation ? operation : "unknown", - manager_uid, target_uid, full_comm, current->pid); + get_timestamp(timestamp, sizeof(timestamp)); + ksu_get_cmdline(full_comm, NULL, sizeof(full_comm)); - if (!dedup_should_print(manager_uid, DEDUP_MANAGER_OP, log_buf, strlen(log_buf))) - goto cleanup; - - sulog_add_entry(log_buf); - -cleanup: - if (timestamp) kfree(timestamp); - if (full_comm) kfree(full_comm); - if (log_buf) kfree(log_buf); + snprintf(log_buf, sizeof(log_buf), + "[%s]MANAGER_OP:OP=%s MANAGER_UID=%d TARGET_UID=%d COMM=%s PID=%d", + timestamp, operation ? operation : "unknown", manager_uid, target_uid, full_comm, current->pid); + + sulog_add_entry(log_buf, strlen(log_buf), manager_uid, DEDUP_MANAGER_OP); } -void ksu_sulog_report_syscall(uid_t uid, const char *comm, - const char *syscall, const char *args) +void ksu_sulog_report_syscall(uid_t uid, const char *comm, const char *syscall, const char *args) { - char *timestamp, *full_comm, *log_buf; + char log_buf[SULOG_ENTRY_MAX_LEN]; + char timestamp[32]; + char full_comm[SULOG_COMM_LEN]; if (!sulog_enabled) return; - timestamp = kmalloc(32, GFP_ATOMIC); - full_comm = kmalloc(SULOG_COMM_LEN, GFP_ATOMIC); - log_buf = kmalloc(SULOG_ENTRY_MAX_LEN, GFP_ATOMIC); + get_timestamp(timestamp, sizeof(timestamp)); + ksu_get_cmdline(full_comm, comm, sizeof(full_comm)); - if (!timestamp || !full_comm || !log_buf) { - pr_err("sulog: failed to allocate memory for syscall log\n"); - goto cleanup; - } + snprintf(log_buf, sizeof(log_buf), + "[%s]SYSCALL:UID=%d COMM=%s SYSCALL=%s ARGS=%s PID=%d", + timestamp, uid, full_comm, syscall ? syscall : "unknown", + args ? args : "none", current->pid); - get_timestamp(timestamp, 32); - - ksu_get_cmdline(full_comm, comm, SULOG_COMM_LEN); - - snprintf(log_buf, SULOG_ENTRY_MAX_LEN, - "[%s] SYSCALL: UID=%d COMM=%s SYSCALL=%s ARGS=%s PID=%d\n", - timestamp, uid, full_comm, - syscall ? syscall : "unknown", - args ? args : "none", - current->pid); - - if (!dedup_should_print(uid, DEDUP_SYSCALL, log_buf, strlen(log_buf))) - goto cleanup; - - sulog_add_entry(log_buf); - -cleanup: - if (timestamp) kfree(timestamp); - if (full_comm) kfree(full_comm); - if (log_buf) kfree(log_buf); + sulog_add_entry(log_buf, strlen(log_buf), uid, DEDUP_SYSCALL); } int ksu_sulog_init(void) @@ -377,9 +271,8 @@ int ksu_sulog_init(void) pr_err("sulog: failed to create workqueue\n"); return -ENOMEM; } - + INIT_WORK(&sulog_work, sulog_work_handler); - pr_info("sulog: initialized successfully\n"); return 0; } @@ -387,22 +280,24 @@ int ksu_sulog_init(void) void ksu_sulog_exit(void) { struct sulog_entry *entry, *tmp; - + unsigned long flags; + sulog_enabled = false; - + if (sulog_workqueue) { flush_workqueue(sulog_workqueue); destroy_workqueue(sulog_workqueue); sulog_workqueue = NULL; } - - mutex_lock(&sulog_mutex); + + spin_lock_irqsave(&dedup_lock, flags); list_for_each_entry_safe(entry, tmp, &sulog_queue, list) { list_del(&entry->list); kfree(entry); } - mutex_unlock(&sulog_mutex); - + spin_unlock_irqrestore(&dedup_lock, flags); + pr_info("sulog: cleaned up successfully\n"); } -#endif // __SULOG_GATE \ No newline at end of file + +#endif // __SULOG_GATE diff --git a/kernel/sulog.h b/kernel/sulog.h index c6593f85..1569a8a4 100644 --- a/kernel/sulog.h +++ b/kernel/sulog.h @@ -8,13 +8,30 @@ #define __SULOG_GATE 1 #if __SULOG_GATE + extern struct timezone sys_tz; #define SULOG_PATH "/data/adb/ksu/log/sulog.log" #define SULOG_MAX_SIZE (128 * 1024 * 1024) // 128MB #define SULOG_ENTRY_MAX_LEN 512 #define SULOG_COMM_LEN 256 -#define DEDUP_SECS 10 +#define DEDUP_SECS 10 + +#if LINUX_VERSION_CODE >= KERNEL_VERSION(6, 10, 0) +static inline size_t strlcpy(char *dest, const char *src, size_t size) +{ + return strscpy(dest, src, size); +} +#endif + +#define KSU_STRSCPY(dst, src, size) \ + do { \ + if (LINUX_VERSION_CODE >= KERNEL_VERSION(4, 13, 0)) { \ + strscpy(dst, src, size); \ + } else { \ + strlcpy(dst, src, size); \ + } \ + } while (0) #if LINUX_VERSION_CODE < KERNEL_VERSION(4, 8, 0) #include @@ -24,25 +41,25 @@ static inline void time64_to_tm(time64_t totalsecs, int offset, struct tm *resul struct rtc_time rtc_tm; rtc_time64_to_tm(totalsecs, &rtc_tm); - result->tm_sec = rtc_tm.tm_sec; - result->tm_min = rtc_tm.tm_min; + result->tm_sec = rtc_tm.tm_sec; + result->tm_min = rtc_tm.tm_min; result->tm_hour = rtc_tm.tm_hour; result->tm_mday = rtc_tm.tm_mday; - result->tm_mon = rtc_tm.tm_mon; + result->tm_mon = rtc_tm.tm_mon; result->tm_year = rtc_tm.tm_year; } #endif struct dedup_key { - u32 crc; - uid_t uid; - u8 type; - u8 _pad[1]; + u32 crc; + uid_t uid; + u8 type; + u8 _pad[1]; }; struct dedup_entry { struct dedup_key key; - u64 ts_ns; + u64 ts_ns; }; enum {