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