diff --git a/liblog/README.md b/liblog/README.md index f64f37624..74a2cd746 100644 --- a/liblog/README.md +++ b/liblog/README.md @@ -60,8 +60,6 @@ Public Functions and Macros LOG_EVENT_INT(tag, value) LOG_EVENT_LONG(tag, value) - clockid_t android_log_clockid() - log_id_t android_logger_get_id(struct logger *logger) int android_logger_clear(struct logger *logger) int android_logger_get_log_size(struct logger *logger) @@ -119,7 +117,7 @@ finally a call closing the logs. A single log can be opened with `android_logge multiple logs can be opened with `android_logger_list_alloc()`, calling in turn the `android_logger_open()` for each log id. Each entry can be retrieved with `android_logger_list_read()`. The log(s) can be closed with `android_logger_list_free()`. -`ANDROID_LOG_NONBLOCK` mode will report when the log reading is done with an `EAGAIN` error return +`ANDROID_LOG_NONBLOCK` mode will report when the log reading is done with an `EAGAIN` error return code, otherwise the `android_logger_list_read()` call will block for new entries. The `ANDROID_LOG_WRAP` mode flag to the `android_logger_list_alloc_time()` signals logd to quiesce diff --git a/liblog/include/log/log.h b/liblog/include/log/log.h index 820b7cb83..d7e9b7dab 100644 --- a/liblog/include/log/log.h +++ b/liblog/include/log/log.h @@ -133,12 +133,6 @@ typedef enum { (void)__android_log_bswrite(_tag, _value); #endif -#ifdef __linux__ - -clockid_t android_log_clockid(void); - -#endif /* __linux__ */ - /* --------------------------------------------------------------------- */ /* diff --git a/liblog/logger_write.cpp b/liblog/logger_write.cpp index 3a75fa3e9..22c7ecaff 100644 --- a/liblog/logger_write.cpp +++ b/liblog/logger_write.cpp @@ -192,7 +192,7 @@ static int write_to_log(log_id_t log_id, struct iovec* vec, size_t nr) { return -EINVAL; } - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); if (log_id == LOG_ID_SECURITY) { if (vec[0].iov_len < 4) { diff --git a/liblog/logprint.cpp b/liblog/logprint.cpp index 9e8d277e0..238431f91 100644 --- a/liblog/logprint.cpp +++ b/liblog/logprint.cpp @@ -216,11 +216,7 @@ AndroidLogFormat* android_log_format_new() { p_ret->year_output = false; p_ret->zone_output = false; p_ret->epoch_output = false; -#ifdef __ANDROID__ - p_ret->monotonic_output = android_log_clockid() == CLOCK_MONOTONIC; -#else p_ret->monotonic_output = false; -#endif p_ret->uid_output = false; p_ret->descriptive_output = false; descriptive_output = false; @@ -1465,13 +1461,10 @@ char* android_log_formatLogLine(AndroidLogFormat* p_format, char* defaultBuffer, nsec = entry->tv_nsec; #if __ANDROID__ if (p_format->monotonic_output) { - /* prevent convertMonotonic from being called if logd is monotonic */ - if (android_log_clockid() != CLOCK_MONOTONIC) { - struct timespec time; - convertMonotonic(&time, entry); - now = time.tv_sec; - nsec = time.tv_nsec; - } + struct timespec time; + convertMonotonic(&time, entry); + now = time.tv_sec; + nsec = time.tv_nsec; } #endif if (now < 0) { diff --git a/liblog/pmsg_writer.cpp b/liblog/pmsg_writer.cpp index 0751e2c53..8e676bdbf 100644 --- a/liblog/pmsg_writer.cpp +++ b/liblog/pmsg_writer.cpp @@ -188,7 +188,7 @@ ssize_t __android_log_pmsg_file_write(log_id_t logId, char prio, const char* fil return -EINVAL; } - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); cp = strdup(filename); if (!cp) { diff --git a/liblog/properties.cpp b/liblog/properties.cpp index 37670ecd6..f5e060c1f 100644 --- a/liblog/properties.cpp +++ b/liblog/properties.cpp @@ -365,29 +365,6 @@ static inline unsigned char do_cache2_char(struct cache2_char* self) { return c; } -static unsigned char evaluate_persist_ro(const struct cache2_char* self) { - unsigned char c = self->cache_persist.c; - - if (c) { - return c; - } - - return self->cache_ro.c; -} - -/* - * Timestamp state generally remains constant, but can change at any time - * to handle developer requirements. - */ -clockid_t android_log_clockid() { - static struct cache2_char clockid = {PTHREAD_MUTEX_INITIALIZER, 0, - "persist.logd.timestamp", {{NULL, 0xFFFFFFFF}, '\0'}, - "ro.logd.timestamp", {{NULL, 0xFFFFFFFF}, '\0'}, - evaluate_persist_ro}; - - return (tolower(do_cache2_char(&clockid)) == 'm') ? CLOCK_MONOTONIC : CLOCK_REALTIME; -} - /* * Security state generally remains constant, but the DO must be able * to turn off logging should it become spammy after an attack is detected. diff --git a/liblog/tests/liblog_benchmark.cpp b/liblog/tests/liblog_benchmark.cpp index f4734b930..a4e4def9c 100644 --- a/liblog/tests/liblog_benchmark.cpp +++ b/liblog/tests/liblog_benchmark.cpp @@ -184,7 +184,7 @@ static void BM_pmsg_short(benchmark::State& state) { */ struct timespec ts; - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); android_pmsg_log_header_t pmsg_header; pmsg_header.magic = LOGGER_MAGIC; @@ -260,7 +260,7 @@ static void BM_pmsg_short_aligned(benchmark::State& state) { */ struct timespec ts; - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); struct packet { android_pmsg_log_header_t pmsg_header; @@ -335,7 +335,7 @@ static void BM_pmsg_short_unaligned1(benchmark::State& state) { */ struct timespec ts; - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); struct packet { android_pmsg_log_header_t pmsg_header; @@ -410,7 +410,7 @@ static void BM_pmsg_long_aligned(benchmark::State& state) { */ struct timespec ts; - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); struct packet { android_pmsg_log_header_t pmsg_header; @@ -483,7 +483,7 @@ static void BM_pmsg_long_unaligned1(benchmark::State& state) { */ struct timespec ts; - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); struct packet { android_pmsg_log_header_t pmsg_header; @@ -791,16 +791,6 @@ static void BM_is_loggable(benchmark::State& state) { } BENCHMARK(BM_is_loggable); -/* - * Measure the time it takes for android_log_clockid. - */ -static void BM_clockid(benchmark::State& state) { - while (state.KeepRunning()) { - android_log_clockid(); - } -} -BENCHMARK(BM_clockid); - /* * Measure the time it takes for __android_log_security. */ diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp index d3d8e914e..bbc985a79 100644 --- a/liblog/tests/liblog_test.cpp +++ b/liblog/tests/liblog_test.cpp @@ -329,8 +329,6 @@ static void bswrite_test(const char* message) { #ifdef __ANDROID__ pid_t pid = getpid(); - log_time ts(android_log_clockid()); - size_t num_lines = 1, size = 0, length = 0, total = 0; const char* cp = message; while (*cp) { @@ -432,7 +430,6 @@ static void buf_write_test(const char* message) { pid_t pid = getpid(); static const char tag[] = "TEST__android_log_buf_write"; - log_time ts(android_log_clockid()); auto write_function = [&] { EXPECT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO, tag, message)); diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp index 8185f0165..13023f2a2 100644 --- a/logcat/logcat.cpp +++ b/logcat/logcat.cpp @@ -459,7 +459,7 @@ static log_time lastLogTime(const char* outputFileName) { closedir); if (!dir.get()) return retval; - log_time now(android_log_clockid()); + log_time now(CLOCK_REALTIME); size_t len = strlen(file); log_time modulo(0, NS_PER_SEC); diff --git a/logcat/tests/logcat_test.cpp b/logcat/tests/logcat_test.cpp index b32b43737..3a55c4e93 100644 --- a/logcat/tests/logcat_test.cpp +++ b/logcat/tests/logcat_test.cpp @@ -174,11 +174,6 @@ static size_t inject(ssize_t count) { } TEST(logcat, year) { - if (android_log_clockid() == CLOCK_MONOTONIC) { - fprintf(stderr, "Skipping test, logd is monotonic time\n"); - return; - } - int count; int tries = 3; // in case run too soon after system start or buffer clear @@ -249,11 +244,6 @@ static char* fgetLongTime(char* buffer, size_t buflen, FILE* fp) { } TEST(logcat, tz) { - if (android_log_clockid() == CLOCK_MONOTONIC) { - fprintf(stderr, "Skipping test, logd is monotonic time\n"); - return; - } - int tries = 4; // in case run too soon after system start or buffer clear int count; diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp index 37067bd81..2133fdfa3 100644 --- a/logd/LogAudit.cpp +++ b/logd/LogAudit.cpp @@ -247,22 +247,13 @@ int LogAudit::logPrint(const char* fmt, ...) { static const char audit_str[] = " audit("; char* timeptr = strstr(str, audit_str); - if (timeptr && - ((cp = now.strptime(timeptr + sizeof(audit_str) - 1, "%s.%q"))) && + if (timeptr && ((cp = now.strptime(timeptr + sizeof(audit_str) - 1, "%s.%q"))) && (*cp == ':')) { memcpy(timeptr + sizeof(audit_str) - 1, "0.0", 3); memmove(timeptr + sizeof(audit_str) - 1 + 3, cp, strlen(cp) + 1); - if (!isMonotonic()) { - if (android::isMonotonic(now)) { - LogKlog::convertMonotonicToReal(now); - } - } else { - if (!android::isMonotonic(now)) { - LogKlog::convertRealToMonotonic(now); - } + if (android::isMonotonic(now)) { + LogKlog::convertMonotonicToReal(now); } - } else if (isMonotonic()) { - now = log_time(CLOCK_MONOTONIC); } else { now = log_time(CLOCK_REALTIME); } diff --git a/logd/LogAudit.h b/logd/LogAudit.h index c3d7a3ede..7df0a5d8e 100644 --- a/logd/LogAudit.h +++ b/logd/LogAudit.h @@ -36,9 +36,6 @@ class LogAudit : public SocketListener { public: LogAudit(LogBuffer* buf, LogReader* reader, int fdDmesg); int log(char* buf, size_t len); - bool isMonotonic() { - return logbuf->isMonotonic(); - } protected: virtual bool onDataAvailable(SocketClient* cli); diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index a7323e8e9..2cb0c5eba 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -50,48 +50,6 @@ void LogBuffer::init() { setSize(i, LOG_BUFFER_MIN_SIZE); } } - bool lastMonotonic = monotonic; - monotonic = android_log_clockid() == CLOCK_MONOTONIC; - if (lastMonotonic != monotonic) { - // - // Fixup all timestamps, may not be 100% accurate, but better than - // throwing what we have away when we get 'surprised' by a change. - // In-place element fixup so no need to check reader-lock. Entries - // should already be in timestamp order, but we could end up with a - // few out-of-order entries if new monotonics come in before we - // are notified of the reinit change in status. A Typical example would - // be: - // --------- beginning of system - // 10.494082 184 201 D Cryptfs : Just triggered post_fs_data - // --------- beginning of kernel - // 0.000000 0 0 I : Initializing cgroup subsys - // as the act of mounting /data would trigger persist.logd.timestamp to - // be corrected. 1/30 corner case YMMV. - // - rdlock(); - LogBufferElementCollection::iterator it = mLogElements.begin(); - while ((it != mLogElements.end())) { - LogBufferElement* e = *it; - if (monotonic) { - if (!android::isMonotonic(e->mRealTime)) { - LogKlog::convertRealToMonotonic(e->mRealTime); - if ((e->mRealTime.tv_nsec % 1000) == 0) { - e->mRealTime.tv_nsec++; - } - } - } else { - if (android::isMonotonic(e->mRealTime)) { - LogKlog::convertMonotonicToReal(e->mRealTime); - if ((e->mRealTime.tv_nsec % 1000) == 0) { - e->mRealTime.tv_nsec++; - } - } - } - ++it; - } - unlock(); - } - // Release any sleeping reader threads to dump their current content. LogReaderThread::wrlock(); @@ -106,10 +64,7 @@ void LogBuffer::init() { } LogBuffer::LogBuffer(LastLogTimes* times, LogTags* tags, PruneList* prune) - : monotonic(android_log_clockid() == CLOCK_MONOTONIC), - mTimes(*times), - tags_(tags), - prune_(prune) { + : mTimes(*times), tags_(tags), prune_(prune) { pthread_rwlock_init(&mLogElementsLock, nullptr); log_id_for_each(i) { diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h index eb41efb0f..0fe19996b 100644 --- a/logd/LogBuffer.h +++ b/logd/LogBuffer.h @@ -91,8 +91,6 @@ class LogBuffer { unsigned long mMaxSize[LOG_ID_MAX]; - bool monotonic; - LogBufferElement* lastLoggedElements[LOG_ID_MAX]; LogBufferElement* droppedElements[LOG_ID_MAX]; void log(LogBufferElement* elem); @@ -103,9 +101,6 @@ class LogBuffer { LogBuffer(LastLogTimes* times, LogTags* tags, PruneList* prune); ~LogBuffer(); void init(); - bool isMonotonic() { - return monotonic; - } int log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid, const char* msg, uint16_t len); diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp index 5788ada47..c30807365 100644 --- a/logd/LogKlog.cpp +++ b/logd/LogKlog.cpp @@ -309,8 +309,6 @@ log_time LogKlog::sniffTime(const char*& buf, ssize_t len, bool reverse) { } buf = cp; - if (isMonotonic()) return now; - const char* b; if (((b = android::strnstr(cp, len, suspendStr))) && (((b += strlen(suspendStr)) - cp) < len)) { @@ -356,11 +354,7 @@ log_time LogKlog::sniffTime(const char*& buf, ssize_t len, bool reverse) { convertMonotonicToReal(now); } else { - if (isMonotonic()) { - now = log_time(CLOCK_MONOTONIC); - } else { - now = log_time(CLOCK_REALTIME); - } + now = log_time(CLOCK_REALTIME); } return now; } @@ -431,45 +425,6 @@ static int parseKernelPrio(const char*& buf, ssize_t len) { return pri; } -// Passed the entire SYSLOG_ACTION_READ_ALL buffer and interpret a -// compensated start time. -void LogKlog::synchronize(const char* buf, ssize_t len) { - const char* cp = android::strnstr(buf, len, suspendStr); - if (!cp) { - cp = android::strnstr(buf, len, resumeStr); - if (!cp) return; - } else { - const char* rp = android::strnstr(buf, len, resumeStr); - if (rp && (rp < cp)) cp = rp; - } - - do { - --cp; - } while ((cp > buf) && (*cp != '\n')); - if (*cp == '\n') { - ++cp; - } - parseKernelPrio(cp, len - (cp - buf)); - - log_time now = sniffTime(cp, len - (cp - buf), true); - - const char* suspended = android::strnstr(buf, len, suspendedStr); - if (!suspended || (suspended > cp)) { - return; - } - cp = suspended; - - do { - --cp; - } while ((cp > buf) && (*cp != '\n')); - if (*cp == '\n') { - ++cp; - } - parseKernelPrio(cp, len - (cp - buf)); - - sniffTime(cp, len - (cp - buf), true); -} - // Convert kernel log priority number into an Android Logger priority number static int convertKernelPrioToAndroidPrio(int pri) { switch (pri & LOG_PRIMASK) { @@ -789,7 +744,7 @@ int LogKlog::log(const char* buf, ssize_t len) { memcpy(np, p, b); np[b] = '\0'; - if (!isMonotonic()) { + { // Watch out for singular race conditions with timezone causing near // integer quarter-hour jumps in the time and compensate accordingly. // Entries will be temporal within near_seconds * 2. b/21868540 diff --git a/logd/LogKlog.h b/logd/LogKlog.h index 6bfd6a841..4c0975155 100644 --- a/logd/LogKlog.h +++ b/logd/LogKlog.h @@ -42,17 +42,10 @@ class LogKlog : public SocketListener { LogKlog(LogBuffer* buf, LogReader* reader, int fdWrite, int fdRead, bool auditd); int log(const char* buf, ssize_t len); - void synchronize(const char* buf, ssize_t len); - bool isMonotonic() { - return logbuf->isMonotonic(); - } static void convertMonotonicToReal(log_time& real) { real += correction; } - static void convertRealToMonotonic(log_time& real) { - real -= correction; - } protected: log_time sniffTime(const char*& buf, ssize_t len, bool reverse); diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp index 4702de55e..a590cef85 100644 --- a/logd/LogReader.cpp +++ b/logd/LogReader.cpp @@ -150,9 +150,8 @@ bool LogReader::onDataAvailable(SocketClient* cli) { // Convert realtime to sequence number if (start != log_time::EPOCH) { bool start_time_set = false; - bool is_monotonic = logbuf().isMonotonic() && android::isMonotonic(start); uint64_t last = sequence; - auto log_find_start = [pid, logMask, start, is_monotonic, &sequence, &start_time_set, + auto log_find_start = [pid, logMask, start, &sequence, &start_time_set, &last](const LogBufferElement* element) -> int { if (pid && pid != element->getPid()) { return 0; @@ -164,15 +163,13 @@ bool LogReader::onDataAvailable(SocketClient* cli) { sequence = element->getSequence(); start_time_set = true; return -1; - } else if (!is_monotonic || android::isMonotonic(element->getRealTime())) { + } else { if (start < element->getRealTime()) { sequence = last; start_time_set = true; return -1; } last = element->getSequence(); - } else { - last = element->getSequence(); } return 0; }; diff --git a/logd/LogTags.cpp b/logd/LogTags.cpp index 3e52b3871..17c9a971e 100644 --- a/logd/LogTags.cpp +++ b/logd/LogTags.cpp @@ -548,7 +548,7 @@ void LogTags::WritePmsgEventLogTags(uint32_t tag, uid_t uid) { */ struct timespec ts; - clock_gettime(android_log_clockid(), &ts); + clock_gettime(CLOCK_REALTIME, &ts); android_log_header_t header = { .id = LOG_ID_EVENTS, diff --git a/logd/README.property b/logd/README.property index 1b7e1652c..6a9369adc 100644 --- a/logd/README.property +++ b/logd/README.property @@ -44,10 +44,6 @@ ro.logd.filter string "~! ~1000/!" default for persist.logd.filter. oldest entries of chattiest UID, and the chattiest PID of system (1000, or AID_SYSTEM). -persist.logd.timestamp string ro The recording timestamp source. - "m[onotonic]" is the only supported - key character, otherwise realtime. -ro.logd.timestamp string realtime default for persist.logd.timestamp log.tag string persist The global logging level, VERBOSE, DEBUG, INFO, WARN, ERROR, ASSERT or SILENT. Only the first character is diff --git a/logd/main.cpp b/logd/main.cpp index cc45eb3f3..84b97cad2 100644 --- a/logd/main.cpp +++ b/logd/main.cpp @@ -201,10 +201,6 @@ static void readDmesg(LogAudit* al, LogKlog* kl) { } buf[--len] = '\0'; - if (kl && kl->isMonotonic()) { - kl->synchronize(buf.get(), len); - } - ssize_t sublen; for (char *ptr = nullptr, *tok = buf.get(); (rc >= 0) && !!(tok = android::log_strntok_r(tok, len, ptr, sublen)); diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp index 1dd5c8696..55737e9e9 100644 --- a/logd/tests/logd_test.cpp +++ b/logd/tests/logd_test.cpp @@ -606,7 +606,7 @@ TEST(logd, timeout) { // A few tries to get it right just in case wrap kicks in due to // content providers being active during the test. int i = 5; - log_time start(android_log_clockid()); + log_time start(CLOCK_REALTIME); start.tv_sec -= 30; // reach back a moderate period of time while (--i) { @@ -682,7 +682,7 @@ TEST(logd, timeout) { if (msg > start) { start = msg; start.tv_sec += 30; - log_time now = log_time(android_log_clockid()); + log_time now = log_time(CLOCK_REALTIME); if (start > now) { start = now; --start.tv_sec;