[core] Module log using lspd logcat (#980)

core/src/main/aidl/org/lsposed/lspd/service/ILSPApplicationService.aidl

@@ -13,7 +13,5 @@ interface ILSPApplicationService {
 
     String getPrefsPath(String packageName);
 
-    ParcelFileDescriptor getModuleLogger();
-
     Bundle requestRemotePreference(String packageName, int userId, IBinder callback);
 }

core/src/main/cpp/daemon/logcat.cpp

@@ -3,8 +3,7 @@
 #include <string>
 #include <android/log.h>
 #include <array>
-#include <inttypes.h>
+#include <cinttypes>
-
 #include "logcat.h"
 
 constexpr size_t kMaxLogSize = 32 * 1024 * 1024;
@@ -33,30 +32,41 @@ public:
 
 class Logcat {
 public:
-    explicit Logcat(JNIEnv *env, jobject thiz, jmethodID method, jlong tid) :
+    explicit Logcat(JNIEnv *env, jobject thiz, jmethodID method, jlong tid, jint fd,
-            env_(env), thiz_(thiz), refresh_fd_method_(method), tid_(tid) {};
+                    jboolean verbose) :
+            env_(env), thiz_(thiz), refresh_fd_method_(method), tid_(tid), module_file_(fd, "w"),
+            verbose_(verbose),
+            stop_verbose_inst_("!!stop_verbose!!" + std::to_string(tid_)),
+            start_verbose_inst_("!!start_verbose!!" + std::to_string(tid_)) {}
 
-    void Run();
+    [[noreturn]] void Run();
 
 private:
     inline void RefreshFd();
 
-    bool ProcessBuffer(struct log_msg *buf);
+    void ProcessBuffer(struct log_msg *buf);
 
-    void PrintLogLine(const AndroidLogEntry &entry);
+    static int PrintLogLine(const AndroidLogEntry &entry, FILE *out);
 
     JNIEnv *env_;
     jobject thiz_;
     jmethodID refresh_fd_method_;
     jlong tid_;
+    UniqueFile module_file_{};
+    size_t module_count_ = 0;
 
     UniqueFile out_file_{};
     size_t print_count_ = 0;
     size_t file_count_ = 1;
+
+    bool verbose_ = true;
+
+    const std::string stop_verbose_inst_;
+    const std::string start_verbose_inst_;
 };
 
-void Logcat::PrintLogLine(const AndroidLogEntry &entry) {
+int Logcat::PrintLogLine(const AndroidLogEntry &entry, FILE *out) {
-    if (!out_file_) return;
+    if (!out) return 0;
     constexpr static size_t kMaxTimeBuff = 64;
     struct tm tm{};
     std::array<char, kMaxTimeBuff> time_buff;
@@ -73,13 +83,12 @@ void Logcat::PrintLogLine(const AndroidLogEntry &entry) {
     }
     localtime_r(&now, &tm);
     strftime(time_buff.data(), time_buff.size(), "%Y-%m-%dT%H:%M:%S", &tm);
-    print_count_ +=
+    return fprintf(out, "[ %s.%03ld %8d:%6d:%6d %c/%-15.*s ] %.*s\n",
-            fprintf(out_file_.get(), "[ %s.%03ld %8d:%6d:%6d %c/%-15.*s ] %.*s\n",
+                   time_buff.data(),
-                    time_buff.data(),
+                   nsec / MS_PER_NSEC,
-                    nsec / MS_PER_NSEC,
+                   entry.uid, entry.pid, entry.tid,
-                    entry.uid, entry.pid, entry.tid,
+                   kLogChar[entry.priority], static_cast<int>(entry.tagLen),
-                    kLogChar[entry.priority], static_cast<int>(entry.tagLen),
+                   entry.tag, static_cast<int>(message_len), message);
-                    entry.tag, static_cast<int>(message_len), message);
 }
 
 void Logcat::RefreshFd() {
@@ -89,21 +98,26 @@ void Logcat::RefreshFd() {
     file_count_++;
 }
 
-bool Logcat::ProcessBuffer(struct log_msg *buf) {
+void Logcat::ProcessBuffer(struct log_msg *buf) {
     AndroidLogEntry entry;
-    if (android_log_processLogBuffer(&buf->entry, &entry) < 0) return false;
+    if (android_log_processLogBuffer(&buf->entry, &entry) < 0) return;
 
     std::string_view tag(entry.tag);
-    if (buf->id() == log_id::LOG_ID_CRASH ||
+    bool skip = false;
-        tag == "Magisk" ||
+    if (tag == "LSPosed-Bridge" || tag == "XSharedPreferences") [[unlikely]] {
-        tag.starts_with("Riru") ||
+        module_count_ += PrintLogLine(entry, module_file_.get());
-        tag.starts_with("LSPosed") ||
+        skip = true;
-        tag == "XSharedPreferences") {
+    }
-        PrintLogLine(entry);
+    if (verbose_ && (skip || buf->id() == log_id::LOG_ID_CRASH ||
+                     tag == "Magisk" ||
+                     tag.starts_with("Riru") ||
+                     tag.starts_with("LSPosed"))) [[unlikely]] {
+        print_count_ += PrintLogLine(entry, out_file_.get());
+    }
+    if (entry.pid == getpid() && tag == "LSPosedLogcat") [[unlikely]] {
+        if (std::string_view(entry.message) == stop_verbose_inst_) verbose_ = false;
+        if (std::string_view(entry.message) == start_verbose_inst_) verbose_ = true;
     }
-    return entry.pid == getpid() &&
-           tag == "LSPosedLogcat" &&
-           std::string_view(entry.message) == "!!stop!!" + std::to_string(tid_);
 }
 
 void Logcat::Run() {
@@ -128,13 +142,19 @@ void Logcat::Run() {
         while (true) {
             if (android_logger_list_read(logger_list.get(), &msg) <= 0) [[unlikely]] break;
 
-            if (ProcessBuffer(&msg)) [[unlikely]] return;
+            ProcessBuffer(&msg);
 
             fflush(out_file_.get());
+            fflush(module_file_.get());
 
             if (print_count_ >= kMaxLogSize) [[unlikely]] RefreshFd();
+            if (module_count_ >= kMaxLogSize) [[unlikely]] {
+                ftruncate(fileno(module_file_.get()), 0);
+                module_count_ = 0;
+            }
         }
-        fprintf(out_file_.get(), "\nLogd maybe crashed, retrying in %" PRId64 "-%zu file after 1s\n",
+        fprintf(out_file_.get(),
+                "\nLogd maybe crashed, retrying in %" PRId64 "-%zu file after 1s\n",
                 tid_, file_count_ + 1);
         sleep(1);
     }
@@ -143,9 +163,10 @@ void Logcat::Run() {
 extern "C"
 JNIEXPORT void JNICALL
 // NOLINTNEXTLINE
-Java_org_lsposed_lspd_service_LogcatService_runLogcat(JNIEnv *env, jobject thiz, jlong tid) {
+Java_org_lsposed_lspd_service_LogcatService_runLogcat(JNIEnv *env, jobject thiz, jlong tid,
+                                                      jint fd, jboolean verbose) {
     jclass clazz = env->GetObjectClass(thiz);
     jmethodID method = env->GetMethodID(clazz, "refreshFd", "()I");
-    Logcat logcat(env, thiz, method, tid);
+    Logcat logcat(env, thiz, method, tid, fd, verbose);
     logcat.Run();
 }

core/src/main/java/de/robv/android/xposed/XposedBridge.java

@@ -28,7 +28,6 @@ import android.util.Log;
 
 import org.lsposed.lspd.BuildConfig;
 import org.lsposed.lspd.nativebridge.ResourcesHook;
-import org.lsposed.lspd.util.ModuleLogger;
 import org.lsposed.lspd.yahfa.hooker.YahfaHooker;
 
 import java.lang.reflect.AccessibleObject;
@@ -133,7 +132,6 @@ public final class XposedBridge {
      */
     public synchronized static void log(String text) {
         Log.i(TAG, text);
-        ModuleLogger.log(text, false);
     }
 
     /**
@@ -147,7 +145,6 @@ public final class XposedBridge {
     public synchronized static void log(Throwable t) {
         String logStr = Log.getStackTraceString(t);
         Log.e(TAG, logStr);
-        ModuleLogger.log(logStr, true);
     }
 
     /**

core/src/main/java/org/lsposed/lspd/config/ApplicationServiceClient.java

@@ -28,7 +28,4 @@ abstract public class ApplicationServiceClient implements ILSPApplicationService
 
     @Override
     abstract public String getPrefsPath(String packageName);
-
-    @Override
-    abstract public ParcelFileDescriptor getModuleLogger();
 }

core/src/main/java/org/lsposed/lspd/config/LSPApplicationServiceClient.java

@@ -109,15 +109,6 @@ public class LSPApplicationServiceClient extends ApplicationServiceClient {
         return null;
     }
 
-    @Override
-    public ParcelFileDescriptor getModuleLogger() {
-        try {
-            return service.getModuleLogger();
-        } catch (RemoteException | NullPointerException ignored) {
-        }
-        return null;
-    }
-
     @Override
     public Bundle requestRemotePreference(String packageName, int userId, IBinder callback) throws RemoteException {
         return null;

core/src/main/java/org/lsposed/lspd/core/Main.java

@@ -37,7 +37,6 @@ import org.lsposed.lspd.hooker.HandleBindAppHooker;
 import org.lsposed.lspd.hooker.LoadedApkCstrHooker;
 import org.lsposed.lspd.hooker.SystemMainHooker;
 import org.lsposed.lspd.service.ServiceManager;
-import org.lsposed.lspd.util.ModuleLogger;
 import org.lsposed.lspd.util.Utils;
 import org.lsposed.lspd.yahfa.hooker.YahfaHooker;
 
@@ -79,7 +78,6 @@ public class Main {
     public static void forkPostCommon(boolean isSystem, String appDataDir, String niceName) {
         // init logger
         YahfaHooker.init();
-        ModuleLogger.initLogger(serviceClient.getModuleLogger());
         XposedBridge.initXResources();
         XposedInit.startsSystemServer = isSystem;
         PrebuiltMethodsDeopter.deoptBootMethods(); // do it once for secondary zygote

core/src/main/java/org/lsposed/lspd/service/ConfigManager.java

@@ -23,6 +23,7 @@ import static org.lsposed.lspd.service.PackageService.MATCH_ALL_FLAGS;
 import static org.lsposed.lspd.service.PackageService.PER_USER_RANGE;
 import static org.lsposed.lspd.service.ServiceManager.TAG;
 import static org.lsposed.lspd.service.ServiceManager.existsInGlobalNamespace;
+import static org.lsposed.lspd.service.ServiceManager.getLogcatService;
 import static org.lsposed.lspd.service.ServiceManager.toGlobalNamespace;
 
 import android.content.ContentValues;
@@ -106,8 +107,6 @@ public class ConfigManager {
     private String miscPath = null;
 
     private static final File logPath = new File(basePath, "log");
-    private static final File modulesLog = new File(logPath, "modules.txt");
-    private static final File oldModulesLog = new File(logPath, "modules.old.txt");
 
     static class FileLocker {
         private final FileChannel lockChannel;
@@ -890,12 +889,9 @@ public class ConfigManager {
     }
 
     public ParcelFileDescriptor getModulesLog(int mode) {
+        var modulesLog = getLogcatService().getModulesLog();
         try {
-            if (modulesLog.length() > 16 * 1024 * 1024) {
+            return ParcelFileDescriptor.open(modulesLog, mode);
-                //noinspection ResultOfMethodCallIgnored
-                modulesLog.renameTo(oldModulesLog);
-            }
-            return ParcelFileDescriptor.open(modulesLog, mode | ParcelFileDescriptor.MODE_CREATE);
         } catch (IOException e) {
             Log.e(TAG, Log.getStackTraceString(e));
             return null;
@@ -916,8 +912,9 @@ public class ConfigManager {
     public boolean clearLogs(boolean verbose) {
         try {
             var logcat = ServiceManager.getLogcatService().getLog();
+            var moduleLog = ServiceManager.getLogcatService().getModulesLog();
             if (verbose && logcat == null) return true;
-            OutputStream os = new FileOutputStream(verbose ? logcat : modulesLog);
+            OutputStream os = new FileOutputStream(verbose ? logcat : moduleLog);
             os.close();
             return true;
         } catch (IOException e) {

core/src/main/java/org/lsposed/lspd/service/LSPApplicationService.java

@@ -88,12 +88,6 @@ public class LSPApplicationService extends ILSPApplicationService.Stub {
         return ConfigManager.getInstance().getPrefsPath(packageName, getCallingUid());
     }
 
-    @Override
-    public ParcelFileDescriptor getModuleLogger() throws RemoteException {
-        ensureRegistered();
-        return ConfigManager.getInstance().getModulesLog(ParcelFileDescriptor.MODE_WRITE_ONLY | ParcelFileDescriptor.MODE_APPEND);
-    }
-
     @Override
     public Bundle requestRemotePreference(String packageName, int userId, IBinder callback) throws RemoteException {
         ensureRegistered();

core/src/main/java/org/lsposed/lspd/service/LogcatService.java

@@ -4,6 +4,7 @@ import android.annotation.SuppressLint;
 import android.os.ParcelFileDescriptor;
 import android.util.Log;
 
+import androidx.annotation.NonNull;
 import androidx.annotation.Nullable;
 
 import org.lsposed.lspd.util.Utils;
@@ -15,34 +16,43 @@ import java.time.format.DateTimeFormatter;
 
 public class LogcatService implements Runnable {
     private static final String TAG = "LSPosedLogcat";
+    private static final int mode = ParcelFileDescriptor.MODE_WRITE_ONLY | ParcelFileDescriptor.MODE_CREATE |
+            ParcelFileDescriptor.MODE_TRUNCATE | ParcelFileDescriptor.MODE_APPEND;
+    public final File modulesLog;
     private final File logPath;
     private final DateTimeFormatter logTimeFormat;
     private File log = null;
     private Thread thread = null;
+    boolean verboseLog = true;
 
     @SuppressLint("UnsafeDynamicallyLoadedCode")
     public LogcatService(File logPath) {
         String libraryPath = System.getProperty("lsp.library.path");
         System.load(libraryPath + "/" + System.mapLibraryName("daemon"));
         this.logPath = logPath;
+        modulesLog = new File(logPath, "module.log");
         logTimeFormat = DateTimeFormatter.ISO_LOCAL_DATE_TIME.withZone(Utils.getZoneId());
     }
 
     @Override
     public void run() {
         Log.i(TAG, "start running");
-        runLogcat(thread.getId());
+        int moduleFd = -1;
+        try (var fd = ParcelFileDescriptor.open(modulesLog, mode)) {
+            moduleFd = fd.detachFd();
+        } catch (IOException e) {
+            Log.w(TAG, "someone chattr +i ?", e);
+        }
+        runLogcat(thread.getId(), moduleFd, verboseLog);
         Log.i(TAG, "stoped");
     }
 
-    private native void runLogcat(long tid);
+    private native void runLogcat(long tid, int fd, boolean verboseLog);
 
     @SuppressWarnings("unused")
     private int refreshFd() {
         log = new File(logPath, logTimeFormat.format(Instant.now()) + ".log");
 
-        var mode = ParcelFileDescriptor.MODE_WRITE_ONLY | ParcelFileDescriptor.MODE_CREATE |
-                ParcelFileDescriptor.MODE_TRUNCATE | ParcelFileDescriptor.MODE_APPEND;
         try (var fd = ParcelFileDescriptor.open(log, mode)) {
             return fd.detachFd();
         } catch (IOException e) {
@@ -52,19 +62,21 @@ public class LogcatService implements Runnable {
     }
 
     public void start() {
+        if (thread != null) Log.i(TAG, "!!start_verbose!!" + thread.getId());
         if (isRunning()) return;
         thread = new Thread(this);
         thread.setName("logcat");
         thread.setUncaughtExceptionHandler((t, e) -> {
             Log.e(TAG, "Crash unexpectedly: ", e);
             thread = null;
+            start();
         });
         thread.start();
     }
 
     public void stop() {
         // logcat thread is listening for this keyword
-        Log.i(TAG, "!!stop!!" + thread.getId());
+        Log.i(TAG, "!!stop_verbose!!" + thread.getId());
     }
 
     public boolean isRunning() {
@@ -75,4 +87,9 @@ public class LogcatService implements Runnable {
     public File getLog() {
         return log;
     }
+
+    @NonNull
+    public File getModulesLog() {
+        return modulesLog;
+    }
 }

core/src/main/java/org/lsposed/lspd/util/ModuleLogger.java

@@ -1,68 +0,0 @@
-/*
- * This file is part of LSPosed.
- *
- * LSPosed is free software: you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation, either version 3 of the License, or
- * (at your option) any later version.
- *
- * LSPosed is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License
- * along with LSPosed.  If not, see <https://www.gnu.org/licenses/>.
- *
- * Copyright (C) 2020 EdXposed Contributors
- * Copyright (C) 2021 LSPosed Contributors
- */
-
-package org.lsposed.lspd.util;
-
-import android.app.ActivityThread;
-import android.os.ParcelFileDescriptor;
-import android.os.Process;
-
-import java.io.FileWriter;
-import java.io.IOException;
-import java.time.Instant;
-import java.time.format.DateTimeFormatter;
-import java.util.Locale;
-
-public class ModuleLogger {
-    private static DateTimeFormatter logDateFormat;
-    private static ParcelFileDescriptor fd = null;
-
-    public static void initLogger(ParcelFileDescriptor fileDescriptor) {
-        if (fd == null && fileDescriptor != null) {
-            fd = fileDescriptor;
-            var zone = Utils.getZoneId();
-            var pattern = "uuuu-MM-dd'T'HH:mm:ss.SSS"; // DateTimeFormatter.ISO_LOCAL_DATE_TIME
-            logDateFormat = DateTimeFormatter.ofPattern(pattern, Locale.ROOT).withZone(zone);
-        }
-    }
-
-    public static void log(String str, boolean isThrowable) {
-        if (fd == null) {
-            Utils.logE("Logger is not initialized");
-            return;
-        }
-        String processName = ActivityThread.currentProcessName();
-        var log = String.format(Locale.ROOT, "[ %s %5d:%5d:%5d %c/%s ] %s\n",
-                logDateFormat.format(Instant.now()),
-                Process.myUid(),
-                Process.myPid(),
-                Process.myTid(),
-                isThrowable ? 'E' : 'I',
-                processName == null ? "android" : processName,
-                str);
-        try {
-            var writer = new FileWriter(fd.getFileDescriptor());
-            writer.write(log, 0, log.length());
-            writer.flush();
-        } catch (IOException e) {
-            Utils.logE("Unable to write to module log file", e);
-        }
-    }
-}