| /* | |
| * Copyright (C) 2014 The Android Open Source Project | |
| * | |
| * Licensed under the Apache License, Version 2.0 (the "License"); | |
| * you may not use this file except in compliance with the License. | |
| * You may obtain a copy of the License at | |
| * | |
| * http://www.apache.org/licenses/LICENSE-2.0 | |
| * | |
| * Unless required by applicable law or agreed to in writing, software | |
| * distributed under the License is distributed on an "AS IS" BASIS, | |
| * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | |
| * See the License for the specific language governing permissions and | |
| * limitations under the License. | |
| */ | |
| #include <ctype.h> | |
| #include <errno.h> | |
| #include <inttypes.h> | |
| #include <limits.h> | |
| #include <stdarg.h> | |
| #include <stdlib.h> | |
| #include <string.h> | |
| #include <sys/prctl.h> | |
| #include <sys/uio.h> | |
| #include <syslog.h> | |
| #include <private/android_filesystem_config.h> | |
| #include <private/android_logger.h> | |
| #include "LogBuffer.h" | |
| #include "LogKlog.h" | |
| #include "LogReader.h" | |
| #define KMSG_PRIORITY(PRI) \ | |
| '<', '0' + (LOG_SYSLOG | (PRI)) / 10, '0' + (LOG_SYSLOG | (PRI)) % 10, '>' | |
| static const char priority_message[] = { KMSG_PRIORITY(LOG_INFO), '\0' }; | |
| // List of the _only_ needles we supply here to android::strnstr | |
| static const char suspendStr[] = "PM: suspend entry "; | |
| static const char resumeStr[] = "PM: suspend exit "; | |
| static const char suspendedStr[] = "Suspended for "; | |
| static const char healthdStr[] = "healthd"; | |
| static const char batteryStr[] = ": battery "; | |
| static const char auditStr[] = " audit("; | |
| static const char klogdStr[] = "logd.klogd: "; | |
| // Parsing is hard | |
| // called if we see a '<', s is the next character, returns pointer after '>' | |
| static char* is_prio(char* s, ssize_t len) { | |
| if ((len <= 0) || !isdigit(*s++)) return nullptr; | |
| --len; | |
| static const size_t max_prio_len = (len < 4) ? len : 4; | |
| size_t priolen = 0; | |
| char c; | |
| while (((c = *s++)) && (++priolen <= max_prio_len)) { | |
| if (!isdigit(c)) return ((c == '>') && (*s == '[')) ? s : nullptr; | |
| } | |
| return nullptr; | |
| } | |
| // called if we see a '[', s is the next character, returns pointer after ']' | |
| static char* is_timestamp(char* s, ssize_t len) { | |
| while ((len > 0) && (*s == ' ')) { | |
| ++s; | |
| --len; | |
| } | |
| if ((len <= 0) || !isdigit(*s++)) return nullptr; | |
| --len; | |
| bool first_period = true; | |
| char c; | |
| while ((len > 0) && ((c = *s++))) { | |
| --len; | |
| if ((c == '.') && first_period) { | |
| first_period = false; | |
| } else if (!isdigit(c)) { | |
| return ((c == ']') && !first_period && (*s == ' ')) ? s : nullptr; | |
| } | |
| } | |
| return nullptr; | |
| } | |
| // Like strtok_r with "\r\n" except that we look for log signatures (regex) | |
| // \(\(<[0-9]\{1,4\}>\)\([[] *[0-9]+[.][0-9]+[]] \)\{0,1\}\|[[] | |
| // *[0-9]+[.][0-9]+[]] \) | |
| // and split if we see a second one without a newline. | |
| // We allow nuls in content, monitoring the overall length and sub-length of | |
| // the discovered tokens. | |
| #define SIGNATURE_MASK 0xF0 | |
| // <digit> following ('0' to '9' masked with ~SIGNATURE_MASK) added to signature | |
| #define LESS_THAN_SIG SIGNATURE_MASK | |
| #define OPEN_BRACKET_SIG ((SIGNATURE_MASK << 1) & SIGNATURE_MASK) | |
| // space is one more than <digit> of 9 | |
| #define OPEN_BRACKET_SPACE ((char)(OPEN_BRACKET_SIG | 10)) | |
| char* android::log_strntok_r(char* s, ssize_t& len, char*& last, | |
| ssize_t& sublen) { | |
| sublen = 0; | |
| if (len <= 0) return nullptr; | |
| if (!s) { | |
| if (!(s = last)) return nullptr; | |
| // fixup for log signature split <, | |
| // LESS_THAN_SIG + <digit> | |
| if ((*s & SIGNATURE_MASK) == LESS_THAN_SIG) { | |
| *s = (*s & ~SIGNATURE_MASK) + '0'; | |
| *--s = '<'; | |
| ++len; | |
| } | |
| // fixup for log signature split [, | |
| // OPEN_BRACKET_SPACE is space, OPEN_BRACKET_SIG + <digit> | |
| if ((*s & SIGNATURE_MASK) == OPEN_BRACKET_SIG) { | |
| *s = (*s == OPEN_BRACKET_SPACE) ? ' ' : (*s & ~SIGNATURE_MASK) + '0'; | |
| *--s = '['; | |
| ++len; | |
| } | |
| } | |
| while ((len > 0) && ((*s == '\r') || (*s == '\n'))) { | |
| ++s; | |
| --len; | |
| } | |
| if (len <= 0) return last = nullptr; | |
| char *peek, *tok = s; | |
| for (;;) { | |
| if (len <= 0) { | |
| last = nullptr; | |
| return tok; | |
| } | |
| char c = *s++; | |
| --len; | |
| ssize_t adjust; | |
| switch (c) { | |
| case '\r': | |
| case '\n': | |
| s[-1] = '\0'; | |
| last = s; | |
| return tok; | |
| case '<': | |
| peek = is_prio(s, len); | |
| if (!peek) break; | |
| if (s != (tok + 1)) { // not first? | |
| s[-1] = '\0'; | |
| *s &= ~SIGNATURE_MASK; | |
| *s |= LESS_THAN_SIG; // signature for '<' | |
| last = s; | |
| return tok; | |
| } | |
| adjust = peek - s; | |
| if (adjust > len) { | |
| adjust = len; | |
| } | |
| sublen += adjust; | |
| len -= adjust; | |
| s = peek; | |
| if ((*s == '[') && ((peek = is_timestamp(s + 1, len - 1)))) { | |
| adjust = peek - s; | |
| if (adjust > len) { | |
| adjust = len; | |
| } | |
| sublen += adjust; | |
| len -= adjust; | |
| s = peek; | |
| } | |
| break; | |
| case '[': | |
| peek = is_timestamp(s, len); | |
| if (!peek) break; | |
| if (s != (tok + 1)) { // not first? | |
| s[-1] = '\0'; | |
| if (*s == ' ') { | |
| *s = OPEN_BRACKET_SPACE; | |
| } else { | |
| *s &= ~SIGNATURE_MASK; | |
| *s |= OPEN_BRACKET_SIG; // signature for '[' | |
| } | |
| last = s; | |
| return tok; | |
| } | |
| adjust = peek - s; | |
| if (adjust > len) { | |
| adjust = len; | |
| } | |
| sublen += adjust; | |
| len -= adjust; | |
| s = peek; | |
| break; | |
| } | |
| ++sublen; | |
| } | |
| // NOTREACHED | |
| } | |
| log_time LogKlog::correction = (log_time(CLOCK_REALTIME) < log_time(CLOCK_MONOTONIC)) | |
| ? log_time(log_time::EPOCH) | |
| : (log_time(CLOCK_REALTIME) - log_time(CLOCK_MONOTONIC)); | |
| LogKlog::LogKlog(LogBuffer* buf, LogReader* reader, int fdWrite, int fdRead, | |
| bool auditd) | |
| : SocketListener(fdRead, false), | |
| logbuf(buf), | |
| reader(reader), | |
| signature(CLOCK_MONOTONIC), | |
| initialized(false), | |
| enableLogging(true), | |
| auditd(auditd) { | |
| static const char klogd_message[] = "%s%s%" PRIu64 "\n"; | |
| char buffer[strlen(priority_message) + strlen(klogdStr) + | |
| strlen(klogd_message) + 20]; | |
| snprintf(buffer, sizeof(buffer), klogd_message, priority_message, klogdStr, | |
| signature.nsec()); | |
| write(fdWrite, buffer, strlen(buffer)); | |
| } | |
| bool LogKlog::onDataAvailable(SocketClient* cli) { | |
| if (!initialized) { | |
| prctl(PR_SET_NAME, "logd.klogd"); | |
| initialized = true; | |
| enableLogging = false; | |
| } | |
| char buffer[LOGGER_ENTRY_MAX_PAYLOAD]; | |
| ssize_t len = 0; | |
| for (;;) { | |
| ssize_t retval = 0; | |
| if (len < (ssize_t)(sizeof(buffer) - 1)) { | |
| retval = | |
| read(cli->getSocket(), buffer + len, sizeof(buffer) - 1 - len); | |
| } | |
| if ((retval == 0) && (len <= 0)) { | |
| break; | |
| } | |
| if (retval < 0) { | |
| return false; | |
| } | |
| len += retval; | |
| bool full = len == (sizeof(buffer) - 1); | |
| char* ep = buffer + len; | |
| *ep = '\0'; | |
| ssize_t sublen; | |
| for (char *ptr = nullptr, *tok = buffer; | |
| !!(tok = android::log_strntok_r(tok, len, ptr, sublen)); | |
| tok = nullptr) { | |
| if (((tok + sublen) >= ep) && (retval != 0) && full) { | |
| if (sublen > 0) memmove(buffer, tok, sublen); | |
| len = sublen; | |
| break; | |
| } | |
| if ((sublen > 0) && *tok) { | |
| log(tok, sublen); | |
| } | |
| } | |
| } | |
| return true; | |
| } | |
| void LogKlog::calculateCorrection(const log_time& monotonic, | |
| const char* real_string, ssize_t len) { | |
| static const char real_format[] = "%Y-%m-%d %H:%M:%S.%09q UTC"; | |
| if (len < (ssize_t)(strlen(real_format) + 5)) return; | |
| log_time real(log_time::EPOCH); | |
| const char* ep = real.strptime(real_string, real_format); | |
| if (!ep || (ep > &real_string[len]) || (real > log_time(CLOCK_REALTIME))) { | |
| return; | |
| } | |
| // kernel report UTC, log_time::strptime is localtime from calendar. | |
| // Bionic and liblog strptime does not support %z or %Z to pick up | |
| // timezone so we are calculating our own correction. | |
| time_t now = real.tv_sec; | |
| struct tm tm; | |
| memset(&tm, 0, sizeof(tm)); | |
| tm.tm_isdst = -1; | |
| localtime_r(&now, &tm); | |
| if ((tm.tm_gmtoff < 0) && ((-tm.tm_gmtoff) > (long)real.tv_sec)) { | |
| real = log_time(log_time::EPOCH); | |
| } else { | |
| real.tv_sec += tm.tm_gmtoff; | |
| } | |
| if (monotonic > real) { | |
| correction = log_time(log_time::EPOCH); | |
| } else { | |
| correction = real - monotonic; | |
| } | |
| } | |
| log_time LogKlog::sniffTime(const char*& buf, ssize_t len, bool reverse) { | |
| log_time now(log_time::EPOCH); | |
| if (len <= 0) return now; | |
| const char* cp = nullptr; | |
| if ((len > 10) && (*buf == '[')) { | |
| cp = now.strptime(buf, "[ %s.%q]"); // can index beyond buffer bounds | |
| if (cp && (cp > &buf[len - 1])) cp = nullptr; | |
| } | |
| if (cp) { | |
| len -= cp - buf; | |
| if ((len > 0) && isspace(*cp)) { | |
| ++cp; | |
| --len; | |
| } | |
| buf = cp; | |
| if (isMonotonic()) return now; | |
| const char* b; | |
| if (((b = android::strnstr(cp, len, suspendStr))) && | |
| (((b += strlen(suspendStr)) - cp) < len)) { | |
| len -= b - cp; | |
| calculateCorrection(now, b, len); | |
| } else if (((b = android::strnstr(cp, len, resumeStr))) && | |
| (((b += strlen(resumeStr)) - cp) < len)) { | |
| len -= b - cp; | |
| calculateCorrection(now, b, len); | |
| } else if (((b = android::strnstr(cp, len, healthdStr))) && | |
| (((b += strlen(healthdStr)) - cp) < len) && | |
| ((b = android::strnstr(b, len -= b - cp, batteryStr))) && | |
| (((b += strlen(batteryStr)) - cp) < len)) { | |
| // NB: healthd is roughly 150us late, so we use it instead to | |
| // trigger a check for ntp-induced or hardware clock drift. | |
| log_time real(CLOCK_REALTIME); | |
| log_time mono(CLOCK_MONOTONIC); | |
| correction = (real < mono) ? log_time(log_time::EPOCH) : (real - mono); | |
| } else if (((b = android::strnstr(cp, len, suspendedStr))) && | |
| (((b += strlen(suspendStr)) - cp) < len)) { | |
| len -= b - cp; | |
| log_time real(log_time::EPOCH); | |
| char* endp; | |
| real.tv_sec = strtol(b, &endp, 10); | |
| if ((*endp == '.') && ((endp - b) < len)) { | |
| unsigned long multiplier = NS_PER_SEC; | |
| real.tv_nsec = 0; | |
| len -= endp - b; | |
| while (--len && isdigit(*++endp) && (multiplier /= 10)) { | |
| real.tv_nsec += (*endp - '0') * multiplier; | |
| } | |
| if (reverse) { | |
| if (real > correction) { | |
| correction = log_time(log_time::EPOCH); | |
| } else { | |
| correction -= real; | |
| } | |
| } else { | |
| correction += real; | |
| } | |
| } | |
| } | |
| convertMonotonicToReal(now); | |
| } else { | |
| if (isMonotonic()) { | |
| now = log_time(CLOCK_MONOTONIC); | |
| } else { | |
| now = log_time(CLOCK_REALTIME); | |
| } | |
| } | |
| return now; | |
| } | |
| pid_t LogKlog::sniffPid(const char*& buf, ssize_t len) { | |
| if (len <= 0) return 0; | |
| const char* cp = buf; | |
| // sscanf does a strlen, let's check if the string is not nul terminated. | |
| // pseudo out-of-bounds access since we always have an extra char on buffer. | |
| if (((ssize_t)strnlen(cp, len) == len) && cp[len]) { | |
| return 0; | |
| } | |
| // HTC kernels with modified printk "c0 1648 " | |
| if ((len > 9) && (cp[0] == 'c') && isdigit(cp[1]) && | |
| (isdigit(cp[2]) || (cp[2] == ' ')) && (cp[3] == ' ')) { | |
| bool gotDigit = false; | |
| int i; | |
| for (i = 4; i < 9; ++i) { | |
| if (isdigit(cp[i])) { | |
| gotDigit = true; | |
| } else if (gotDigit || (cp[i] != ' ')) { | |
| break; | |
| } | |
| } | |
| if ((i == 9) && (cp[i] == ' ')) { | |
| int pid = 0; | |
| char dummy; | |
| if (sscanf(cp + 4, "%d%c", &pid, &dummy) == 2) { | |
| buf = cp + 10; // skip-it-all | |
| return pid; | |
| } | |
| } | |
| } | |
| while (len) { | |
| // Mediatek kernels with modified printk | |
| if (*cp == '[') { | |
| int pid = 0; | |
| char dummy; | |
| if (sscanf(cp, "[%d:%*[a-z_./0-9:A-Z]]%c", &pid, &dummy) == 2) { | |
| return pid; | |
| } | |
| break; // Only the first one | |
| } | |
| ++cp; | |
| --len; | |
| } | |
| return 0; | |
| } | |
| // kernel log prefix, convert to a kernel log priority number | |
| static int parseKernelPrio(const char*& buf, ssize_t len) { | |
| int pri = LOG_USER | LOG_INFO; | |
| const char* cp = buf; | |
| if ((len > 0) && (*cp == '<')) { | |
| pri = 0; | |
| while (--len && isdigit(*++cp)) { | |
| pri = (pri * 10) + *cp - '0'; | |
| } | |
| if ((len > 0) && (*cp == '>')) { | |
| ++cp; | |
| } else { | |
| cp = buf; | |
| pri = LOG_USER | LOG_INFO; | |
| } | |
| buf = cp; | |
| } | |
| 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) { | |
| case LOG_EMERG: | |
| case LOG_ALERT: | |
| case LOG_CRIT: | |
| return ANDROID_LOG_FATAL; | |
| case LOG_ERR: | |
| return ANDROID_LOG_ERROR; | |
| case LOG_WARNING: | |
| return ANDROID_LOG_WARN; | |
| default: | |
| case LOG_NOTICE: | |
| case LOG_INFO: | |
| break; | |
| case LOG_DEBUG: | |
| return ANDROID_LOG_DEBUG; | |
| } | |
| return ANDROID_LOG_INFO; | |
| } | |
| static const char* strnrchr(const char* s, ssize_t len, char c) { | |
| const char* save = nullptr; | |
| for (; len > 0; ++s, len--) { | |
| if (*s == c) { | |
| save = s; | |
| } | |
| } | |
| return save; | |
| } | |
| // | |
| // log a message into the kernel log buffer | |
| // | |
| // Filter rules to parse <PRI> <TIME> <tag> and <message> in order for | |
| // them to appear correct in the logcat output: | |
| // | |
| // LOG_KERN (0): | |
| // <PRI>[<TIME>] <tag> ":" <message> | |
| // <PRI>[<TIME>] <tag> <tag> ":" <message> | |
| // <PRI>[<TIME>] <tag> <tag>_work ":" <message> | |
| // <PRI>[<TIME>] <tag> '<tag>.<num>' ":" <message> | |
| // <PRI>[<TIME>] <tag> '<tag><num>' ":" <message> | |
| // <PRI>[<TIME>] <tag>_host '<tag>.<num>' ":" <message> | |
| // (unimplemented) <PRI>[<TIME>] <tag> '<num>.<tag>' ":" <message> | |
| // <PRI>[<TIME>] "[INFO]"<tag> : <message> | |
| // <PRI>[<TIME>] "------------[ cut here ]------------" (?) | |
| // <PRI>[<TIME>] "---[ end trace 3225a3070ca3e4ac ]---" (?) | |
| // LOG_USER, LOG_MAIL, LOG_DAEMON, LOG_AUTH, LOG_SYSLOG, LOG_LPR, LOG_NEWS | |
| // LOG_UUCP, LOG_CRON, LOG_AUTHPRIV, LOG_FTP: | |
| // <PRI+TAG>[<TIME>] (see sys/syslog.h) | |
| // Observe: | |
| // Minimum tag length = 3 NB: drops things like r5:c00bbadf, but allow PM: | |
| // Maximum tag words = 2 | |
| // Maximum tag length = 16 NB: we are thinking of how ugly logcat can get. | |
| // Not a Tag if there is no message content. | |
| // leading additional spaces means no tag, inherit last tag. | |
| // Not a Tag if <tag>: is "ERROR:", "WARNING:", "INFO:" or "CPU:" | |
| // Drop: | |
| // empty messages | |
| // messages with ' audit(' in them if auditd is running | |
| // logd.klogd: | |
| // return -1 if message logd.klogd: <signature> | |
| // | |
| int LogKlog::log(const char* buf, ssize_t len) { | |
| if (auditd && android::strnstr(buf, len, auditStr)) { | |
| return 0; | |
| } | |
| const char* p = buf; | |
| int pri = parseKernelPrio(p, len); | |
| log_time now = sniffTime(p, len - (p - buf), false); | |
| // sniff for start marker | |
| const char* start = android::strnstr(p, len - (p - buf), klogdStr); | |
| if (start) { | |
| uint64_t sig = strtoll(start + strlen(klogdStr), nullptr, 10); | |
| if (sig == signature.nsec()) { | |
| if (initialized) { | |
| enableLogging = true; | |
| } else { | |
| enableLogging = false; | |
| } | |
| return -1; | |
| } | |
| return 0; | |
| } | |
| if (!enableLogging) { | |
| return 0; | |
| } | |
| // Parse pid, tid and uid | |
| const pid_t pid = sniffPid(p, len - (p - buf)); | |
| const pid_t tid = pid; | |
| uid_t uid = AID_ROOT; | |
| if (pid) { | |
| logbuf->wrlock(); | |
| uid = logbuf->pidToUid(pid); | |
| logbuf->unlock(); | |
| } | |
| // Parse (rules at top) to pull out a tag from the incoming kernel message. | |
| // Some may view the following as an ugly heuristic, the desire is to | |
| // beautify the kernel logs into an Android Logging format; the goal is | |
| // admirable but costly. | |
| while ((p < &buf[len]) && (isspace(*p) || !*p)) { | |
| ++p; | |
| } | |
| if (p >= &buf[len]) { // timestamp, no content | |
| return 0; | |
| } | |
| start = p; | |
| const char* tag = ""; | |
| const char* etag = tag; | |
| ssize_t taglen = len - (p - buf); | |
| const char* bt = p; | |
| static const char infoBrace[] = "[INFO]"; | |
| static const ssize_t infoBraceLen = strlen(infoBrace); | |
| if ((taglen >= infoBraceLen) && | |
| !fastcmp<strncmp>(p, infoBrace, infoBraceLen)) { | |
| // <PRI>[<TIME>] "[INFO]"<tag> ":" message | |
| bt = p + infoBraceLen; | |
| taglen -= infoBraceLen; | |
| } | |
| const char* et; | |
| for (et = bt; (taglen > 0) && *et && (*et != ':') && !isspace(*et); | |
| ++et, --taglen) { | |
| // skip ':' within [ ... ] | |
| if (*et == '[') { | |
| while ((taglen > 0) && *et && *et != ']') { | |
| ++et; | |
| --taglen; | |
| } | |
| if (taglen <= 0) { | |
| break; | |
| } | |
| } | |
| } | |
| const char* cp; | |
| for (cp = et; (taglen > 0) && isspace(*cp); ++cp, --taglen) { | |
| } | |
| // Validate tag | |
| ssize_t size = et - bt; | |
| if ((taglen > 0) && (size > 0)) { | |
| if (*cp == ':') { | |
| // ToDo: handle case insensitive colon separated logging stutter: | |
| // <tag> : <tag>: ... | |
| // One Word | |
| tag = bt; | |
| etag = et; | |
| p = cp + 1; | |
| } else if ((taglen > size) && (tolower(*bt) == tolower(*cp))) { | |
| // clean up any tag stutter | |
| if (!fastcmp<strncasecmp>(bt + 1, cp + 1, size - 1)) { // no match | |
| // <PRI>[<TIME>] <tag> <tag> : message | |
| // <PRI>[<TIME>] <tag> <tag>: message | |
| // <PRI>[<TIME>] <tag> '<tag>.<num>' : message | |
| // <PRI>[<TIME>] <tag> '<tag><num>' : message | |
| // <PRI>[<TIME>] <tag> '<tag><stuff>' : message | |
| const char* b = cp; | |
| cp += size; | |
| taglen -= size; | |
| while ((--taglen > 0) && !isspace(*++cp) && (*cp != ':')) { | |
| } | |
| const char* e; | |
| for (e = cp; (taglen > 0) && isspace(*cp); ++cp, --taglen) { | |
| } | |
| if ((taglen > 0) && (*cp == ':')) { | |
| tag = b; | |
| etag = e; | |
| p = cp + 1; | |
| } | |
| } else { | |
| // what about <PRI>[<TIME>] <tag>_host '<tag><stuff>' : message | |
| static const char host[] = "_host"; | |
| static const ssize_t hostlen = strlen(host); | |
| if ((size > hostlen) && | |
| !fastcmp<strncmp>(bt + size - hostlen, host, hostlen) && | |
| !fastcmp<strncmp>(bt + 1, cp + 1, size - hostlen - 1)) { | |
| const char* b = cp; | |
| cp += size - hostlen; | |
| taglen -= size - hostlen; | |
| if (*cp == '.') { | |
| while ((--taglen > 0) && !isspace(*++cp) && | |
| (*cp != ':')) { | |
| } | |
| const char* e; | |
| for (e = cp; (taglen > 0) && isspace(*cp); | |
| ++cp, --taglen) { | |
| } | |
| if ((taglen > 0) && (*cp == ':')) { | |
| tag = b; | |
| etag = e; | |
| p = cp + 1; | |
| } | |
| } | |
| } else { | |
| goto twoWord; | |
| } | |
| } | |
| } else { | |
| // <PRI>[<TIME>] <tag> <stuff>' : message | |
| twoWord: | |
| while ((--taglen > 0) && !isspace(*++cp) && (*cp != ':')) { | |
| } | |
| const char* e; | |
| for (e = cp; (taglen > 0) && isspace(*cp); ++cp, --taglen) { | |
| } | |
| // Two words | |
| if ((taglen > 0) && (*cp == ':')) { | |
| tag = bt; | |
| etag = e; | |
| p = cp + 1; | |
| } | |
| } | |
| } // else no tag | |
| static const char cpu[] = "CPU"; | |
| static const ssize_t cpuLen = strlen(cpu); | |
| static const char warning[] = "WARNING"; | |
| static const ssize_t warningLen = strlen(warning); | |
| static const char error[] = "ERROR"; | |
| static const ssize_t errorLen = strlen(error); | |
| static const char info[] = "INFO"; | |
| static const ssize_t infoLen = strlen(info); | |
| size = etag - tag; | |
| if ((size <= 1) || | |
| // register names like x9 | |
| ((size == 2) && (isdigit(tag[0]) || isdigit(tag[1]))) || | |
| // register names like x18 but not driver names like en0 | |
| ((size == 3) && (isdigit(tag[1]) && isdigit(tag[2]))) || | |
| // blacklist | |
| ((size == cpuLen) && !fastcmp<strncmp>(tag, cpu, cpuLen)) || | |
| ((size == warningLen) && | |
| !fastcmp<strncasecmp>(tag, warning, warningLen)) || | |
| ((size == errorLen) && !fastcmp<strncasecmp>(tag, error, errorLen)) || | |
| ((size == infoLen) && !fastcmp<strncasecmp>(tag, info, infoLen))) { | |
| p = start; | |
| etag = tag = ""; | |
| } | |
| // Suppress additional stutter in tag: | |
| // eg: [143:healthd]healthd -> [143:healthd] | |
| taglen = etag - tag; | |
| // Mediatek-special printk induced stutter | |
| const char* mp = strnrchr(tag, taglen, ']'); | |
| if (mp && (++mp < etag)) { | |
| ssize_t s = etag - mp; | |
| if (((s + s) < taglen) && !fastcmp<memcmp>(mp, mp - 1 - s, s)) { | |
| taglen = mp - tag; | |
| } | |
| } | |
| // Deal with sloppy and simplistic harmless p = cp + 1 etc above. | |
| if (len < (p - buf)) { | |
| p = &buf[len]; | |
| } | |
| // skip leading space | |
| while ((p < &buf[len]) && (isspace(*p) || !*p)) { | |
| ++p; | |
| } | |
| // truncate trailing space or nuls | |
| ssize_t b = len - (p - buf); | |
| while ((b > 0) && (isspace(p[b - 1]) || !p[b - 1])) { | |
| --b; | |
| } | |
| // trick ... allow tag with empty content to be logged. log() drops empty | |
| if ((b <= 0) && (taglen > 0)) { | |
| p = " "; | |
| b = 1; | |
| } | |
| // paranoid sanity check, can not happen ... | |
| if (b > LOGGER_ENTRY_MAX_PAYLOAD) { | |
| b = LOGGER_ENTRY_MAX_PAYLOAD; | |
| } | |
| if (taglen > LOGGER_ENTRY_MAX_PAYLOAD) { | |
| taglen = LOGGER_ENTRY_MAX_PAYLOAD; | |
| } | |
| // calculate buffer copy requirements | |
| ssize_t n = 1 + taglen + 1 + b + 1; | |
| // paranoid sanity check, first two just can not happen ... | |
| if ((taglen > n) || (b > n) || (n > (ssize_t)USHRT_MAX) || (n <= 0)) { | |
| return -EINVAL; | |
| } | |
| // Careful. | |
| // We are using the stack to house the log buffer for speed reasons. | |
| // If we malloc'd this buffer, we could get away without n's USHRT_MAX | |
| // test above, but we would then required a max(n, USHRT_MAX) as | |
| // truncating length argument to logbuf->log() below. Gain is protection | |
| // of stack sanity and speedup, loss is truncated long-line content. | |
| char newstr[n]; | |
| char* np = newstr; | |
| // Convert priority into single-byte Android logger priority | |
| *np = convertKernelPrioToAndroidPrio(pri); | |
| ++np; | |
| // Copy parsed tag following priority | |
| memcpy(np, tag, taglen); | |
| np += taglen; | |
| *np = '\0'; | |
| ++np; | |
| // Copy main message to the remainder | |
| 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 | |
| static uint32_t vote_time[3]; | |
| vote_time[2] = vote_time[1]; | |
| vote_time[1] = vote_time[0]; | |
| vote_time[0] = now.tv_sec; | |
| if (vote_time[1] && vote_time[2]) { | |
| static const unsigned near_seconds = 10; | |
| static const unsigned timezones_seconds = 900; | |
| int diff0 = (vote_time[0] - vote_time[1]) / near_seconds; | |
| unsigned abs0 = (diff0 < 0) ? -diff0 : diff0; | |
| int diff1 = (vote_time[1] - vote_time[2]) / near_seconds; | |
| unsigned abs1 = (diff1 < 0) ? -diff1 : diff1; | |
| if ((abs1 <= 1) && // last two were in agreement on timezone | |
| ((abs0 + 1) % (timezones_seconds / near_seconds)) <= 2) { | |
| abs0 = (abs0 + 1) / (timezones_seconds / near_seconds) * | |
| timezones_seconds; | |
| now.tv_sec -= (diff0 < 0) ? -abs0 : abs0; | |
| } | |
| } | |
| } | |
| // Log message | |
| int rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr, (uint16_t)n); | |
| // notify readers | |
| if (rc > 0) { | |
| reader->notifyNewLog(static_cast<log_mask_t>(1 << LOG_ID_KERNEL)); | |
| } | |
| return rc; | |
| } |