Esempio n. 1
0
//
// 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, size_t len) {
    if (auditd && strnstr(buf, len, " audit(")) {
        return 0;
    }

    const char *p = buf;
    int pri = parseKernelPrio(&p, len);

    log_time now;
    sniffTime(now, &p, len - (p - buf), false);

    // sniff for start marker
    const char klogd_message[] = "logd.klogd: ";
    const char *start = strnstr(p, len - (p - buf), klogd_message);
    if (start) {
        uint64_t sig = strtoll(start + sizeof(klogd_message) - 1, NULL, 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;
    const uid_t uid = pid ? logbuf->pidToUid(pid) : 0;

    // 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;
    size_t taglen = len - (p - buf);
    if (!isspace(*p) && *p) {
        const char *bt, *et, *cp;

        bt = p;
        if ((taglen >= 6) && !fast<strncmp>(p, "[INFO]", 6)) {
            // <PRI>[<TIME>] "[INFO]"<tag> ":" message
            bt = p + 6;
            taglen -= 6;
        }
        for(et = bt; taglen && *et && (*et != ':') && !isspace(*et); ++et, --taglen) {
           // skip ':' within [ ... ]
           if (*et == '[') {
               while (taglen && *et && *et != ']') {
                   ++et;
                   --taglen;
               }
            }
        }
        for(cp = et; taglen && isspace(*cp); ++cp, --taglen);
        size_t size;

        if (*cp == ':') {
            // One Word
            tag = bt;
            etag = et;
            p = cp + 1;
        } else if (taglen) {
            size = et - bt;
            if ((taglen > size) &&   // enough space for match plus trailing :
                    (*bt == *cp) &&  // ubber fast<strncmp> pair
                    fast<strncmp>(bt + 1, cp + 1, size - 1)) {
                // <PRI>[<TIME>] <tag>_host '<tag>.<num>' : message
                if (!fast<strncmp>(bt + size - 5, "_host", 5)
                        && !fast<strncmp>(bt + 1, cp + 1, size - 6)) {
                    const char *b = cp;
                    cp += size - 5;
                    taglen -= size - 5;
                    if (*cp == '.') {
                        while (--taglen && !isspace(*++cp) && (*cp != ':'));
                        const char *e;
                        for(e = cp; taglen && isspace(*cp); ++cp, --taglen);
                        if (*cp == ':') {
                            tag = b;
                            etag = e;
                            p = cp + 1;
                        }
                    }
                } else {
                    while (--taglen && !isspace(*++cp) && (*cp != ':'));
                    const char *e;
                    for(e = cp; taglen && isspace(*cp); ++cp, --taglen);
                    // Two words
                    if (*cp == ':') {
                        tag = bt;
                        etag = e;
                        p = cp + 1;
                    }
                }
            } else if (isspace(cp[size])) {
                cp += size;
                taglen -= size;
                while (--taglen && isspace(*++cp));
                // <PRI>[<TIME>] <tag> <tag> : message
                if (*cp == ':') {
                    tag = bt;
                    etag = et;
                    p = cp + 1;
                }
            } else if (cp[size] == ':') {
                // <PRI>[<TIME>] <tag> <tag> : message
                tag = bt;
                etag = et;
                p = cp + size + 1;
            } else if ((cp[size] == '.') || isdigit(cp[size])) {
                // <PRI>[<TIME>] <tag> '<tag>.<num>' : message
                // <PRI>[<TIME>] <tag> '<tag><num>' : message
                const char *b = cp;
                cp += size;
                taglen -= size;
                while (--taglen && !isspace(*++cp) && (*cp != ':'));
                const char *e = cp;
                while (taglen && isspace(*cp)) {
                    ++cp;
                    --taglen;
                }
                if (*cp == ':') {
                    tag = b;
                    etag = e;
                    p = cp + 1;
                }
            } else {
                while (--taglen && !isspace(*++cp) && (*cp != ':'));
                const char *e = cp;
                while (taglen && isspace(*cp)) {
                    ++cp;
                    --taglen;
                }
                // Two words
                if (*cp == ':') {
                    tag = bt;
                    etag = e;
                    p = cp + 1;
                }
            }
        } /* else no tag */
        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 == 3) && !fast<strncmp>(tag, "CPU", 3))
                || ((size == 7) && !fast<strncasecmp>(tag, "WARNING", 7))
                || ((size == 5) && !fast<strncasecmp>(tag, "ERROR", 5))
                || ((size == 4) && !fast<strncasecmp>(tag, "INFO", 4))) {
            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)) {
        size_t s = etag - mp;
        if (((s + s) < taglen) && !fast<memcmp>(mp, mp - 1 - s, s)) {
            taglen = mp - tag;
        }
    }
    // Deal with sloppy and simplistic harmless p = cp + 1 etc above.
    if (len < (size_t)(p - buf)) {
        p = &buf[len];
    }
    // skip leading space
    while ((p < &buf[len]) && (isspace(*p) || !*p)) {
        ++p;
    }
    // truncate trailing space or nuls
    size_t b = len - (p - buf);
    while (b && (isspace(p[b-1]) || !p[b-1])) {
        --b;
    }
    // trick ... allow tag with empty content to be logged. log() drops empty
    if (!b && taglen) {
        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
    size_t n = 1 + taglen + 1 + b + 1;
    // paranoid sanity check, first two just can not happen ...
    if ((taglen > n) || (b > n) || (n > USHRT_MAX)) {
        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,
                         (unsigned short) n);

    // notify readers
    if (!rc) {
        reader->notifyNewLog();
    }

    return rc;
}
//
// 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, size_t len) {
    if (auditd && strnstr(buf, len, " audit(")) {
        return 0;
    }

    const char *p = buf;
    int pri = parseKernelPrio(&p, len);

    log_time now;
    sniffTime(now, &p, len - (p - buf), false);

    // sniff for start marker
    const char klogd_message[] = "logd.klogd: ";
    const char *start = strnstr(p, len - (p - buf), klogd_message);
    if (start) {
        uint64_t sig = strtoll(start + sizeof(klogd_message) - 1, NULL, 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;
    const uid_t uid = pid ? logbuf->pidToUid(pid) : 0;

    // 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 ((isspace(*p) || !*p) && (p < &buf[len])) {
        ++p;
    }
    if (p >= &buf[len]) { // timestamp, no content
        return 0;
    }
    start = p;
    const char *tag = "";
    const char *etag = tag;
    size_t taglen = len - (p - buf);
    if (!isspace(*p) && *p) {
        const char *bt, *et, *cp;

        bt = p;
        if (!strncmp(p, "[INFO]", 6)) {
            // <PRI>[<TIME>] "[INFO]"<tag> ":" message
            bt = p + 6;
            taglen -= 6;
        }
        for(et = bt; taglen && *et && (*et != ':') && !isspace(*et); ++et, --taglen) {
           // skip ':' within [ ... ]
           if (*et == '[') {
               while (taglen && *et && *et != ']') {
                   ++et;
                   --taglen;
               }
            }
        }
        for(cp = et; taglen && isspace(*cp); ++cp, --taglen);
        size_t size;

        if (*cp == ':') {
            // One Word
            tag = bt;
            etag = et;
            p = cp + 1;
        } else if (taglen) {
            size = et - bt;
            if (strncmp(bt, cp, size)) {
                // <PRI>[<TIME>] <tag>_host '<tag>.<num>' : message
                if (!strncmp(bt + size - 5, "_host", 5)
                        && !strncmp(bt, cp, size - 5)) {
                    const char *b = cp;
                    cp += size - 5;
                    taglen -= size - 5;
                    if (*cp == '.') {
                        while (--taglen && !isspace(*++cp) && (*cp != ':'));
                        const char *e;
                        for(e = cp; taglen && isspace(*cp); ++cp, --taglen);
                        if (*cp == ':') {
                            tag = b;
                            etag = e;
                            p = cp + 1;
                        }
                    }
                } else {
                    while (--taglen && !isspace(*++cp) && (*cp != ':'));
                    const char *e;
                    for(e = cp; taglen && isspace(*cp); ++cp, --taglen);
                    // Two words
                    if (*cp == ':') {
                        tag = bt;
                        etag = e;
                        p = cp + 1;
                    }
                }
            } else if (isspace(cp[size])) {
                cp += size;
                taglen -= size;
                while (--taglen && isspace(*++cp));
                // <PRI>[<TIME>] <tag> <tag> : message
                if (*cp == ':') {
                    tag = bt;
                    etag = et;
                    p = cp + 1;
                }
            } else if (cp[size] == ':') {
                // <PRI>[<TIME>] <tag> <tag> : message
                tag = bt;
                etag = et;
                p = cp + size + 1;
            } else if ((cp[size] == '.') || isdigit(cp[size])) {
                // <PRI>[<TIME>] <tag> '<tag>.<num>' : message
                // <PRI>[<TIME>] <tag> '<tag><num>' : message
                const char *b = cp;
                cp += size;
                taglen -= size;
                while (--taglen && !isspace(*++cp) && (*cp != ':'));
                const char *e = cp;
                while (taglen && isspace(*cp)) {
                    ++cp;
                    --taglen;
                }
                if (*cp == ':') {
                    tag = b;
                    etag = e;
                    p = cp + 1;
                }
            } else {
                while (--taglen && !isspace(*++cp) && (*cp != ':'));
                const char *e = cp;
                while (taglen && isspace(*cp)) {
                    ++cp;
                    --taglen;
                }
                // Two words
                if (*cp == ':') {
                    tag = bt;
                    etag = e;
                    p = cp + 1;
                }
            }
        }
        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 == 3) && !strncmp(tag, "CPU", 3))
                || ((size == 7) && !strncasecmp(tag, "WARNING", 7))
                || ((size == 5) && !strncasecmp(tag, "ERROR", 5))
                || ((size == 4) && !strncasecmp(tag, "INFO", 4))) {
            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)) {
        size_t s = etag - mp;
        if (((s + s) < taglen) && !memcmp(mp, mp - 1 - s, s)) {
            taglen = mp - tag;
        }
    }
    // skip leading space
    while ((isspace(*p) || !*p) && (p < &buf[len])) {
        ++p;
    }
    // truncate trailing space or nuls
    size_t b = len - (p - buf);
    while (b && (isspace(p[b-1]) || !p[b-1])) {
        --b;
    }
    // trick ... allow tag with empty content to be logged. log() drops empty
    if (!b && taglen) {
        p = " ";
        b = 1;
    }
    size_t n = 1 + taglen + 1 + b + 1;
    int rc = n;
    if ((taglen > n) || (b > n)) { // Can not happen ...
        rc = -EINVAL;
        return rc;
    }

    // Allocate a buffer to hold the interpreted log message
    char *newstr = reinterpret_cast<char *>(malloc(n));
    if (!newstr) {
        rc = -ENOMEM;
        return rc;
    }
    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';

    // Log message
    rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr,
                     (n <= USHRT_MAX) ? (unsigned short) n : USHRT_MAX);
    free(newstr);

    // notify readers
    if (!rc) {
        reader->notifyNewLog();
    }

    return rc;
}
Esempio n. 3
0
//
// 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(now, 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,
                         (unsigned short)n);

    // notify readers
    if (!rc) {
        reader->notifyNewLog();
    }

    return rc;
}
Esempio n. 4
0
//
// 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) {
    if (auditd && strstr(buf, " audit(")) {
        return 0;
    }

    int pri = parseKernelPrio(&buf);

    log_time now;
    sniffTime(now, &buf, false);

    // sniff for start marker
    const char klogd_message[] = "logd.klogd: ";
    if (!strncmp(buf, klogd_message, sizeof(klogd_message) - 1)) {
        char *endp;
        uint64_t sig = strtoll(buf + sizeof(klogd_message) - 1, &endp, 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 (not possible)
    const pid_t pid = 0;
    const pid_t tid = 0;
    const uid_t uid = 0;

    // 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 (isspace(*buf)) {
        ++buf;
    }
    if (!*buf) {
        return 0;
    }
    const char *start = buf;
    const char *tag = "";
    const char *etag = tag;
    if (!isspace(*buf)) {
        const char *bt, *et, *cp;

        bt = buf;
        if (!strncmp(buf, "[INFO]", 6)) {
            // <PRI>[<TIME>] "[INFO]"<tag> ":" message
            bt = buf + 6;
        }
        for(et = bt; *et && (*et != ':') && !isspace(*et); ++et);
        for(cp = et; isspace(*cp); ++cp);
        size_t size;

        if (*cp == ':') {
            // One Word
            tag = bt;
            etag = et;
            buf = cp + 1;
        } else {
            size = et - bt;
            if (strncmp(bt, cp, size)) {
                // <PRI>[<TIME>] <tag>_host '<tag>.<num>' : message
                if (!strncmp(bt + size - 5, "_host", 5)
                        && !strncmp(bt, cp, size - 5)) {
                    const char *b = cp;
                    cp += size - 5;
                    if (*cp == '.') {
                        while (!isspace(*++cp) && (*cp != ':'));
                        const char *e;
                        for(e = cp; isspace(*cp); ++cp);
                        if (*cp == ':') {
                            tag = b;
                            etag = e;
                            buf = cp + 1;
                        }
                    }
                } else {
                    while (!isspace(*++cp) && (*cp != ':'));
                    const char *e;
                    for(e = cp; isspace(*cp); ++cp);
                    // Two words
                    if (*cp == ':') {
                        tag = bt;
                        etag = e;
                        buf = cp + 1;
                    }
                }
            } else if (isspace(cp[size])) {
                cp += size;
                while (isspace(*++cp));
                // <PRI>[<TIME>] <tag> <tag> : message
                if (*cp == ':') {
                    tag = bt;
                    etag = et;
                    buf = cp + 1;
                }
            } else if (cp[size] == ':') {
                // <PRI>[<TIME>] <tag> <tag> : message
                tag = bt;
                etag = et;
                buf = cp + size + 1;
            } else if ((cp[size] == '.') || isdigit(cp[size])) {
                // <PRI>[<TIME>] <tag> '<tag>.<num>' : message
                // <PRI>[<TIME>] <tag> '<tag><num>' : message
                const char *b = cp;
                cp += size;
                while (!isspace(*++cp) && (*cp != ':'));
                const char *e = cp;
                while (isspace(*cp)) {
                    ++cp;
                }
                if (*cp == ':') {
                    tag = b;
                    etag = e;
                    buf = cp + 1;
                }
            } else {
                while (!isspace(*++cp) && (*cp != ':'));
                const char *e = cp;
                while (isspace(*cp)) {
                    ++cp;
                }
                // Two words
                if (*cp == ':') {
                    tag = bt;
                    etag = e;
                    buf = cp + 1;
                }
            }
        }
        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 == 3) && !strncmp(tag, "CPU", 3))
                || ((size == 7) && !strncmp(tag, "WARNING", 7))
                || ((size == 5) && !strncmp(tag, "ERROR", 5))
                || ((size == 4) && !strncmp(tag, "INFO", 4))) {
            buf = start;
            etag = tag = "";
        }
    }
    size_t l = etag - tag;
    // skip leading space
    while (isspace(*buf)) {
        ++buf;
    }
    // truncate trailing space
    size_t b = strlen(buf);
    while (b && isspace(buf[b-1])) {
        --b;
    }
    // trick ... allow tag with empty content to be logged. log() drops empty
    if (!b && l) {
        buf = " ";
        b = 1;
    }
    size_t n = 1 + l + 1 + b + 1;

    // Allocate a buffer to hold the interpreted log message
    int rc = n;
    char *newstr = reinterpret_cast<char *>(malloc(n));
    if (!newstr) {
        rc = -ENOMEM;
        return rc;
    }
    char *np = newstr;

    // Convert priority into single-byte Android logger priority
    *np = convertKernelPrioToAndroidPrio(pri);
    ++np;

    // Copy parsed tag following priority
    strncpy(np, tag, l);
    np += l;
    *np = '\0';
    ++np;

    // Copy main message to the remainder
    strncpy(np, buf, b);
    np[b] = '\0';

    // Log message
    rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr,
                     (n <= USHRT_MAX) ? (unsigned short) n : USHRT_MAX);
    free(newstr);

    // notify readers
    if (!rc) {
        reader->notifyNewLog();
    }

    return rc;
}