From 5746614ccf213105099d5a0affd5b2a54bd7ea8f Mon Sep 17 00:00:00 2001 From: topjohnwu Date: Sun, 10 Feb 2019 03:16:52 -0500 Subject: [PATCH] Keep track of timestamps and skip old logs --- native/jni/core/logcat.cpp | 67 ++++++++++++++++++------ native/jni/utils/include/BlockingQueue.h | 54 ++++++++++++------- 2 files changed, 86 insertions(+), 35 deletions(-) diff --git a/native/jni/core/logcat.cpp b/native/jni/core/logcat.cpp index 1df90a10c..04160ada1 100644 --- a/native/jni/core/logcat.cpp +++ b/native/jni/core/logcat.cpp @@ -1,6 +1,7 @@ #include #include #include +#include #include #include @@ -8,14 +9,16 @@ #include #include -static std::vector log_cmd, clear_cmd; +static std::vector log_cmd; static pthread_mutex_t event_lock = PTHREAD_MUTEX_INITIALIZER; +static time_t LAST_TIMESTAMP = 0; + bool logcat_started = false; struct log_listener { bool enable = false; - BlockingQueue queue; bool (*filter)(const char *); + BlockingQueue queue; }; static struct log_listener events[] = { @@ -31,30 +34,39 @@ static void init_args() { // Construct cmdline log_cmd.push_back(MIRRDIR "/system/bin/logcat"); // Test whether these buffers actually works - const char *b[] = { "main", "events", "crash" }; - for (auto &buffer : b) { - if (exec_command_sync(MIRRDIR "/system/bin/logcat", "-b", buffer, "-d", "-f", "/dev/null") == 0) { + const char *buffers[] = { "main", "events", "crash" }; + for (auto b : buffers) { + if (exec_command_sync(MIRRDIR "/system/bin/logcat", "-b", b, "-d", "-f", "/dev/null") == 0) { log_cmd.push_back("-b"); - log_cmd.push_back(buffer); + log_cmd.push_back(b); } } chmod("/dev/null", 0666); - clear_cmd = log_cmd; log_cmd.insert(log_cmd.end(), { "-v", "threadtime", "-s", "am_proc_start", "Magisk" }); #ifdef MAGISK_DEBUG log_cmd.push_back("*:F"); #endif log_cmd.push_back(nullptr); +} - clear_cmd.push_back("-c"); - clear_cmd.push_back(nullptr); +static bool test_logcat() { + int test = exec_command_sync(MIRRDIR "/system/bin/logcat", "-d", "-f", "/dev/null"); + chmod("/dev/null", 0666); + return test == 0; } static void *logcat_gobbler(void *) { int log_pid; char line[4096]; + struct tm tm{}; + time_t prev; + + // Set tm year info + time_t now = time(nullptr); + localtime_r(&now, &tm); + while (true) { - // Start logcat + prev = 0; exec_t exec { .fd = -1, .argv = log_cmd.data() @@ -64,6 +76,22 @@ static void *logcat_gobbler(void *) { while (fgets(line, sizeof(line), logs)) { if (line[0] == '-') continue; + // Parse timestamp + strptime(line, "%m-%d %H:%M:%S", &tm); + now = mktime(&tm); + if (now < prev) { + /* Log timestamps should be monotonic increasing, if this happens, + * it means that we occur the super rare case: crossing year boundary + * (e.g 2019 -> 2020). Reset and reparse timestamp */ + now = time(nullptr); + localtime_r(&now, &tm); + strptime(line, "%m-%d %H:%M:%S", &tm); + now = mktime(&tm); + } + // Skip old logs + if (now < LAST_TIMESTAMP) + continue; + LAST_TIMESTAMP = prev = now; pthread_mutex_lock(&event_lock); for (auto &event : events) { if (event.enable && event.filter(line)) @@ -76,9 +104,17 @@ static void *logcat_gobbler(void *) { kill(log_pid, SIGTERM); waitpid(log_pid, nullptr, 0); - LOGI("magisklogd: logcat output EOF"); - // Clear buffer - exec_command_sync(clear_cmd.data()); + LOGI("logcat: unexpected output EOF"); + + // Wait a few seconds and retry + sleep(2); + if (!test_logcat()) { + // Cancel all events and terminate + logcat_started = false; + for (auto &event : events) + event.queue.cancel(); + return nullptr; + } } } @@ -109,9 +145,7 @@ void stop_logging(logcat_event event) { bool start_logcat() { if (logcat_started) return true; - int test = exec_command_sync(MIRRDIR "/system/bin/logcat", "-d", "-f", "/dev/null"); - chmod("/dev/null", 0666); - if (test != 0) + if (!test_logcat()) return false; init_args(); pthread_t t; @@ -122,4 +156,3 @@ bool start_logcat() { logcat_started = true; return true; } - diff --git a/native/jni/utils/include/BlockingQueue.h b/native/jni/utils/include/BlockingQueue.h index 38ba0ad0c..b12a67073 100644 --- a/native/jni/utils/include/BlockingQueue.h +++ b/native/jni/utils/include/BlockingQueue.h @@ -6,10 +6,10 @@ template class BlockingQueue { std::deque deque{}; - pthread_mutex_t lock; - pthread_cond_t cond; + pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER; + pthread_cond_t cond = PTHREAD_COND_INITIALIZER; + bool cancelled = false; public: - BlockingQueue() : lock(PTHREAD_MUTEX_INITIALIZER), cond(PTHREAD_COND_INITIALIZER) {} ~BlockingQueue(); T take(); T &front(); @@ -19,8 +19,15 @@ public: template< class... Args > void emplace_back(Args&&... args); void clear(); + void cancel(); }; +#define run_and_notify(block) \ +pthread_mutex_lock(&this->lock); \ +block \ +pthread_cond_signal(&this->cond); \ +pthread_mutex_unlock(&this->lock); + template BlockingQueue::~BlockingQueue() { pthread_mutex_destroy(&lock); @@ -30,8 +37,11 @@ BlockingQueue::~BlockingQueue() { template T BlockingQueue::take() { pthread_mutex_lock(&lock); - while (deque.empty()) + cancelled = false; + while (deque.empty() && !cancelled) pthread_cond_wait(&cond, &lock); + if (cancelled) + pthread_exit(nullptr); T ret(std::move(deque.front())); deque.pop_front(); pthread_mutex_unlock(&lock); @@ -40,41 +50,49 @@ T BlockingQueue::take() { template void BlockingQueue::put(const T &s) { - pthread_mutex_lock(&lock); - deque.push_back(s); - pthread_cond_signal(&cond); - pthread_mutex_unlock(&lock); + run_and_notify({ deque.push_back(s); }) } template void BlockingQueue::put(T &&s) { - pthread_mutex_lock(&lock); - deque.push_back(std::move(s)); - pthread_cond_signal(&cond); - pthread_mutex_unlock(&lock); + run_and_notify({ deque.push_back(std::move(s)); }) } template T &BlockingQueue::front() { - return deque.front(); + pthread_mutex_lock(&lock); + auto &ret = deque.front(); + pthread_mutex_unlock(&lock); + return ret; } template T &BlockingQueue::back() { - return deque.back(); + pthread_mutex_lock(&lock); + auto &ret = deque.back(); + pthread_mutex_unlock(&lock); + return ret; } template template void BlockingQueue::emplace_back(Args &&... args) { - pthread_mutex_lock(&lock); - deque.emplace_back(std::forward(args)...); - pthread_cond_signal(&cond); - pthread_mutex_unlock(&lock); + run_and_notify({ deque.emplace_back(std::forward(args)...); }) } template void BlockingQueue::clear() { + pthread_mutex_lock(&lock); std::deque t; deque.swap(t); + pthread_mutex_unlock(&lock); +} + +template +void BlockingQueue::cancel() { + run_and_notify({ + cancelled = true; + std::deque t; + deque.swap(t); + }) }