Home | History | Annotate | Download | only in logd
      1 /*
      2  * Copyright (C) 2012-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 <stdio.h>
     20 #include <string.h>
     21 #include <sys/user.h>
     22 #include <time.h>
     23 #include <unistd.h>
     24 
     25 #include <unordered_map>
     26 
     27 #include <cutils/properties.h>
     28 #include <log/logger.h>
     29 
     30 #include "LogBuffer.h"
     31 #include "LogKlog.h"
     32 #include "LogReader.h"
     33 
     34 // Default
     35 #define LOG_BUFFER_SIZE (256 * 1024) // Tuned with ro.logd.size per-platform
     36 #define log_buffer_size(id) mMaxSize[id]
     37 #define LOG_BUFFER_MIN_SIZE (64 * 1024UL)
     38 #define LOG_BUFFER_MAX_SIZE (256 * 1024 * 1024UL)
     39 
     40 static bool valid_size(unsigned long value) {
     41     if ((value < LOG_BUFFER_MIN_SIZE) || (LOG_BUFFER_MAX_SIZE < value)) {
     42         return false;
     43     }
     44 
     45     long pages = sysconf(_SC_PHYS_PAGES);
     46     if (pages < 1) {
     47         return true;
     48     }
     49 
     50     long pagesize = sysconf(_SC_PAGESIZE);
     51     if (pagesize <= 1) {
     52         pagesize = PAGE_SIZE;
     53     }
     54 
     55     // maximum memory impact a somewhat arbitrary ~3%
     56     pages = (pages + 31) / 32;
     57     unsigned long maximum = pages * pagesize;
     58 
     59     if ((maximum < LOG_BUFFER_MIN_SIZE) || (LOG_BUFFER_MAX_SIZE < maximum)) {
     60         return true;
     61     }
     62 
     63     return value <= maximum;
     64 }
     65 
     66 static unsigned long property_get_size(const char *key) {
     67     char property[PROPERTY_VALUE_MAX];
     68     property_get(key, property, "");
     69 
     70     char *cp;
     71     unsigned long value = strtoul(property, &cp, 10);
     72 
     73     switch(*cp) {
     74     case 'm':
     75     case 'M':
     76         value *= 1024;
     77     /* FALLTHRU */
     78     case 'k':
     79     case 'K':
     80         value *= 1024;
     81     /* FALLTHRU */
     82     case '\0':
     83         break;
     84 
     85     default:
     86         value = 0;
     87     }
     88 
     89     if (!valid_size(value)) {
     90         value = 0;
     91     }
     92 
     93     return value;
     94 }
     95 
     96 void LogBuffer::init() {
     97     static const char global_tuneable[] = "persist.logd.size"; // Settings App
     98     static const char global_default[] = "ro.logd.size";       // BoardConfig.mk
     99 
    100     unsigned long default_size = property_get_size(global_tuneable);
    101     if (!default_size) {
    102         default_size = property_get_size(global_default);
    103         if (!default_size) {
    104             default_size = property_get_bool("ro.config.low_ram",
    105                                              BOOL_DEFAULT_FALSE)
    106                 ? LOG_BUFFER_MIN_SIZE // 64K
    107                 : LOG_BUFFER_SIZE;    // 256K
    108         }
    109     }
    110 
    111     log_id_for_each(i) {
    112         mLastSet[i] = false;
    113         mLast[i] = mLogElements.begin();
    114 
    115         char key[PROP_NAME_MAX];
    116 
    117         snprintf(key, sizeof(key), "%s.%s",
    118                  global_tuneable, android_log_id_to_name(i));
    119         unsigned long property_size = property_get_size(key);
    120 
    121         if (!property_size) {
    122             snprintf(key, sizeof(key), "%s.%s",
    123                      global_default, android_log_id_to_name(i));
    124             property_size = property_get_size(key);
    125         }
    126 
    127         if (!property_size) {
    128             property_size = default_size;
    129         }
    130 
    131         if (!property_size) {
    132             property_size = LOG_BUFFER_SIZE;
    133         }
    134 
    135         if (setSize(i, property_size)) {
    136             setSize(i, LOG_BUFFER_MIN_SIZE);
    137         }
    138     }
    139     bool lastMonotonic = monotonic;
    140     monotonic = android_log_clockid() == CLOCK_MONOTONIC;
    141     if (lastMonotonic != monotonic) {
    142         //
    143         // Fixup all timestamps, may not be 100% accurate, but better than
    144         // throwing what we have away when we get 'surprised' by a change.
    145         // In-place element fixup so no need to check reader-lock. Entries
    146         // should already be in timestamp order, but we could end up with a
    147         // few out-of-order entries if new monotonics come in before we
    148         // are notified of the reinit change in status. A Typical example would
    149         // be:
    150         //  --------- beginning of system
    151         //      10.494082   184   201 D Cryptfs : Just triggered post_fs_data
    152         //  --------- beginning of kernel
    153         //       0.000000     0     0 I         : Initializing cgroup subsys
    154         // as the act of mounting /data would trigger persist.logd.timestamp to
    155         // be corrected. 1/30 corner case YMMV.
    156         //
    157         pthread_mutex_lock(&mLogElementsLock);
    158         LogBufferElementCollection::iterator it = mLogElements.begin();
    159         while((it != mLogElements.end())) {
    160             LogBufferElement *e = *it;
    161             if (monotonic) {
    162                 if (!android::isMonotonic(e->mRealTime)) {
    163                     LogKlog::convertRealToMonotonic(e->mRealTime);
    164                 }
    165             } else {
    166                 if (android::isMonotonic(e->mRealTime)) {
    167                     LogKlog::convertMonotonicToReal(e->mRealTime);
    168                 }
    169             }
    170             ++it;
    171         }
    172         pthread_mutex_unlock(&mLogElementsLock);
    173     }
    174 
    175     // We may have been triggered by a SIGHUP. Release any sleeping reader
    176     // threads to dump their current content.
    177     //
    178     // NB: this is _not_ performed in the context of a SIGHUP, it is
    179     // performed during startup, and in context of reinit administrative thread
    180     LogTimeEntry::lock();
    181 
    182     LastLogTimes::iterator times = mTimes.begin();
    183     while(times != mTimes.end()) {
    184         LogTimeEntry *entry = (*times);
    185         if (entry->owned_Locked()) {
    186             entry->triggerReader_Locked();
    187         }
    188         times++;
    189     }
    190 
    191     LogTimeEntry::unlock();
    192 }
    193 
    194 LogBuffer::LogBuffer(LastLogTimes *times):
    195         monotonic(android_log_clockid() == CLOCK_MONOTONIC),
    196         mTimes(*times) {
    197     pthread_mutex_init(&mLogElementsLock, NULL);
    198 
    199     init();
    200 }
    201 
    202 int LogBuffer::log(log_id_t log_id, log_time realtime,
    203                    uid_t uid, pid_t pid, pid_t tid,
    204                    const char *msg, unsigned short len) {
    205     if ((log_id >= LOG_ID_MAX) || (log_id < 0)) {
    206         return -EINVAL;
    207     }
    208 
    209     LogBufferElement *elem = new LogBufferElement(log_id, realtime,
    210                                                   uid, pid, tid, msg, len);
    211     if (log_id != LOG_ID_SECURITY) {
    212         int prio = ANDROID_LOG_INFO;
    213         const char *tag = NULL;
    214         if (log_id == LOG_ID_EVENTS) {
    215             tag = android::tagToName(elem->getTag());
    216         } else {
    217             prio = *msg;
    218             tag = msg + 1;
    219         }
    220         if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) {
    221             // Log traffic received to total
    222             pthread_mutex_lock(&mLogElementsLock);
    223             stats.add(elem);
    224             stats.subtract(elem);
    225             pthread_mutex_unlock(&mLogElementsLock);
    226             delete elem;
    227             return -EACCES;
    228         }
    229     }
    230 
    231     pthread_mutex_lock(&mLogElementsLock);
    232 
    233     // Insert elements in time sorted order if possible
    234     //  NB: if end is region locked, place element at end of list
    235     LogBufferElementCollection::iterator it = mLogElements.end();
    236     LogBufferElementCollection::iterator last = it;
    237     while (last != mLogElements.begin()) {
    238         --it;
    239         if ((*it)->getRealTime() <= realtime) {
    240             break;
    241         }
    242         last = it;
    243     }
    244 
    245     if (last == mLogElements.end()) {
    246         mLogElements.push_back(elem);
    247     } else {
    248         uint64_t end = 1;
    249         bool end_set = false;
    250         bool end_always = false;
    251 
    252         LogTimeEntry::lock();
    253 
    254         LastLogTimes::iterator times = mTimes.begin();
    255         while(times != mTimes.end()) {
    256             LogTimeEntry *entry = (*times);
    257             if (entry->owned_Locked()) {
    258                 if (!entry->mNonBlock) {
    259                     end_always = true;
    260                     break;
    261                 }
    262                 if (!end_set || (end <= entry->mEnd)) {
    263                     end = entry->mEnd;
    264                     end_set = true;
    265                 }
    266             }
    267             times++;
    268         }
    269 
    270         if (end_always
    271                 || (end_set && (end >= (*last)->getSequence()))) {
    272             mLogElements.push_back(elem);
    273         } else {
    274             mLogElements.insert(last,elem);
    275         }
    276 
    277         LogTimeEntry::unlock();
    278     }
    279 
    280     stats.add(elem);
    281     maybePrune(log_id);
    282     pthread_mutex_unlock(&mLogElementsLock);
    283 
    284     return len;
    285 }
    286 
    287 // Prune at most 10% of the log entries or maxPrune, whichever is less.
    288 //
    289 // mLogElementsLock must be held when this function is called.
    290 void LogBuffer::maybePrune(log_id_t id) {
    291     size_t sizes = stats.sizes(id);
    292     unsigned long maxSize = log_buffer_size(id);
    293     if (sizes > maxSize) {
    294         size_t sizeOver = sizes - ((maxSize * 9) / 10);
    295         size_t elements = stats.realElements(id);
    296         size_t minElements = elements / 100;
    297         if (minElements < minPrune) {
    298             minElements = minPrune;
    299         }
    300         unsigned long pruneRows = elements * sizeOver / sizes;
    301         if (pruneRows < minElements) {
    302             pruneRows = minElements;
    303         }
    304         if (pruneRows > maxPrune) {
    305             pruneRows = maxPrune;
    306         }
    307         prune(id, pruneRows);
    308     }
    309 }
    310 
    311 LogBufferElementCollection::iterator LogBuffer::erase(
    312         LogBufferElementCollection::iterator it, bool coalesce) {
    313     LogBufferElement *element = *it;
    314     log_id_t id = element->getLogId();
    315 
    316     {   // start of scope for uid found iterator
    317         LogBufferIteratorMap::iterator found =
    318             mLastWorstUid[id].find(element->getUid());
    319         if ((found != mLastWorstUid[id].end())
    320                 && (it == found->second)) {
    321             mLastWorstUid[id].erase(found);
    322         }
    323     }
    324 
    325     if (element->getUid() == AID_SYSTEM) {
    326         // start of scope for pid found iterator
    327         LogBufferPidIteratorMap::iterator found =
    328             mLastWorstPidOfSystem[id].find(element->getPid());
    329         if ((found != mLastWorstPidOfSystem[id].end())
    330                 && (it == found->second)) {
    331             mLastWorstPidOfSystem[id].erase(found);
    332         }
    333     }
    334 
    335     bool setLast[LOG_ID_MAX];
    336     bool doSetLast = false;
    337     log_id_for_each(i) {
    338         doSetLast |= setLast[i] = mLastSet[i] && (it == mLast[i]);
    339     }
    340     it = mLogElements.erase(it);
    341     if (doSetLast) {
    342         log_id_for_each(i) {
    343             if (setLast[i]) {
    344                 if (it == mLogElements.end()) { // unlikely
    345                     mLastSet[i] = false;
    346                 } else {
    347                     mLast[i] = it;
    348                 }
    349             }
    350         }
    351     }
    352     if (coalesce) {
    353         stats.erase(element);
    354     } else {
    355         stats.subtract(element);
    356     }
    357     delete element;
    358 
    359     return it;
    360 }
    361 
    362 // Define a temporary mechanism to report the last LogBufferElement pointer
    363 // for the specified uid, pid and tid. Used below to help merge-sort when
    364 // pruning for worst UID.
    365 class LogBufferElementKey {
    366     const union {
    367         struct {
    368             uint16_t uid;
    369             uint16_t pid;
    370             uint16_t tid;
    371             uint16_t padding;
    372         } __packed;
    373         uint64_t value;
    374     } __packed;
    375 
    376 public:
    377     LogBufferElementKey(uid_t uid, pid_t pid, pid_t tid):
    378             uid(uid),
    379             pid(pid),
    380             tid(tid),
    381             padding(0) {
    382     }
    383     LogBufferElementKey(uint64_t key):value(key) { }
    384 
    385     uint64_t getKey() { return value; }
    386 };
    387 
    388 class LogBufferElementLast {
    389 
    390     typedef std::unordered_map<uint64_t, LogBufferElement *> LogBufferElementMap;
    391     LogBufferElementMap map;
    392 
    393 public:
    394 
    395     bool coalesce(LogBufferElement *element, unsigned short dropped) {
    396         LogBufferElementKey key(element->getUid(),
    397                                 element->getPid(),
    398                                 element->getTid());
    399         LogBufferElementMap::iterator it = map.find(key.getKey());
    400         if (it != map.end()) {
    401             LogBufferElement *found = it->second;
    402             unsigned short moreDropped = found->getDropped();
    403             if ((dropped + moreDropped) > USHRT_MAX) {
    404                 map.erase(it);
    405             } else {
    406                 found->setDropped(dropped + moreDropped);
    407                 return true;
    408             }
    409         }
    410         return false;
    411     }
    412 
    413     void add(LogBufferElement *element) {
    414         LogBufferElementKey key(element->getUid(),
    415                                 element->getPid(),
    416                                 element->getTid());
    417         map[key.getKey()] = element;
    418     }
    419 
    420     inline void clear() {
    421         map.clear();
    422     }
    423 
    424     void clear(LogBufferElement *element) {
    425         uint64_t current = element->getRealTime().nsec()
    426                          - (EXPIRE_RATELIMIT * NS_PER_SEC);
    427         for(LogBufferElementMap::iterator it = map.begin(); it != map.end();) {
    428             LogBufferElement *mapElement = it->second;
    429             if ((mapElement->getDropped() >= EXPIRE_THRESHOLD)
    430                     && (current > mapElement->getRealTime().nsec())) {
    431                 it = map.erase(it);
    432             } else {
    433                 ++it;
    434             }
    435         }
    436     }
    437 
    438 };
    439 
    440 // prune "pruneRows" of type "id" from the buffer.
    441 //
    442 // This garbage collection task is used to expire log entries. It is called to
    443 // remove all logs (clear), all UID logs (unprivileged clear), or every
    444 // 256 or 10% of the total logs (whichever is less) to prune the logs.
    445 //
    446 // First there is a prep phase where we discover the reader region lock that
    447 // acts as a backstop to any pruning activity to stop there and go no further.
    448 //
    449 // There are three major pruning loops that follow. All expire from the oldest
    450 // entries. Since there are multiple log buffers, the Android logging facility
    451 // will appear to drop entries 'in the middle' when looking at multiple log
    452 // sources and buffers. This effect is slightly more prominent when we prune
    453 // the worst offender by logging source. Thus the logs slowly loose content
    454 // and value as you move back in time. This is preferred since chatty sources
    455 // invariably move the logs value down faster as less chatty sources would be
    456 // expired in the noise.
    457 //
    458 // The first loop performs blacklisting and worst offender pruning. Falling
    459 // through when there are no notable worst offenders and have not hit the
    460 // region lock preventing further worst offender pruning. This loop also looks
    461 // after managing the chatty log entries and merging to help provide
    462 // statistical basis for blame. The chatty entries are not a notification of
    463 // how much logs you may have, but instead represent how much logs you would
    464 // have had in a virtual log buffer that is extended to cover all the in-memory
    465 // logs without loss. They last much longer than the represented pruned logs
    466 // since they get multiplied by the gains in the non-chatty log sources.
    467 //
    468 // The second loop get complicated because an algorithm of watermarks and
    469 // history is maintained to reduce the order and keep processing time
    470 // down to a minimum at scale. These algorithms can be costly in the face
    471 // of larger log buffers, or severly limited processing time granted to a
    472 // background task at lowest priority.
    473 //
    474 // This second loop does straight-up expiration from the end of the logs
    475 // (again, remember for the specified log buffer id) but does some whitelist
    476 // preservation. Thus whitelist is a Hail Mary low priority, blacklists and
    477 // spam filtration all take priority. This second loop also checks if a region
    478 // lock is causing us to buffer too much in the logs to help the reader(s),
    479 // and will tell the slowest reader thread to skip log entries, and if
    480 // persistent and hits a further threshold, kill the reader thread.
    481 //
    482 // The third thread is optional, and only gets hit if there was a whitelist
    483 // and more needs to be pruned against the backstop of the region lock.
    484 //
    485 // mLogElementsLock must be held when this function is called.
    486 //
    487 bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
    488     LogTimeEntry *oldest = NULL;
    489     bool busy = false;
    490     bool clearAll = pruneRows == ULONG_MAX;
    491 
    492     LogTimeEntry::lock();
    493 
    494     // Region locked?
    495     LastLogTimes::iterator times = mTimes.begin();
    496     while(times != mTimes.end()) {
    497         LogTimeEntry *entry = (*times);
    498         if (entry->owned_Locked() && entry->isWatching(id)
    499                 && (!oldest ||
    500                     (oldest->mStart > entry->mStart) ||
    501                     ((oldest->mStart == entry->mStart) &&
    502                      (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec)))) {
    503             oldest = entry;
    504         }
    505         times++;
    506     }
    507 
    508     LogBufferElementCollection::iterator it;
    509 
    510     if (caller_uid != AID_ROOT) {
    511         // Only here if clearAll condition (pruneRows == ULONG_MAX)
    512         it = mLastSet[id] ? mLast[id] : mLogElements.begin();
    513         while (it != mLogElements.end()) {
    514             LogBufferElement *element = *it;
    515 
    516             if ((element->getLogId() != id) || (element->getUid() != caller_uid)) {
    517                 ++it;
    518                 continue;
    519             }
    520 
    521             if (!mLastSet[id] || ((*mLast[id])->getLogId() != id)) {
    522                 mLast[id] = it;
    523                 mLastSet[id] = true;
    524             }
    525 
    526             if (oldest && (oldest->mStart <= element->getSequence())) {
    527                 busy = true;
    528                 if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
    529                     oldest->triggerReader_Locked();
    530                 } else {
    531                     oldest->triggerSkip_Locked(id, pruneRows);
    532                 }
    533                 break;
    534             }
    535 
    536             it = erase(it);
    537             pruneRows--;
    538         }
    539         LogTimeEntry::unlock();
    540         return busy;
    541     }
    542 
    543     // prune by worst offenders; by blacklist, UID, and by PID of system UID
    544     bool hasBlacklist = (id != LOG_ID_SECURITY) && mPrune.naughty();
    545     while (!clearAll && (pruneRows > 0)) {
    546         // recalculate the worst offender on every batched pass
    547         uid_t worst = (uid_t) -1;
    548         size_t worst_sizes = 0;
    549         size_t second_worst_sizes = 0;
    550         pid_t worstPid = 0; // POSIX guarantees PID != 0
    551 
    552         if (worstUidEnabledForLogid(id) && mPrune.worstUidEnabled()) {
    553             {   // begin scope for UID sorted list
    554                 std::unique_ptr<const UidEntry *[]> sorted = stats.sort(
    555                     AID_ROOT, (pid_t)0, 2, id);
    556 
    557                 if (sorted.get() && sorted[0] && sorted[1]) {
    558                     worst_sizes = sorted[0]->getSizes();
    559                     // Calculate threshold as 12.5% of available storage
    560                     size_t threshold = log_buffer_size(id) / 8;
    561                     if ((worst_sizes > threshold)
    562                         // Allow time horizon to extend roughly tenfold, assume
    563                         // average entry length is 100 characters.
    564                             && (worst_sizes > (10 * sorted[0]->getDropped()))) {
    565                         worst = sorted[0]->getKey();
    566                         second_worst_sizes = sorted[1]->getSizes();
    567                         if (second_worst_sizes < threshold) {
    568                             second_worst_sizes = threshold;
    569                         }
    570                     }
    571                 }
    572             }
    573 
    574             if ((worst == AID_SYSTEM) && mPrune.worstPidOfSystemEnabled()) {
    575                 // begin scope of PID sorted list
    576                 std::unique_ptr<const PidEntry *[]> sorted = stats.sort(
    577                     worst, (pid_t)0, 2, id, worst);
    578                 if (sorted.get() && sorted[0] && sorted[1]) {
    579                     worstPid = sorted[0]->getKey();
    580                     second_worst_sizes = worst_sizes
    581                                        - sorted[0]->getSizes()
    582                                        + sorted[1]->getSizes();
    583                 }
    584             }
    585         }
    586 
    587         // skip if we have neither worst nor naughty filters
    588         if ((worst == (uid_t) -1) && !hasBlacklist) {
    589             break;
    590         }
    591 
    592         bool kick = false;
    593         bool leading = true;
    594         it = mLastSet[id] ? mLast[id] : mLogElements.begin();
    595         // Perform at least one mandatory garbage collection cycle in following
    596         // - clear leading chatty tags
    597         // - coalesce chatty tags
    598         // - check age-out of preserved logs
    599         bool gc = pruneRows <= 1;
    600         if (!gc && (worst != (uid_t) -1)) {
    601             {   // begin scope for uid worst found iterator
    602                 LogBufferIteratorMap::iterator found = mLastWorstUid[id].find(worst);
    603                 if ((found != mLastWorstUid[id].end())
    604                         && (found->second != mLogElements.end())) {
    605                     leading = false;
    606                     it = found->second;
    607                 }
    608             }
    609             if (worstPid) {
    610                 // begin scope for pid worst found iterator
    611                 LogBufferPidIteratorMap::iterator found
    612                     = mLastWorstPidOfSystem[id].find(worstPid);
    613                 if ((found != mLastWorstPidOfSystem[id].end())
    614                         && (found->second != mLogElements.end())) {
    615                     leading = false;
    616                     it = found->second;
    617                 }
    618             }
    619         }
    620         static const timespec too_old = {
    621             EXPIRE_HOUR_THRESHOLD * 60 * 60, 0
    622         };
    623         LogBufferElementCollection::iterator lastt;
    624         lastt = mLogElements.end();
    625         --lastt;
    626         LogBufferElementLast last;
    627         while (it != mLogElements.end()) {
    628             LogBufferElement *element = *it;
    629 
    630             if (oldest && (oldest->mStart <= element->getSequence())) {
    631                 busy = true;
    632                 if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
    633                     oldest->triggerReader_Locked();
    634                 }
    635                 break;
    636             }
    637 
    638             if (element->getLogId() != id) {
    639                 ++it;
    640                 continue;
    641             }
    642 
    643             if (leading && (!mLastSet[id] || ((*mLast[id])->getLogId() != id))) {
    644                 mLast[id] = it;
    645                 mLastSet[id] = true;
    646             }
    647 
    648             unsigned short dropped = element->getDropped();
    649 
    650             // remove any leading drops
    651             if (leading && dropped) {
    652                 it = erase(it);
    653                 continue;
    654             }
    655 
    656             if (dropped && last.coalesce(element, dropped)) {
    657                 it = erase(it, true);
    658                 continue;
    659             }
    660 
    661             if (hasBlacklist && mPrune.naughty(element)) {
    662                 last.clear(element);
    663                 it = erase(it);
    664                 if (dropped) {
    665                     continue;
    666                 }
    667 
    668                 pruneRows--;
    669                 if (pruneRows == 0) {
    670                     break;
    671                 }
    672 
    673                 if (element->getUid() == worst) {
    674                     kick = true;
    675                     if (worst_sizes < second_worst_sizes) {
    676                         break;
    677                     }
    678                     worst_sizes -= element->getMsgLen();
    679                 }
    680                 continue;
    681             }
    682 
    683             if ((element->getRealTime() < ((*lastt)->getRealTime() - too_old))
    684                     || (element->getRealTime() > (*lastt)->getRealTime())) {
    685                 break;
    686             }
    687 
    688             if (dropped) {
    689                 last.add(element);
    690                 if (worstPid
    691                         && ((!gc && (element->getPid() == worstPid))
    692                             || (mLastWorstPidOfSystem[id].find(element->getPid())
    693                                 == mLastWorstPidOfSystem[id].end()))) {
    694                     mLastWorstPidOfSystem[id][element->getUid()] = it;
    695                 }
    696                 if ((!gc && !worstPid && (element->getUid() == worst))
    697                         || (mLastWorstUid[id].find(element->getUid())
    698                             == mLastWorstUid[id].end())) {
    699                     mLastWorstUid[id][element->getUid()] = it;
    700                 }
    701                 ++it;
    702                 continue;
    703             }
    704 
    705             if ((element->getUid() != worst)
    706                     || (worstPid && (element->getPid() != worstPid))) {
    707                 leading = false;
    708                 last.clear(element);
    709                 ++it;
    710                 continue;
    711             }
    712 
    713             pruneRows--;
    714             if (pruneRows == 0) {
    715                 break;
    716             }
    717 
    718             kick = true;
    719 
    720             unsigned short len = element->getMsgLen();
    721 
    722             // do not create any leading drops
    723             if (leading) {
    724                 it = erase(it);
    725             } else {
    726                 stats.drop(element);
    727                 element->setDropped(1);
    728                 if (last.coalesce(element, 1)) {
    729                     it = erase(it, true);
    730                 } else {
    731                     last.add(element);
    732                     if (worstPid && (!gc
    733                                 || (mLastWorstPidOfSystem[id].find(worstPid)
    734                                     == mLastWorstPidOfSystem[id].end()))) {
    735                         mLastWorstPidOfSystem[id][worstPid] = it;
    736                     }
    737                     if ((!gc && !worstPid) || (mLastWorstUid[id].find(worst)
    738                                 == mLastWorstUid[id].end())) {
    739                         mLastWorstUid[id][worst] = it;
    740                     }
    741                     ++it;
    742                 }
    743             }
    744             if (worst_sizes < second_worst_sizes) {
    745                 break;
    746             }
    747             worst_sizes -= len;
    748         }
    749         last.clear();
    750 
    751         if (!kick || !mPrune.worstUidEnabled()) {
    752             break; // the following loop will ask bad clients to skip/drop
    753         }
    754     }
    755 
    756     bool whitelist = false;
    757     bool hasWhitelist = (id != LOG_ID_SECURITY) && mPrune.nice() && !clearAll;
    758     it = mLastSet[id] ? mLast[id] : mLogElements.begin();
    759     while((pruneRows > 0) && (it != mLogElements.end())) {
    760         LogBufferElement *element = *it;
    761 
    762         if (element->getLogId() != id) {
    763             it++;
    764             continue;
    765         }
    766 
    767         if (!mLastSet[id] || ((*mLast[id])->getLogId() != id)) {
    768             mLast[id] = it;
    769             mLastSet[id] = true;
    770         }
    771 
    772         if (oldest && (oldest->mStart <= element->getSequence())) {
    773             busy = true;
    774             if (whitelist) {
    775                 break;
    776             }
    777 
    778             if (stats.sizes(id) > (2 * log_buffer_size(id))) {
    779                 // kick a misbehaving log reader client off the island
    780                 oldest->release_Locked();
    781             } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
    782                 oldest->triggerReader_Locked();
    783             } else {
    784                 oldest->triggerSkip_Locked(id, pruneRows);
    785             }
    786             break;
    787         }
    788 
    789         if (hasWhitelist && !element->getDropped() && mPrune.nice(element)) {
    790             // WhiteListed
    791             whitelist = true;
    792             it++;
    793             continue;
    794         }
    795 
    796         it = erase(it);
    797         pruneRows--;
    798     }
    799 
    800     // Do not save the whitelist if we are reader range limited
    801     if (whitelist && (pruneRows > 0)) {
    802         it = mLastSet[id] ? mLast[id] : mLogElements.begin();
    803         while((it != mLogElements.end()) && (pruneRows > 0)) {
    804             LogBufferElement *element = *it;
    805 
    806             if (element->getLogId() != id) {
    807                 ++it;
    808                 continue;
    809             }
    810 
    811             if (!mLastSet[id] || ((*mLast[id])->getLogId() != id)) {
    812                 mLast[id] = it;
    813                 mLastSet[id] = true;
    814             }
    815 
    816             if (oldest && (oldest->mStart <= element->getSequence())) {
    817                 busy = true;
    818                 if (stats.sizes(id) > (2 * log_buffer_size(id))) {
    819                     // kick a misbehaving log reader client off the island
    820                     oldest->release_Locked();
    821                 } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
    822                     oldest->triggerReader_Locked();
    823                 } else {
    824                     oldest->triggerSkip_Locked(id, pruneRows);
    825                 }
    826                 break;
    827             }
    828 
    829             it = erase(it);
    830             pruneRows--;
    831         }
    832     }
    833 
    834     LogTimeEntry::unlock();
    835 
    836     return (pruneRows > 0) && busy;
    837 }
    838 
    839 // clear all rows of type "id" from the buffer.
    840 bool LogBuffer::clear(log_id_t id, uid_t uid) {
    841     bool busy = true;
    842     // If it takes more than 4 tries (seconds) to clear, then kill reader(s)
    843     for (int retry = 4;;) {
    844         if (retry == 1) { // last pass
    845             // Check if it is still busy after the sleep, we say prune
    846             // one entry, not another clear run, so we are looking for
    847             // the quick side effect of the return value to tell us if
    848             // we have a _blocked_ reader.
    849             pthread_mutex_lock(&mLogElementsLock);
    850             busy = prune(id, 1, uid);
    851             pthread_mutex_unlock(&mLogElementsLock);
    852             // It is still busy, blocked reader(s), lets kill them all!
    853             // otherwise, lets be a good citizen and preserve the slow
    854             // readers and let the clear run (below) deal with determining
    855             // if we are still blocked and return an error code to caller.
    856             if (busy) {
    857                 LogTimeEntry::lock();
    858                 LastLogTimes::iterator times = mTimes.begin();
    859                 while (times != mTimes.end()) {
    860                     LogTimeEntry *entry = (*times);
    861                     // Killer punch
    862                     if (entry->owned_Locked() && entry->isWatching(id)) {
    863                         entry->release_Locked();
    864                     }
    865                     times++;
    866                 }
    867                 LogTimeEntry::unlock();
    868             }
    869         }
    870         pthread_mutex_lock(&mLogElementsLock);
    871         busy = prune(id, ULONG_MAX, uid);
    872         pthread_mutex_unlock(&mLogElementsLock);
    873         if (!busy || !--retry) {
    874             break;
    875         }
    876         sleep (1); // Let reader(s) catch up after notification
    877     }
    878     return busy;
    879 }
    880 
    881 // get the used space associated with "id".
    882 unsigned long LogBuffer::getSizeUsed(log_id_t id) {
    883     pthread_mutex_lock(&mLogElementsLock);
    884     size_t retval = stats.sizes(id);
    885     pthread_mutex_unlock(&mLogElementsLock);
    886     return retval;
    887 }
    888 
    889 // set the total space allocated to "id"
    890 int LogBuffer::setSize(log_id_t id, unsigned long size) {
    891     // Reasonable limits ...
    892     if (!valid_size(size)) {
    893         return -1;
    894     }
    895     pthread_mutex_lock(&mLogElementsLock);
    896     log_buffer_size(id) = size;
    897     pthread_mutex_unlock(&mLogElementsLock);
    898     return 0;
    899 }
    900 
    901 // get the total space allocated to "id"
    902 unsigned long LogBuffer::getSize(log_id_t id) {
    903     pthread_mutex_lock(&mLogElementsLock);
    904     size_t retval = log_buffer_size(id);
    905     pthread_mutex_unlock(&mLogElementsLock);
    906     return retval;
    907 }
    908 
    909 uint64_t LogBuffer::flushTo(
    910         SocketClient *reader, const uint64_t start,
    911         bool privileged, bool security,
    912         int (*filter)(const LogBufferElement *element, void *arg), void *arg) {
    913     LogBufferElementCollection::iterator it;
    914     uint64_t max = start;
    915     uid_t uid = reader->getUid();
    916 
    917     pthread_mutex_lock(&mLogElementsLock);
    918 
    919     if (start <= 1) {
    920         // client wants to start from the beginning
    921         it = mLogElements.begin();
    922     } else {
    923         // Client wants to start from some specified time. Chances are
    924         // we are better off starting from the end of the time sorted list.
    925         for (it = mLogElements.end(); it != mLogElements.begin(); /* do nothing */) {
    926             --it;
    927             LogBufferElement *element = *it;
    928             if (element->getSequence() <= start) {
    929                 it++;
    930                 break;
    931             }
    932         }
    933     }
    934 
    935     for (; it != mLogElements.end(); ++it) {
    936         LogBufferElement *element = *it;
    937 
    938         if (!privileged && (element->getUid() != uid)) {
    939             continue;
    940         }
    941 
    942         if (!security && (element->getLogId() == LOG_ID_SECURITY)) {
    943             continue;
    944         }
    945 
    946         if (element->getSequence() <= start) {
    947             continue;
    948         }
    949 
    950         // NB: calling out to another object with mLogElementsLock held (safe)
    951         if (filter) {
    952             int ret = (*filter)(element, arg);
    953             if (ret == false) {
    954                 continue;
    955             }
    956             if (ret != true) {
    957                 break;
    958             }
    959         }
    960 
    961         pthread_mutex_unlock(&mLogElementsLock);
    962 
    963         // range locking in LastLogTimes looks after us
    964         max = element->flushTo(reader, this, privileged);
    965 
    966         if (max == element->FLUSH_ERROR) {
    967             return max;
    968         }
    969 
    970         pthread_mutex_lock(&mLogElementsLock);
    971     }
    972     pthread_mutex_unlock(&mLogElementsLock);
    973 
    974     return max;
    975 }
    976 
    977 std::string LogBuffer::formatStatistics(uid_t uid, pid_t pid,
    978                                         unsigned int logMask) {
    979     pthread_mutex_lock(&mLogElementsLock);
    980 
    981     std::string ret = stats.format(uid, pid, logMask);
    982 
    983     pthread_mutex_unlock(&mLogElementsLock);
    984 
    985     return ret;
    986 }
    987