1 /*
2  * Copyright (C) 2014 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 #include <ctype.h>
18 #include <errno.h>
19 #include <inttypes.h>
20 #include <limits.h>
21 #include <stdarg.h>
22 #include <stdlib.h>
23 #include <string.h>
24 #include <sys/prctl.h>
25 #include <sys/uio.h>
26 #include <syslog.h>
27 
28 #include <private/android_filesystem_config.h>
29 #include <private/android_logger.h>
30 
31 #include "LogBuffer.h"
32 #include "LogKlog.h"
33 #include "LogReader.h"
34 
35 #define KMSG_PRIORITY(PRI) \
36     '<', '0' + (LOG_SYSLOG | (PRI)) / 10, '0' + (LOG_SYSLOG | (PRI)) % 10, '>'
37 
38 static const char priority_message[] = { KMSG_PRIORITY(LOG_INFO), '\0' };
39 
40 // List of the _only_ needles we supply here to android::strnstr
41 static const char suspendStr[] = "PM: suspend entry ";
42 static const char resumeStr[] = "PM: suspend exit ";
43 static const char suspendedStr[] = "Suspended for ";
44 static const char healthdStr[] = "healthd";
45 static const char batteryStr[] = ": battery ";
46 static const char auditStr[] = " audit(";
47 static const char klogdStr[] = "logd.klogd: ";
48 
49 // Parsing is hard
50 
51 // called if we see a '<', s is the next character, returns pointer after '>'
is_prio(char * s,ssize_t len)52 static char* is_prio(char* s, ssize_t len) {
53     if ((len <= 0) || !isdigit(*s++)) return nullptr;
54     --len;
55     static const size_t max_prio_len = (len < 4) ? len : 4;
56     size_t priolen = 0;
57     char c;
58     while (((c = *s++)) && (++priolen <= max_prio_len)) {
59         if (!isdigit(c)) return ((c == '>') && (*s == '[')) ? s : nullptr;
60     }
61     return nullptr;
62 }
63 
64 // called if we see a '[', s is the next character, returns pointer after ']'
is_timestamp(char * s,ssize_t len)65 static char* is_timestamp(char* s, ssize_t len) {
66     while ((len > 0) && (*s == ' ')) {
67         ++s;
68         --len;
69     }
70     if ((len <= 0) || !isdigit(*s++)) return nullptr;
71     --len;
72     bool first_period = true;
73     char c;
74     while ((len > 0) && ((c = *s++))) {
75         --len;
76         if ((c == '.') && first_period) {
77             first_period = false;
78         } else if (!isdigit(c)) {
79             return ((c == ']') && !first_period && (*s == ' ')) ? s : nullptr;
80         }
81     }
82     return nullptr;
83 }
84 
85 // Like strtok_r with "\r\n" except that we look for log signatures (regex)
86 //  \(\(<[0-9]\{1,4\}>\)\([[] *[0-9]+[.][0-9]+[]] \)\{0,1\}\|[[]
87 //  *[0-9]+[.][0-9]+[]] \)
88 // and split if we see a second one without a newline.
89 // We allow nuls in content, monitoring the overall length and sub-length of
90 // the discovered tokens.
91 
92 #define SIGNATURE_MASK 0xF0
93 // <digit> following ('0' to '9' masked with ~SIGNATURE_MASK) added to signature
94 #define LESS_THAN_SIG SIGNATURE_MASK
95 #define OPEN_BRACKET_SIG ((SIGNATURE_MASK << 1) & SIGNATURE_MASK)
96 // space is one more than <digit> of 9
97 #define OPEN_BRACKET_SPACE ((char)(OPEN_BRACKET_SIG | 10))
98 
log_strntok_r(char * s,ssize_t & len,char * & last,ssize_t & sublen)99 char* android::log_strntok_r(char* s, ssize_t& len, char*& last,
100                              ssize_t& sublen) {
101     sublen = 0;
102     if (len <= 0) return nullptr;
103     if (!s) {
104         if (!(s = last)) return nullptr;
105         // fixup for log signature split <,
106         // LESS_THAN_SIG + <digit>
107         if ((*s & SIGNATURE_MASK) == LESS_THAN_SIG) {
108             *s = (*s & ~SIGNATURE_MASK) + '0';
109             *--s = '<';
110             ++len;
111         }
112         // fixup for log signature split [,
113         // OPEN_BRACKET_SPACE is space, OPEN_BRACKET_SIG + <digit>
114         if ((*s & SIGNATURE_MASK) == OPEN_BRACKET_SIG) {
115             *s = (*s == OPEN_BRACKET_SPACE) ? ' ' : (*s & ~SIGNATURE_MASK) + '0';
116             *--s = '[';
117             ++len;
118         }
119     }
120 
121     while ((len > 0) && ((*s == '\r') || (*s == '\n'))) {
122         ++s;
123         --len;
124     }
125 
126     if (len <= 0) return last = nullptr;
127     char *peek, *tok = s;
128 
129     for (;;) {
130         if (len <= 0) {
131             last = nullptr;
132             return tok;
133         }
134         char c = *s++;
135         --len;
136         ssize_t adjust;
137         switch (c) {
138             case '\r':
139             case '\n':
140                 s[-1] = '\0';
141                 last = s;
142                 return tok;
143 
144             case '<':
145                 peek = is_prio(s, len);
146                 if (!peek) break;
147                 if (s != (tok + 1)) {  // not first?
148                     s[-1] = '\0';
149                     *s &= ~SIGNATURE_MASK;
150                     *s |= LESS_THAN_SIG;  // signature for '<'
151                     last = s;
152                     return tok;
153                 }
154                 adjust = peek - s;
155                 if (adjust > len) {
156                     adjust = len;
157                 }
158                 sublen += adjust;
159                 len -= adjust;
160                 s = peek;
161                 if ((*s == '[') && ((peek = is_timestamp(s + 1, len - 1)))) {
162                     adjust = peek - s;
163                     if (adjust > len) {
164                         adjust = len;
165                     }
166                     sublen += adjust;
167                     len -= adjust;
168                     s = peek;
169                 }
170                 break;
171 
172             case '[':
173                 peek = is_timestamp(s, len);
174                 if (!peek) break;
175                 if (s != (tok + 1)) {  // not first?
176                     s[-1] = '\0';
177                     if (*s == ' ') {
178                         *s = OPEN_BRACKET_SPACE;
179                     } else {
180                         *s &= ~SIGNATURE_MASK;
181                         *s |= OPEN_BRACKET_SIG;  // signature for '['
182                     }
183                     last = s;
184                     return tok;
185                 }
186                 adjust = peek - s;
187                 if (adjust > len) {
188                     adjust = len;
189                 }
190                 sublen += adjust;
191                 len -= adjust;
192                 s = peek;
193                 break;
194         }
195         ++sublen;
196     }
197     // NOTREACHED
198 }
199 
200 log_time LogKlog::correction =
201     (log_time(CLOCK_REALTIME) < log_time(CLOCK_MONOTONIC))
202         ? log_time::EPOCH
203         : (log_time(CLOCK_REALTIME) - log_time(CLOCK_MONOTONIC));
204 
LogKlog(LogBuffer * buf,LogReader * reader,int fdWrite,int fdRead,bool auditd)205 LogKlog::LogKlog(LogBuffer* buf, LogReader* reader, int fdWrite, int fdRead,
206                  bool auditd)
207     : SocketListener(fdRead, false),
208       logbuf(buf),
209       reader(reader),
210       signature(CLOCK_MONOTONIC),
211       initialized(false),
212       enableLogging(true),
213       auditd(auditd) {
214     static const char klogd_message[] = "%s%s%" PRIu64 "\n";
215     char buffer[strlen(priority_message) + strlen(klogdStr) +
216                 strlen(klogd_message) + 20];
217     snprintf(buffer, sizeof(buffer), klogd_message, priority_message, klogdStr,
218              signature.nsec());
219     write(fdWrite, buffer, strlen(buffer));
220 }
221 
onDataAvailable(SocketClient * cli)222 bool LogKlog::onDataAvailable(SocketClient* cli) {
223     if (!initialized) {
224         prctl(PR_SET_NAME, "logd.klogd");
225         initialized = true;
226         enableLogging = false;
227     }
228 
229     char buffer[LOGGER_ENTRY_MAX_PAYLOAD];
230     ssize_t len = 0;
231 
232     for (;;) {
233         ssize_t retval = 0;
234         if (len < (ssize_t)(sizeof(buffer) - 1)) {
235             retval =
236                 read(cli->getSocket(), buffer + len, sizeof(buffer) - 1 - len);
237         }
238         if ((retval == 0) && (len <= 0)) {
239             break;
240         }
241         if (retval < 0) {
242             return false;
243         }
244         len += retval;
245         bool full = len == (sizeof(buffer) - 1);
246         char* ep = buffer + len;
247         *ep = '\0';
248         ssize_t sublen;
249         for (char *ptr = nullptr, *tok = buffer;
250              !!(tok = android::log_strntok_r(tok, len, ptr, sublen));
251              tok = nullptr) {
252             if (((tok + sublen) >= ep) && (retval != 0) && full) {
253                 if (sublen > 0) memmove(buffer, tok, sublen);
254                 len = sublen;
255                 break;
256             }
257             if ((sublen > 0) && *tok) {
258                 log(tok, sublen);
259             }
260         }
261     }
262 
263     return true;
264 }
265 
calculateCorrection(const log_time & monotonic,const char * real_string,ssize_t len)266 void LogKlog::calculateCorrection(const log_time& monotonic,
267                                   const char* real_string, ssize_t len) {
268     static const char real_format[] = "%Y-%m-%d %H:%M:%S.%09q UTC";
269     if (len < (ssize_t)(strlen(real_format) + 5)) return;
270 
271     log_time real;
272     const char* ep = real.strptime(real_string, real_format);
273     if (!ep || (ep > &real_string[len]) || (real > log_time(CLOCK_REALTIME))) {
274         return;
275     }
276     // kernel report UTC, log_time::strptime is localtime from calendar.
277     // Bionic and liblog strptime does not support %z or %Z to pick up
278     // timezone so we are calculating our own correction.
279     time_t now = real.tv_sec;
280     struct tm tm;
281     memset(&tm, 0, sizeof(tm));
282     tm.tm_isdst = -1;
283     localtime_r(&now, &tm);
284     if ((tm.tm_gmtoff < 0) && ((-tm.tm_gmtoff) > (long)real.tv_sec)) {
285         real = log_time::EPOCH;
286     } else {
287         real.tv_sec += tm.tm_gmtoff;
288     }
289     if (monotonic > real) {
290         correction = log_time::EPOCH;
291     } else {
292         correction = real - monotonic;
293     }
294 }
295 
sniffTime(log_time & now,const char * & buf,ssize_t len,bool reverse)296 void LogKlog::sniffTime(log_time& now, const char*& buf, ssize_t len,
297                         bool reverse) {
298     if (len <= 0) return;
299 
300     const char* cp = nullptr;
301     if ((len > 10) && (*buf == '[')) {
302         cp = now.strptime(buf, "[ %s.%q]");  // can index beyond buffer bounds
303         if (cp && (cp > &buf[len - 1])) cp = nullptr;
304     }
305     if (cp) {
306         len -= cp - buf;
307         if ((len > 0) && isspace(*cp)) {
308             ++cp;
309             --len;
310         }
311         buf = cp;
312 
313         if (isMonotonic()) return;
314 
315         const char* b;
316         if (((b = android::strnstr(cp, len, suspendStr))) &&
317             (((b += strlen(suspendStr)) - cp) < len)) {
318             len -= b - cp;
319             calculateCorrection(now, b, len);
320         } else if (((b = android::strnstr(cp, len, resumeStr))) &&
321                    (((b += strlen(resumeStr)) - cp) < len)) {
322             len -= b - cp;
323             calculateCorrection(now, b, len);
324         } else if (((b = android::strnstr(cp, len, healthdStr))) &&
325                    (((b += strlen(healthdStr)) - cp) < len) &&
326                    ((b = android::strnstr(b, len -= b - cp, batteryStr))) &&
327                    (((b += strlen(batteryStr)) - cp) < len)) {
328             // NB: healthd is roughly 150us late, so we use it instead to
329             //     trigger a check for ntp-induced or hardware clock drift.
330             log_time real(CLOCK_REALTIME);
331             log_time mono(CLOCK_MONOTONIC);
332             correction = (real < mono) ? log_time::EPOCH : (real - mono);
333         } else if (((b = android::strnstr(cp, len, suspendedStr))) &&
334                    (((b += strlen(suspendStr)) - cp) < len)) {
335             len -= b - cp;
336             log_time real;
337             char* endp;
338             real.tv_sec = strtol(b, &endp, 10);
339             if ((*endp == '.') && ((endp - b) < len)) {
340                 unsigned long multiplier = NS_PER_SEC;
341                 real.tv_nsec = 0;
342                 len -= endp - b;
343                 while (--len && isdigit(*++endp) && (multiplier /= 10)) {
344                     real.tv_nsec += (*endp - '0') * multiplier;
345                 }
346                 if (reverse) {
347                     if (real > correction) {
348                         correction = log_time::EPOCH;
349                     } else {
350                         correction -= real;
351                     }
352                 } else {
353                     correction += real;
354                 }
355             }
356         }
357 
358         convertMonotonicToReal(now);
359     } else {
360         if (isMonotonic()) {
361             now = log_time(CLOCK_MONOTONIC);
362         } else {
363             now = log_time(CLOCK_REALTIME);
364         }
365     }
366 }
367 
sniffPid(const char * & buf,ssize_t len)368 pid_t LogKlog::sniffPid(const char*& buf, ssize_t len) {
369     if (len <= 0) return 0;
370 
371     const char* cp = buf;
372     // sscanf does a strlen, let's check if the string is not nul terminated.
373     // pseudo out-of-bounds access since we always have an extra char on buffer.
374     if (((ssize_t)strnlen(cp, len) == len) && cp[len]) {
375         return 0;
376     }
377     // HTC kernels with modified printk "c0   1648 "
378     if ((len > 9) && (cp[0] == 'c') && isdigit(cp[1]) &&
379         (isdigit(cp[2]) || (cp[2] == ' ')) && (cp[3] == ' ')) {
380         bool gotDigit = false;
381         int i;
382         for (i = 4; i < 9; ++i) {
383             if (isdigit(cp[i])) {
384                 gotDigit = true;
385             } else if (gotDigit || (cp[i] != ' ')) {
386                 break;
387             }
388         }
389         if ((i == 9) && (cp[i] == ' ')) {
390             int pid = 0;
391             char dummy;
392             if (sscanf(cp + 4, "%d%c", &pid, &dummy) == 2) {
393                 buf = cp + 10;  // skip-it-all
394                 return pid;
395             }
396         }
397     }
398     while (len) {
399         // Mediatek kernels with modified printk
400         if (*cp == '[') {
401             int pid = 0;
402             char dummy;
403             if (sscanf(cp, "[%d:%*[a-z_./0-9:A-Z]]%c", &pid, &dummy) == 2) {
404                 return pid;
405             }
406             break;  // Only the first one
407         }
408         ++cp;
409         --len;
410     }
411     return 0;
412 }
413 
414 // kernel log prefix, convert to a kernel log priority number
parseKernelPrio(const char * & buf,ssize_t len)415 static int parseKernelPrio(const char*& buf, ssize_t len) {
416     int pri = LOG_USER | LOG_INFO;
417     const char* cp = buf;
418     if ((len > 0) && (*cp == '<')) {
419         pri = 0;
420         while (--len && isdigit(*++cp)) {
421             pri = (pri * 10) + *cp - '0';
422         }
423         if ((len > 0) && (*cp == '>')) {
424             ++cp;
425         } else {
426             cp = buf;
427             pri = LOG_USER | LOG_INFO;
428         }
429         buf = cp;
430     }
431     return pri;
432 }
433 
434 // Passed the entire SYSLOG_ACTION_READ_ALL buffer and interpret a
435 // compensated start time.
synchronize(const char * buf,ssize_t len)436 void LogKlog::synchronize(const char* buf, ssize_t len) {
437     const char* cp = android::strnstr(buf, len, suspendStr);
438     if (!cp) {
439         cp = android::strnstr(buf, len, resumeStr);
440         if (!cp) return;
441     } else {
442         const char* rp = android::strnstr(buf, len, resumeStr);
443         if (rp && (rp < cp)) cp = rp;
444     }
445 
446     do {
447         --cp;
448     } while ((cp > buf) && (*cp != '\n'));
449     if (*cp == '\n') {
450         ++cp;
451     }
452     parseKernelPrio(cp, len - (cp - buf));
453 
454     log_time now;
455     sniffTime(now, cp, len - (cp - buf), true);
456 
457     const char* suspended = android::strnstr(buf, len, suspendedStr);
458     if (!suspended || (suspended > cp)) {
459         return;
460     }
461     cp = suspended;
462 
463     do {
464         --cp;
465     } while ((cp > buf) && (*cp != '\n'));
466     if (*cp == '\n') {
467         ++cp;
468     }
469     parseKernelPrio(cp, len - (cp - buf));
470 
471     sniffTime(now, cp, len - (cp - buf), true);
472 }
473 
474 // Convert kernel log priority number into an Android Logger priority number
convertKernelPrioToAndroidPrio(int pri)475 static int convertKernelPrioToAndroidPrio(int pri) {
476     switch (pri & LOG_PRIMASK) {
477         case LOG_EMERG:
478         // FALLTHRU
479         case LOG_ALERT:
480         // FALLTHRU
481         case LOG_CRIT:
482             return ANDROID_LOG_FATAL;
483 
484         case LOG_ERR:
485             return ANDROID_LOG_ERROR;
486 
487         case LOG_WARNING:
488             return ANDROID_LOG_WARN;
489 
490         default:
491         // FALLTHRU
492         case LOG_NOTICE:
493         // FALLTHRU
494         case LOG_INFO:
495             break;
496 
497         case LOG_DEBUG:
498             return ANDROID_LOG_DEBUG;
499     }
500 
501     return ANDROID_LOG_INFO;
502 }
503 
strnrchr(const char * s,ssize_t len,char c)504 static const char* strnrchr(const char* s, ssize_t len, char c) {
505     const char* save = nullptr;
506     for (; len > 0; ++s, len--) {
507         if (*s == c) {
508             save = s;
509         }
510     }
511     return save;
512 }
513 
514 //
515 // log a message into the kernel log buffer
516 //
517 // Filter rules to parse <PRI> <TIME> <tag> and <message> in order for
518 // them to appear correct in the logcat output:
519 //
520 // LOG_KERN (0):
521 // <PRI>[<TIME>] <tag> ":" <message>
522 // <PRI>[<TIME>] <tag> <tag> ":" <message>
523 // <PRI>[<TIME>] <tag> <tag>_work ":" <message>
524 // <PRI>[<TIME>] <tag> '<tag>.<num>' ":" <message>
525 // <PRI>[<TIME>] <tag> '<tag><num>' ":" <message>
526 // <PRI>[<TIME>] <tag>_host '<tag>.<num>' ":" <message>
527 // (unimplemented) <PRI>[<TIME>] <tag> '<num>.<tag>' ":" <message>
528 // <PRI>[<TIME>] "[INFO]"<tag> : <message>
529 // <PRI>[<TIME>] "------------[ cut here ]------------"   (?)
530 // <PRI>[<TIME>] "---[ end trace 3225a3070ca3e4ac ]---"   (?)
531 // LOG_USER, LOG_MAIL, LOG_DAEMON, LOG_AUTH, LOG_SYSLOG, LOG_LPR, LOG_NEWS
532 // LOG_UUCP, LOG_CRON, LOG_AUTHPRIV, LOG_FTP:
533 // <PRI+TAG>[<TIME>] (see sys/syslog.h)
534 // Observe:
535 //  Minimum tag length = 3   NB: drops things like r5:c00bbadf, but allow PM:
536 //  Maximum tag words = 2
537 //  Maximum tag length = 16  NB: we are thinking of how ugly logcat can get.
538 //  Not a Tag if there is no message content.
539 //  leading additional spaces means no tag, inherit last tag.
540 //  Not a Tag if <tag>: is "ERROR:", "WARNING:", "INFO:" or "CPU:"
541 // Drop:
542 //  empty messages
543 //  messages with ' audit(' in them if auditd is running
544 //  logd.klogd:
545 // return -1 if message logd.klogd: <signature>
546 //
log(const char * buf,ssize_t len)547 int LogKlog::log(const char* buf, ssize_t len) {
548     if (auditd && android::strnstr(buf, len, auditStr)) {
549         return 0;
550     }
551 
552     const char* p = buf;
553     int pri = parseKernelPrio(p, len);
554 
555     log_time now;
556     sniffTime(now, p, len - (p - buf), false);
557 
558     // sniff for start marker
559     const char* start = android::strnstr(p, len - (p - buf), klogdStr);
560     if (start) {
561         uint64_t sig = strtoll(start + strlen(klogdStr), nullptr, 10);
562         if (sig == signature.nsec()) {
563             if (initialized) {
564                 enableLogging = true;
565             } else {
566                 enableLogging = false;
567             }
568             return -1;
569         }
570         return 0;
571     }
572 
573     if (!enableLogging) {
574         return 0;
575     }
576 
577     // Parse pid, tid and uid
578     const pid_t pid = sniffPid(p, len - (p - buf));
579     const pid_t tid = pid;
580     uid_t uid = AID_ROOT;
581     if (pid) {
582         logbuf->lock();
583         uid = logbuf->pidToUid(pid);
584         logbuf->unlock();
585     }
586 
587     // Parse (rules at top) to pull out a tag from the incoming kernel message.
588     // Some may view the following as an ugly heuristic, the desire is to
589     // beautify the kernel logs into an Android Logging format; the goal is
590     // admirable but costly.
591     while ((p < &buf[len]) && (isspace(*p) || !*p)) {
592         ++p;
593     }
594     if (p >= &buf[len]) {  // timestamp, no content
595         return 0;
596     }
597     start = p;
598     const char* tag = "";
599     const char* etag = tag;
600     ssize_t taglen = len - (p - buf);
601     const char* bt = p;
602 
603     static const char infoBrace[] = "[INFO]";
604     static const ssize_t infoBraceLen = strlen(infoBrace);
605     if ((taglen >= infoBraceLen) &&
606         !fastcmp<strncmp>(p, infoBrace, infoBraceLen)) {
607         // <PRI>[<TIME>] "[INFO]"<tag> ":" message
608         bt = p + infoBraceLen;
609         taglen -= infoBraceLen;
610     }
611 
612     const char* et;
613     for (et = bt; (taglen > 0) && *et && (*et != ':') && !isspace(*et);
614          ++et, --taglen) {
615         // skip ':' within [ ... ]
616         if (*et == '[') {
617             while ((taglen > 0) && *et && *et != ']') {
618                 ++et;
619                 --taglen;
620             }
621             if (taglen <= 0) {
622                 break;
623             }
624         }
625     }
626     const char* cp;
627     for (cp = et; (taglen > 0) && isspace(*cp); ++cp, --taglen) {
628     }
629 
630     // Validate tag
631     ssize_t size = et - bt;
632     if ((taglen > 0) && (size > 0)) {
633         if (*cp == ':') {
634             // ToDo: handle case insensitive colon separated logging stutter:
635             //       <tag> : <tag>: ...
636 
637             // One Word
638             tag = bt;
639             etag = et;
640             p = cp + 1;
641         } else if ((taglen > size) && (tolower(*bt) == tolower(*cp))) {
642             // clean up any tag stutter
643             if (!fastcmp<strncasecmp>(bt + 1, cp + 1, size - 1)) {  // no match
644                 // <PRI>[<TIME>] <tag> <tag> : message
645                 // <PRI>[<TIME>] <tag> <tag>: message
646                 // <PRI>[<TIME>] <tag> '<tag>.<num>' : message
647                 // <PRI>[<TIME>] <tag> '<tag><num>' : message
648                 // <PRI>[<TIME>] <tag> '<tag><stuff>' : message
649                 const char* b = cp;
650                 cp += size;
651                 taglen -= size;
652                 while ((--taglen > 0) && !isspace(*++cp) && (*cp != ':')) {
653                 }
654                 const char* e;
655                 for (e = cp; (taglen > 0) && isspace(*cp); ++cp, --taglen) {
656                 }
657                 if ((taglen > 0) && (*cp == ':')) {
658                     tag = b;
659                     etag = e;
660                     p = cp + 1;
661                 }
662             } else {
663                 // what about <PRI>[<TIME>] <tag>_host '<tag><stuff>' : message
664                 static const char host[] = "_host";
665                 static const ssize_t hostlen = strlen(host);
666                 if ((size > hostlen) &&
667                     !fastcmp<strncmp>(bt + size - hostlen, host, hostlen) &&
668                     !fastcmp<strncmp>(bt + 1, cp + 1, size - hostlen - 1)) {
669                     const char* b = cp;
670                     cp += size - hostlen;
671                     taglen -= size - hostlen;
672                     if (*cp == '.') {
673                         while ((--taglen > 0) && !isspace(*++cp) &&
674                                (*cp != ':')) {
675                         }
676                         const char* e;
677                         for (e = cp; (taglen > 0) && isspace(*cp);
678                              ++cp, --taglen) {
679                         }
680                         if ((taglen > 0) && (*cp == ':')) {
681                             tag = b;
682                             etag = e;
683                             p = cp + 1;
684                         }
685                     }
686                 } else {
687                     goto twoWord;
688                 }
689             }
690         } else {
691         // <PRI>[<TIME>] <tag> <stuff>' : message
692         twoWord:
693             while ((--taglen > 0) && !isspace(*++cp) && (*cp != ':')) {
694             }
695             const char* e;
696             for (e = cp; (taglen > 0) && isspace(*cp); ++cp, --taglen) {
697             }
698             // Two words
699             if ((taglen > 0) && (*cp == ':')) {
700                 tag = bt;
701                 etag = e;
702                 p = cp + 1;
703             }
704         }
705     }  // else no tag
706 
707     static const char cpu[] = "CPU";
708     static const ssize_t cpuLen = strlen(cpu);
709     static const char warning[] = "WARNING";
710     static const ssize_t warningLen = strlen(warning);
711     static const char error[] = "ERROR";
712     static const ssize_t errorLen = strlen(error);
713     static const char info[] = "INFO";
714     static const ssize_t infoLen = strlen(info);
715 
716     size = etag - tag;
717     if ((size <= 1) ||
718         // register names like x9
719         ((size == 2) && (isdigit(tag[0]) || isdigit(tag[1]))) ||
720         // register names like x18 but not driver names like en0
721         ((size == 3) && (isdigit(tag[1]) && isdigit(tag[2]))) ||
722         // blacklist
723         ((size == cpuLen) && !fastcmp<strncmp>(tag, cpu, cpuLen)) ||
724         ((size == warningLen) &&
725          !fastcmp<strncasecmp>(tag, warning, warningLen)) ||
726         ((size == errorLen) && !fastcmp<strncasecmp>(tag, error, errorLen)) ||
727         ((size == infoLen) && !fastcmp<strncasecmp>(tag, info, infoLen))) {
728         p = start;
729         etag = tag = "";
730     }
731 
732     // Suppress additional stutter in tag:
733     //   eg: [143:healthd]healthd -> [143:healthd]
734     taglen = etag - tag;
735     // Mediatek-special printk induced stutter
736     const char* mp = strnrchr(tag, taglen, ']');
737     if (mp && (++mp < etag)) {
738         ssize_t s = etag - mp;
739         if (((s + s) < taglen) && !fastcmp<memcmp>(mp, mp - 1 - s, s)) {
740             taglen = mp - tag;
741         }
742     }
743     // Deal with sloppy and simplistic harmless p = cp + 1 etc above.
744     if (len < (p - buf)) {
745         p = &buf[len];
746     }
747     // skip leading space
748     while ((p < &buf[len]) && (isspace(*p) || !*p)) {
749         ++p;
750     }
751     // truncate trailing space or nuls
752     ssize_t b = len - (p - buf);
753     while ((b > 0) && (isspace(p[b - 1]) || !p[b - 1])) {
754         --b;
755     }
756     // trick ... allow tag with empty content to be logged. log() drops empty
757     if ((b <= 0) && (taglen > 0)) {
758         p = " ";
759         b = 1;
760     }
761     // paranoid sanity check, can not happen ...
762     if (b > LOGGER_ENTRY_MAX_PAYLOAD) {
763         b = LOGGER_ENTRY_MAX_PAYLOAD;
764     }
765     if (taglen > LOGGER_ENTRY_MAX_PAYLOAD) {
766         taglen = LOGGER_ENTRY_MAX_PAYLOAD;
767     }
768     // calculate buffer copy requirements
769     ssize_t n = 1 + taglen + 1 + b + 1;
770     // paranoid sanity check, first two just can not happen ...
771     if ((taglen > n) || (b > n) || (n > (ssize_t)USHRT_MAX) || (n <= 0)) {
772         return -EINVAL;
773     }
774 
775     // Careful.
776     // We are using the stack to house the log buffer for speed reasons.
777     // If we malloc'd this buffer, we could get away without n's USHRT_MAX
778     // test above, but we would then required a max(n, USHRT_MAX) as
779     // truncating length argument to logbuf->log() below. Gain is protection
780     // of stack sanity and speedup, loss is truncated long-line content.
781     char newstr[n];
782     char* np = newstr;
783 
784     // Convert priority into single-byte Android logger priority
785     *np = convertKernelPrioToAndroidPrio(pri);
786     ++np;
787 
788     // Copy parsed tag following priority
789     memcpy(np, tag, taglen);
790     np += taglen;
791     *np = '\0';
792     ++np;
793 
794     // Copy main message to the remainder
795     memcpy(np, p, b);
796     np[b] = '\0';
797 
798     if (!isMonotonic()) {
799         // Watch out for singular race conditions with timezone causing near
800         // integer quarter-hour jumps in the time and compensate accordingly.
801         // Entries will be temporal within near_seconds * 2. b/21868540
802         static uint32_t vote_time[3];
803         vote_time[2] = vote_time[1];
804         vote_time[1] = vote_time[0];
805         vote_time[0] = now.tv_sec;
806 
807         if (vote_time[1] && vote_time[2]) {
808             static const unsigned near_seconds = 10;
809             static const unsigned timezones_seconds = 900;
810             int diff0 = (vote_time[0] - vote_time[1]) / near_seconds;
811             unsigned abs0 = (diff0 < 0) ? -diff0 : diff0;
812             int diff1 = (vote_time[1] - vote_time[2]) / near_seconds;
813             unsigned abs1 = (diff1 < 0) ? -diff1 : diff1;
814             if ((abs1 <= 1) &&  // last two were in agreement on timezone
815                 ((abs0 + 1) % (timezones_seconds / near_seconds)) <= 2) {
816                 abs0 = (abs0 + 1) / (timezones_seconds / near_seconds) *
817                        timezones_seconds;
818                 now.tv_sec -= (diff0 < 0) ? -abs0 : abs0;
819             }
820         }
821     }
822 
823     // Log message
824     int rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr,
825                          (unsigned short)n);
826 
827     // notify readers
828     if (!rc) {
829         reader->notifyNewLog();
830     }
831 
832     return rc;
833 }
834