Remove the monotonic option for logging
This has been around for ~5 years but there has been roughly no
adoption, so remove this as we clean up the logging code.
Future efforts may track the monotonic timestamp in all cases.
Test: logging unit tests
Change-Id: I55ed565669f923988e741f6b384141bba893630d
diff --git a/liblog/README.md b/liblog/README.md
index f64f376..74a2cd7 100644
--- a/liblog/README.md
+++ b/liblog/README.md
@@ -60,8 +60,6 @@
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 @@
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 820b7cb..d7e9b7d 100644
--- a/liblog/include/log/log.h
+++ b/liblog/include/log/log.h
@@ -133,12 +133,6 @@
(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 3a75fa3..22c7eca 100644
--- a/liblog/logger_write.cpp
+++ b/liblog/logger_write.cpp
@@ -192,7 +192,7 @@
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 9e8d277..238431f 100644
--- a/liblog/logprint.cpp
+++ b/liblog/logprint.cpp
@@ -216,11 +216,7 @@
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 @@
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 0751e2c..8e676bd 100644
--- a/liblog/pmsg_writer.cpp
+++ b/liblog/pmsg_writer.cpp
@@ -188,7 +188,7 @@
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 37670ec..f5e060c 100644
--- a/liblog/properties.cpp
+++ b/liblog/properties.cpp
@@ -365,29 +365,6 @@
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 f4734b9..a4e4def 100644
--- a/liblog/tests/liblog_benchmark.cpp
+++ b/liblog/tests/liblog_benchmark.cpp
@@ -184,7 +184,7 @@
*/
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 @@
*/
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 @@
*/
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 @@
*/
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 @@
*/
struct timespec ts;
- clock_gettime(android_log_clockid(), &ts);
+ clock_gettime(CLOCK_REALTIME, &ts);
struct packet {
android_pmsg_log_header_t pmsg_header;
@@ -792,16 +792,6 @@
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.
*/
static void BM_security(benchmark::State& state) {
diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp
index d3d8e91..bbc985a 100644
--- a/liblog/tests/liblog_test.cpp
+++ b/liblog/tests/liblog_test.cpp
@@ -329,8 +329,6 @@
#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 @@
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 8185f01..13023f2 100644
--- a/logcat/logcat.cpp
+++ b/logcat/logcat.cpp
@@ -459,7 +459,7 @@
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 b32b437..3a55c4e 100644
--- a/logcat/tests/logcat_test.cpp
+++ b/logcat/tests/logcat_test.cpp
@@ -174,11 +174,6 @@
}
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 @@
}
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 37067bd..2133fdf 100644
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -247,22 +247,13 @@
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 c3d7a3e..7df0a5d 100644
--- a/logd/LogAudit.h
+++ b/logd/LogAudit.h
@@ -36,9 +36,6 @@
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 a7323e8..2cb0c5e 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -50,48 +50,6 @@
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 @@
}
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 eb41efb..0fe1999 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -91,8 +91,6 @@
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 @@
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 5788ada..c308073 100644
--- a/logd/LogKlog.cpp
+++ b/logd/LogKlog.cpp
@@ -309,8 +309,6 @@
}
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 @@
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 @@
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 @@
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 6bfd6a8..4c09751 100644
--- a/logd/LogKlog.h
+++ b/logd/LogKlog.h
@@ -42,17 +42,10 @@
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 4702de5..a590cef 100644
--- a/logd/LogReader.cpp
+++ b/logd/LogReader.cpp
@@ -150,9 +150,8 @@
// 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 @@
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 3e52b38..17c9a97 100644
--- a/logd/LogTags.cpp
+++ b/logd/LogTags.cpp
@@ -548,7 +548,7 @@
*/
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 1b7e165..6a9369a 100644
--- a/logd/README.property
+++ b/logd/README.property
@@ -44,10 +44,6 @@
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 cc45eb3..84b97ca 100644
--- a/logd/main.cpp
+++ b/logd/main.cpp
@@ -201,10 +201,6 @@
}
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 1dd5c86..55737e9 100644
--- a/logd/tests/logd_test.cpp
+++ b/logd/tests/logd_test.cpp
@@ -606,7 +606,7 @@
// 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 @@
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;