Home | History | Annotate | Download | only in logd 
      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 <endian.h>
     19 #include <errno.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 <android-base/macros.h>
     29 #include <private/android_filesystem_config.h>
     30 #include <private/android_logger.h>
     31 
     32 #include "LogAudit.h"
     33 #include "LogBuffer.h"
     34 #include "LogKlog.h"
     35 #include "LogReader.h"
     36 #include "LogUtils.h"
     37 #include "libaudit.h"
     38 
     39 #define KMSG_PRIORITY(PRI)                               \
     40     '<', '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) / 10, \
     41         '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) % 10, '>'
     42 
     43 LogAudit::LogAudit(LogBuffer* buf, LogReader* reader, int fdDmesg)
     44     : SocketListener(mSock = getLogSocket(), false),
     45       logbuf(buf),
     46       reader(reader),
     47       fdDmesg(fdDmesg),
     48       main(__android_logger_property_get_bool("ro.logd.auditd.main",
     49                                               BOOL_DEFAULT_TRUE)),
     50       events(__android_logger_property_get_bool("ro.logd.auditd.events",
     51                                                 BOOL_DEFAULT_TRUE)),
     52       initialized(false),
     53       tooFast(false) {
     54     static const char auditd_message[] = { KMSG_PRIORITY(LOG_INFO),
     55                                            'l',
     56                                            'o',
     57                                            'g',
     58                                            'd',
     59                                            '.',
     60                                            'a',
     61                                            'u',
     62                                            'd',
     63                                            'i',
     64                                            't',
     65                                            'd',
     66                                            ':',
     67                                            ' ',
     68                                            's',
     69                                            't',
     70                                            'a',
     71                                            'r',
     72                                            't',
     73                                            '\n' };
     74     write(fdDmesg, auditd_message, sizeof(auditd_message));
     75 }
     76 
     77 void LogAudit::checkRateLimit() {
     78     // trim list for AUDIT_RATE_LIMIT_BURST_DURATION of history
     79     log_time oldest(AUDIT_RATE_LIMIT_BURST_DURATION, 0);
     80     bucket.emplace(android_log_clockid());
     81     oldest = bucket.back() - oldest;
     82     while (bucket.front() < oldest) bucket.pop();
     83 
     84     static const size_t upperThreshold =
     85         ((AUDIT_RATE_LIMIT_BURST_DURATION *
     86           (AUDIT_RATE_LIMIT_DEFAULT + AUDIT_RATE_LIMIT_MAX)) +
     87          1) /
     88         2;
     89     if (bucket.size() >= upperThreshold) {
     90         // Hit peak, slow down source
     91         if (!tooFast) {
     92             tooFast = true;
     93             audit_rate_limit(mSock, AUDIT_RATE_LIMIT_MAX);
     94         }
     95 
     96         // We do not need to hold on to the full set of timing data history,
     97         // let's ensure it does not grow without bounds.  This also ensures
     98         // that std::dequeue underneath behaves almost like a ring buffer.
     99         do {
    100             bucket.pop();
    101         } while (bucket.size() >= upperThreshold);
    102         return;
    103     }
    104 
    105     if (!tooFast) return;
    106 
    107     static const size_t lowerThreshold =
    108         AUDIT_RATE_LIMIT_BURST_DURATION * AUDIT_RATE_LIMIT_MAX;
    109 
    110     if (bucket.size() >= lowerThreshold) return;
    111 
    112     tooFast = false;
    113     // Went below max sustained rate, allow source to speed up
    114     audit_rate_limit(mSock, AUDIT_RATE_LIMIT_DEFAULT);
    115 }
    116 
    117 bool LogAudit::onDataAvailable(SocketClient* cli) {
    118     if (!initialized) {
    119         prctl(PR_SET_NAME, "logd.auditd");
    120         initialized = true;
    121     }
    122 
    123     checkRateLimit();
    124 
    125     struct audit_message rep;
    126 
    127     rep.nlh.nlmsg_type = 0;
    128     rep.nlh.nlmsg_len = 0;
    129     rep.data[0] = '\0';
    130 
    131     if (audit_get_reply(cli->getSocket(), &rep, GET_REPLY_BLOCKING, 0) < 0) {
    132         SLOGE("Failed on audit_get_reply with error: %s", strerror(errno));
    133         return false;
    134     }
    135 
    136     logPrint("type=%d %.*s", rep.nlh.nlmsg_type, rep.nlh.nlmsg_len, rep.data);
    137 
    138     return true;
    139 }
    140 
    141 int LogAudit::logPrint(const char* fmt, ...) {
    142     if (fmt == NULL) {
    143         return -EINVAL;
    144     }
    145 
    146     va_list args;
    147 
    148     char* str = NULL;
    149     va_start(args, fmt);
    150     int rc = vasprintf(&str, fmt, args);
    151     va_end(args);
    152 
    153     if (rc < 0) {
    154         return rc;
    155     }
    156 
    157     char* cp;
    158     // Work around kernels missing
    159     // https://github.com/torvalds/linux/commit/b8f89caafeb55fba75b74bea25adc4e4cd91be67
    160     // Such kernels improperly add newlines inside audit messages.
    161     while ((cp = strchr(str, '\n'))) {
    162         *cp = ' ';
    163     }
    164 
    165     while ((cp = strstr(str, "  "))) {
    166         memmove(cp, cp + 1, strlen(cp + 1) + 1);
    167     }
    168 
    169     bool info = strstr(str, " permissive=1") || strstr(str, " policy loaded ");
    170     if ((fdDmesg >= 0) && initialized) {
    171         struct iovec iov[3];
    172         static const char log_info[] = { KMSG_PRIORITY(LOG_INFO) };
    173         static const char log_warning[] = { KMSG_PRIORITY(LOG_WARNING) };
    174         static const char newline[] = "\n";
    175 
    176         // Dedupe messages, checking for identical messages starting with avc:
    177         static unsigned count;
    178         static char* last_str;
    179         static bool last_info;
    180 
    181         if (last_str != NULL) {
    182             static const char avc[] = "): avc: ";
    183             char* avcl = strstr(last_str, avc);
    184             bool skip = false;
    185 
    186             if (avcl) {
    187                 char* avcr = strstr(str, avc);
    188 
    189                 skip = avcr &&
    190                        !fastcmp<strcmp>(avcl + strlen(avc), avcr + strlen(avc));
    191                 if (skip) {
    192                     ++count;
    193                     free(last_str);
    194                     last_str = strdup(str);
    195                     last_info = info;
    196                 }
    197             }
    198             if (!skip) {
    199                 static const char resume[] = " duplicate messages suppressed\n";
    200 
    201                 iov[0].iov_base = last_info ? const_cast<char*>(log_info)
    202                                             : const_cast<char*>(log_warning);
    203                 iov[0].iov_len =
    204                     last_info ? sizeof(log_info) : sizeof(log_warning);
    205                 iov[1].iov_base = last_str;
    206                 iov[1].iov_len = strlen(last_str);
    207                 if (count > 1) {
    208                     iov[2].iov_base = const_cast<char*>(resume);
    209                     iov[2].iov_len = strlen(resume);
    210                 } else {
    211                     iov[2].iov_base = const_cast<char*>(newline);
    212                     iov[2].iov_len = strlen(newline);
    213                 }
    214 
    215                 writev(fdDmesg, iov, arraysize(iov));
    216                 free(last_str);
    217                 last_str = NULL;
    218             }
    219         }
    220         if (last_str == NULL) {
    221             count = 0;
    222             last_str = strdup(str);
    223             last_info = info;
    224         }
    225         if (count == 0) {
    226             iov[0].iov_base = info ? const_cast<char*>(log_info)
    227                                    : const_cast<char*>(log_warning);
    228             iov[0].iov_len = info ? sizeof(log_info) : sizeof(log_warning);
    229             iov[1].iov_base = str;
    230             iov[1].iov_len = strlen(str);
    231             iov[2].iov_base = const_cast<char*>(newline);
    232             iov[2].iov_len = strlen(newline);
    233 
    234             writev(fdDmesg, iov, arraysize(iov));
    235         }
    236     }
    237 
    238     if (!main && !events) {
    239         free(str);
    240         return 0;
    241     }
    242 
    243     pid_t pid = getpid();
    244     pid_t tid = gettid();
    245     uid_t uid = AID_LOGD;
    246     log_time now;
    247 
    248     static const char audit_str[] = " audit(";
    249     char* timeptr = strstr(str, audit_str);
    250     if (timeptr &&
    251         ((cp = now.strptime(timeptr + sizeof(audit_str) - 1, "%s.%q"))) &&
    252         (*cp == ':')) {
    253         memcpy(timeptr + sizeof(audit_str) - 1, "0.0", 3);
    254         memmove(timeptr + sizeof(audit_str) - 1 + 3, cp, strlen(cp) + 1);
    255         if (!isMonotonic()) {
    256             if (android::isMonotonic(now)) {
    257                 LogKlog::convertMonotonicToReal(now);
    258             }
    259         } else {
    260             if (!android::isMonotonic(now)) {
    261                 LogKlog::convertRealToMonotonic(now);
    262             }
    263         }
    264     } else if (isMonotonic()) {
    265         now = log_time(CLOCK_MONOTONIC);
    266     } else {
    267         now = log_time(CLOCK_REALTIME);
    268     }
    269 
    270     static const char pid_str[] = " pid=";
    271     char* pidptr = strstr(str, pid_str);
    272     if (pidptr && isdigit(pidptr[sizeof(pid_str) - 1])) {
    273         cp = pidptr + sizeof(pid_str) - 1;
    274         pid = 0;
    275         while (isdigit(*cp)) {
    276             pid = (pid * 10) + (*cp - '0');
    277             ++cp;
    278         }
    279         tid = pid;
    280         logbuf->lock();
    281         uid = logbuf->pidToUid(pid);
    282         logbuf->unlock();
    283         memmove(pidptr, cp, strlen(cp) + 1);
    284     }
    285 
    286     // log to events
    287 
    288     size_t l = strnlen(str, LOGGER_ENTRY_MAX_PAYLOAD);
    289     size_t n = l + sizeof(android_log_event_string_t);
    290 
    291     bool notify = false;
    292 
    293     if (events) {  // begin scope for event buffer
    294         uint32_t buffer[(n + sizeof(uint32_t) - 1) / sizeof(uint32_t)];
    295 
    296         android_log_event_string_t* event =
    297             reinterpret_cast<android_log_event_string_t*>(buffer);
    298         event->header.tag = htole32(AUDITD_LOG_TAG);
    299         event->type = EVENT_TYPE_STRING;
    300         event->length = htole32(l);
    301         memcpy(event->data, str, l);
    302 
    303         rc = logbuf->log(LOG_ID_EVENTS, now, uid, pid, tid,
    304                          reinterpret_cast<char*>(event),
    305                          (n <= USHRT_MAX) ? (unsigned short)n : USHRT_MAX);
    306         if (rc >= 0) {
    307             notify = true;
    308         }
    309         // end scope for event buffer
    310     }
    311 
    312     // log to main
    313 
    314     static const char comm_str[] = " comm=\"";
    315     const char* comm = strstr(str, comm_str);
    316     const char* estr = str + strlen(str);
    317     const char* commfree = NULL;
    318     if (comm) {
    319         estr = comm;
    320         comm += sizeof(comm_str) - 1;
    321     } else if (pid == getpid()) {
    322         pid = tid;
    323         comm = "auditd";
    324     } else {
    325         logbuf->lock();
    326         comm = commfree = logbuf->pidToName(pid);
    327         logbuf->unlock();
    328         if (!comm) {
    329             comm = "unknown";
    330         }
    331     }
    332 
    333     const char* ecomm = strchr(comm, '"');
    334     if (ecomm) {
    335         ++ecomm;
    336         l = ecomm - comm;
    337     } else {
    338         l = strlen(comm) + 1;
    339         ecomm = "";
    340     }
    341     size_t b = estr - str;
    342     if (b > LOGGER_ENTRY_MAX_PAYLOAD) {
    343         b = LOGGER_ENTRY_MAX_PAYLOAD;
    344     }
    345     size_t e = strnlen(ecomm, LOGGER_ENTRY_MAX_PAYLOAD - b);
    346     n = b + e + l + 2;
    347 
    348     if (main) {  // begin scope for main buffer
    349         char newstr[n];
    350 
    351         *newstr = info ? ANDROID_LOG_INFO : ANDROID_LOG_WARN;
    352         strlcpy(newstr + 1, comm, l);
    353         strncpy(newstr + 1 + l, str, b);
    354         strncpy(newstr + 1 + l + b, ecomm, e);
    355 
    356         rc = logbuf->log(LOG_ID_MAIN, now, uid, pid, tid, newstr,
    357                          (n <= USHRT_MAX) ? (unsigned short)n : USHRT_MAX);
    358 
    359         if (rc >= 0) {
    360             notify = true;
    361         }
    362         // end scope for main buffer
    363     }
    364 
    365     free(const_cast<char*>(commfree));
    366     free(str);
    367 
    368     if (notify) {
    369         reader->notifyNewLog();
    370         if (rc < 0) {
    371             rc = n;
    372         }
    373     }
    374 
    375     return rc;
    376 }
    377 
    378 int LogAudit::log(char* buf, size_t len) {
    379     char* audit = strstr(buf, " audit(");
    380     if (!audit || (audit >= &buf[len])) {
    381         return 0;
    382     }
    383 
    384     *audit = '\0';
    385 
    386     int rc;
    387     char* type = strstr(buf, "type=");
    388     if (type && (type < &buf[len])) {
    389         rc = logPrint("%s %s", type, audit + 1);
    390     } else {
    391         rc = logPrint("%s", audit + 1);
    392     }
    393     *audit = ' ';
    394     return rc;
    395 }
    396 
    397 int LogAudit::getLogSocket() {
    398     int fd = audit_open();
    399     if (fd < 0) {
    400         return fd;
    401     }
    402     if (audit_setup(fd, getpid()) < 0) {
    403         audit_close(fd);
    404         fd = -1;
    405     }
    406     (void)audit_rate_limit(fd, AUDIT_RATE_LIMIT_DEFAULT);
    407     return fd;
    408 }
    409