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 // Remove iterator references in the various lists that will become stale 317 // after the element is erased from the main logging list. 318 319 { // start of scope for uid found iterator 320 LogBufferIteratorMap::iterator found = 321 mLastWorstUid[id].find(element->getUid()); 322 if ((found != mLastWorstUid[id].end()) 323 && (it == found->second)) { 324 mLastWorstUid[id].erase(found); 325 } 326 } 327 328 { // start of scope for pid found iterator 329 // element->getUid() may not be AID_SYSTEM for next-best-watermark. 330 LogBufferPidIteratorMap::iterator found = 331 mLastWorstPidOfSystem[id].find(element->getPid()); 332 if ((found != mLastWorstPidOfSystem[id].end()) 333 && (it == found->second)) { 334 mLastWorstPidOfSystem[id].erase(found); 335 } 336 } 337 338 bool setLast[LOG_ID_MAX]; 339 bool doSetLast = false; 340 log_id_for_each(i) { 341 doSetLast |= setLast[i] = mLastSet[i] && (it == mLast[i]); 342 } 343 it = mLogElements.erase(it); 344 if (doSetLast) { 345 log_id_for_each(i) { 346 if (setLast[i]) { 347 if (it == mLogElements.end()) { // unlikely 348 mLastSet[i] = false; 349 } else { 350 mLast[i] = it; 351 } 352 } 353 } 354 } 355 if (coalesce) { 356 stats.erase(element); 357 } else { 358 stats.subtract(element); 359 } 360 delete element; 361 362 return it; 363 } 364 365 // Define a temporary mechanism to report the last LogBufferElement pointer 366 // for the specified uid, pid and tid. Used below to help merge-sort when 367 // pruning for worst UID. 368 class LogBufferElementKey { 369 const union { 370 struct { 371 uint16_t uid; 372 uint16_t pid; 373 uint16_t tid; 374 uint16_t padding; 375 } __packed; 376 uint64_t value; 377 } __packed; 378 379 public: 380 LogBufferElementKey(uid_t uid, pid_t pid, pid_t tid): 381 uid(uid), 382 pid(pid), 383 tid(tid), 384 padding(0) { 385 } 386 LogBufferElementKey(uint64_t key):value(key) { } 387 388 uint64_t getKey() { return value; } 389 }; 390 391 class LogBufferElementLast { 392 393 typedef std::unordered_map<uint64_t, LogBufferElement *> LogBufferElementMap; 394 LogBufferElementMap map; 395 396 public: 397 398 bool coalesce(LogBufferElement *element, unsigned short dropped) { 399 LogBufferElementKey key(element->getUid(), 400 element->getPid(), 401 element->getTid()); 402 LogBufferElementMap::iterator it = map.find(key.getKey()); 403 if (it != map.end()) { 404 LogBufferElement *found = it->second; 405 unsigned short moreDropped = found->getDropped(); 406 if ((dropped + moreDropped) > USHRT_MAX) { 407 map.erase(it); 408 } else { 409 found->setDropped(dropped + moreDropped); 410 return true; 411 } 412 } 413 return false; 414 } 415 416 void add(LogBufferElement *element) { 417 LogBufferElementKey key(element->getUid(), 418 element->getPid(), 419 element->getTid()); 420 map[key.getKey()] = element; 421 } 422 423 inline void clear() { 424 map.clear(); 425 } 426 427 void clear(LogBufferElement *element) { 428 uint64_t current = element->getRealTime().nsec() 429 - (EXPIRE_RATELIMIT * NS_PER_SEC); 430 for(LogBufferElementMap::iterator it = map.begin(); it != map.end();) { 431 LogBufferElement *mapElement = it->second; 432 if ((mapElement->getDropped() >= EXPIRE_THRESHOLD) 433 && (current > mapElement->getRealTime().nsec())) { 434 it = map.erase(it); 435 } else { 436 ++it; 437 } 438 } 439 } 440 441 }; 442 443 // prune "pruneRows" of type "id" from the buffer. 444 // 445 // This garbage collection task is used to expire log entries. It is called to 446 // remove all logs (clear), all UID logs (unprivileged clear), or every 447 // 256 or 10% of the total logs (whichever is less) to prune the logs. 448 // 449 // First there is a prep phase where we discover the reader region lock that 450 // acts as a backstop to any pruning activity to stop there and go no further. 451 // 452 // There are three major pruning loops that follow. All expire from the oldest 453 // entries. Since there are multiple log buffers, the Android logging facility 454 // will appear to drop entries 'in the middle' when looking at multiple log 455 // sources and buffers. This effect is slightly more prominent when we prune 456 // the worst offender by logging source. Thus the logs slowly loose content 457 // and value as you move back in time. This is preferred since chatty sources 458 // invariably move the logs value down faster as less chatty sources would be 459 // expired in the noise. 460 // 461 // The first loop performs blacklisting and worst offender pruning. Falling 462 // through when there are no notable worst offenders and have not hit the 463 // region lock preventing further worst offender pruning. This loop also looks 464 // after managing the chatty log entries and merging to help provide 465 // statistical basis for blame. The chatty entries are not a notification of 466 // how much logs you may have, but instead represent how much logs you would 467 // have had in a virtual log buffer that is extended to cover all the in-memory 468 // logs without loss. They last much longer than the represented pruned logs 469 // since they get multiplied by the gains in the non-chatty log sources. 470 // 471 // The second loop get complicated because an algorithm of watermarks and 472 // history is maintained to reduce the order and keep processing time 473 // down to a minimum at scale. These algorithms can be costly in the face 474 // of larger log buffers, or severly limited processing time granted to a 475 // background task at lowest priority. 476 // 477 // This second loop does straight-up expiration from the end of the logs 478 // (again, remember for the specified log buffer id) but does some whitelist 479 // preservation. Thus whitelist is a Hail Mary low priority, blacklists and 480 // spam filtration all take priority. This second loop also checks if a region 481 // lock is causing us to buffer too much in the logs to help the reader(s), 482 // and will tell the slowest reader thread to skip log entries, and if 483 // persistent and hits a further threshold, kill the reader thread. 484 // 485 // The third thread is optional, and only gets hit if there was a whitelist 486 // and more needs to be pruned against the backstop of the region lock. 487 // 488 // mLogElementsLock must be held when this function is called. 489 // 490 bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { 491 LogTimeEntry *oldest = NULL; 492 bool busy = false; 493 bool clearAll = pruneRows == ULONG_MAX; 494 495 LogTimeEntry::lock(); 496 497 // Region locked? 498 LastLogTimes::iterator times = mTimes.begin(); 499 while(times != mTimes.end()) { 500 LogTimeEntry *entry = (*times); 501 if (entry->owned_Locked() && entry->isWatching(id) 502 && (!oldest || 503 (oldest->mStart > entry->mStart) || 504 ((oldest->mStart == entry->mStart) && 505 (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec)))) { 506 oldest = entry; 507 } 508 times++; 509 } 510 511 LogBufferElementCollection::iterator it; 512 513 if (caller_uid != AID_ROOT) { 514 // Only here if clearAll condition (pruneRows == ULONG_MAX) 515 it = mLastSet[id] ? mLast[id] : mLogElements.begin(); 516 while (it != mLogElements.end()) { 517 LogBufferElement *element = *it; 518 519 if ((element->getLogId() != id) || (element->getUid() != caller_uid)) { 520 ++it; 521 continue; 522 } 523 524 if (!mLastSet[id] || ((*mLast[id])->getLogId() != id)) { 525 mLast[id] = it; 526 mLastSet[id] = true; 527 } 528 529 if (oldest && (oldest->mStart <= element->getSequence())) { 530 busy = true; 531 if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { 532 oldest->triggerReader_Locked(); 533 } else { 534 oldest->triggerSkip_Locked(id, pruneRows); 535 } 536 break; 537 } 538 539 it = erase(it); 540 pruneRows--; 541 } 542 LogTimeEntry::unlock(); 543 return busy; 544 } 545 546 // prune by worst offenders; by blacklist, UID, and by PID of system UID 547 bool hasBlacklist = (id != LOG_ID_SECURITY) && mPrune.naughty(); 548 while (!clearAll && (pruneRows > 0)) { 549 // recalculate the worst offender on every batched pass 550 uid_t worst = (uid_t) -1; 551 size_t worst_sizes = 0; 552 size_t second_worst_sizes = 0; 553 pid_t worstPid = 0; // POSIX guarantees PID != 0 554 555 if (worstUidEnabledForLogid(id) && mPrune.worstUidEnabled()) { 556 { // begin scope for UID sorted list 557 std::unique_ptr<const UidEntry *[]> sorted = stats.sort( 558 AID_ROOT, (pid_t)0, 2, id); 559 560 if (sorted.get() && sorted[0] && sorted[1]) { 561 worst_sizes = sorted[0]->getSizes(); 562 // Calculate threshold as 12.5% of available storage 563 size_t threshold = log_buffer_size(id) / 8; 564 if ((worst_sizes > threshold) 565 // Allow time horizon to extend roughly tenfold, assume 566 // average entry length is 100 characters. 567 && (worst_sizes > (10 * sorted[0]->getDropped()))) { 568 worst = sorted[0]->getKey(); 569 second_worst_sizes = sorted[1]->getSizes(); 570 if (second_worst_sizes < threshold) { 571 second_worst_sizes = threshold; 572 } 573 } 574 } 575 } 576 577 if ((worst == AID_SYSTEM) && mPrune.worstPidOfSystemEnabled()) { 578 // begin scope of PID sorted list 579 std::unique_ptr<const PidEntry *[]> sorted = stats.sort( 580 worst, (pid_t)0, 2, id, worst); 581 if (sorted.get() && sorted[0] && sorted[1]) { 582 worstPid = sorted[0]->getKey(); 583 second_worst_sizes = worst_sizes 584 - sorted[0]->getSizes() 585 + sorted[1]->getSizes(); 586 } 587 } 588 } 589 590 // skip if we have neither worst nor naughty filters 591 if ((worst == (uid_t) -1) && !hasBlacklist) { 592 break; 593 } 594 595 bool kick = false; 596 bool leading = true; 597 it = mLastSet[id] ? mLast[id] : mLogElements.begin(); 598 // Perform at least one mandatory garbage collection cycle in following 599 // - clear leading chatty tags 600 // - coalesce chatty tags 601 // - check age-out of preserved logs 602 bool gc = pruneRows <= 1; 603 if (!gc && (worst != (uid_t) -1)) { 604 { // begin scope for uid worst found iterator 605 LogBufferIteratorMap::iterator found = mLastWorstUid[id].find(worst); 606 if ((found != mLastWorstUid[id].end()) 607 && (found->second != mLogElements.end())) { 608 leading = false; 609 it = found->second; 610 } 611 } 612 if (worstPid) { 613 // begin scope for pid worst found iterator 614 LogBufferPidIteratorMap::iterator found 615 = mLastWorstPidOfSystem[id].find(worstPid); 616 if ((found != mLastWorstPidOfSystem[id].end()) 617 && (found->second != mLogElements.end())) { 618 leading = false; 619 it = found->second; 620 } 621 } 622 } 623 static const timespec too_old = { 624 EXPIRE_HOUR_THRESHOLD * 60 * 60, 0 625 }; 626 LogBufferElementCollection::iterator lastt; 627 lastt = mLogElements.end(); 628 --lastt; 629 LogBufferElementLast last; 630 while (it != mLogElements.end()) { 631 LogBufferElement *element = *it; 632 633 if (oldest && (oldest->mStart <= element->getSequence())) { 634 busy = true; 635 if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { 636 oldest->triggerReader_Locked(); 637 } 638 break; 639 } 640 641 if (element->getLogId() != id) { 642 ++it; 643 continue; 644 } 645 // below this point element->getLogId() == id 646 647 if (leading && (!mLastSet[id] || ((*mLast[id])->getLogId() != id))) { 648 mLast[id] = it; 649 mLastSet[id] = true; 650 } 651 652 unsigned short dropped = element->getDropped(); 653 654 // remove any leading drops 655 if (leading && dropped) { 656 it = erase(it); 657 continue; 658 } 659 660 if (dropped && last.coalesce(element, dropped)) { 661 it = erase(it, true); 662 continue; 663 } 664 665 if (hasBlacklist && mPrune.naughty(element)) { 666 last.clear(element); 667 it = erase(it); 668 if (dropped) { 669 continue; 670 } 671 672 pruneRows--; 673 if (pruneRows == 0) { 674 break; 675 } 676 677 if (element->getUid() == worst) { 678 kick = true; 679 if (worst_sizes < second_worst_sizes) { 680 break; 681 } 682 worst_sizes -= element->getMsgLen(); 683 } 684 continue; 685 } 686 687 if ((element->getRealTime() < ((*lastt)->getRealTime() - too_old)) 688 || (element->getRealTime() > (*lastt)->getRealTime())) { 689 break; 690 } 691 692 if (dropped) { 693 last.add(element); 694 if (worstPid 695 && ((!gc && (element->getPid() == worstPid)) 696 || (mLastWorstPidOfSystem[id].find(element->getPid()) 697 == mLastWorstPidOfSystem[id].end()))) { 698 // element->getUid() may not be AID_SYSTEM, next best 699 // watermark if current one empty. 700 mLastWorstPidOfSystem[id][element->getPid()] = it; 701 } 702 if ((!gc && !worstPid && (element->getUid() == worst)) 703 || (mLastWorstUid[id].find(element->getUid()) 704 == mLastWorstUid[id].end())) { 705 mLastWorstUid[id][element->getUid()] = it; 706 } 707 ++it; 708 continue; 709 } 710 711 if ((element->getUid() != worst) 712 || (worstPid && (element->getPid() != worstPid))) { 713 leading = false; 714 last.clear(element); 715 ++it; 716 continue; 717 } 718 // key == worst below here 719 // If worstPid set, then element->getPid() == worstPid below here 720 721 pruneRows--; 722 if (pruneRows == 0) { 723 break; 724 } 725 726 kick = true; 727 728 unsigned short len = element->getMsgLen(); 729 730 // do not create any leading drops 731 if (leading) { 732 it = erase(it); 733 } else { 734 stats.drop(element); 735 element->setDropped(1); 736 if (last.coalesce(element, 1)) { 737 it = erase(it, true); 738 } else { 739 last.add(element); 740 if (worstPid && (!gc 741 || (mLastWorstPidOfSystem[id].find(worstPid) 742 == mLastWorstPidOfSystem[id].end()))) { 743 // element->getUid() may not be AID_SYSTEM, next best 744 // watermark if current one empty. 745 mLastWorstPidOfSystem[id][worstPid] = it; 746 } 747 if ((!gc && !worstPid) || (mLastWorstUid[id].find(worst) 748 == mLastWorstUid[id].end())) { 749 mLastWorstUid[id][worst] = it; 750 } 751 ++it; 752 } 753 } 754 if (worst_sizes < second_worst_sizes) { 755 break; 756 } 757 worst_sizes -= len; 758 } 759 last.clear(); 760 761 if (!kick || !mPrune.worstUidEnabled()) { 762 break; // the following loop will ask bad clients to skip/drop 763 } 764 } 765 766 bool whitelist = false; 767 bool hasWhitelist = (id != LOG_ID_SECURITY) && mPrune.nice() && !clearAll; 768 it = mLastSet[id] ? mLast[id] : mLogElements.begin(); 769 while((pruneRows > 0) && (it != mLogElements.end())) { 770 LogBufferElement *element = *it; 771 772 if (element->getLogId() != id) { 773 it++; 774 continue; 775 } 776 777 if (!mLastSet[id] || ((*mLast[id])->getLogId() != id)) { 778 mLast[id] = it; 779 mLastSet[id] = true; 780 } 781 782 if (oldest && (oldest->mStart <= element->getSequence())) { 783 busy = true; 784 if (whitelist) { 785 break; 786 } 787 788 if (stats.sizes(id) > (2 * log_buffer_size(id))) { 789 // kick a misbehaving log reader client off the island 790 oldest->release_Locked(); 791 } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { 792 oldest->triggerReader_Locked(); 793 } else { 794 oldest->triggerSkip_Locked(id, pruneRows); 795 } 796 break; 797 } 798 799 if (hasWhitelist && !element->getDropped() && mPrune.nice(element)) { 800 // WhiteListed 801 whitelist = true; 802 it++; 803 continue; 804 } 805 806 it = erase(it); 807 pruneRows--; 808 } 809 810 // Do not save the whitelist if we are reader range limited 811 if (whitelist && (pruneRows > 0)) { 812 it = mLastSet[id] ? mLast[id] : mLogElements.begin(); 813 while((it != mLogElements.end()) && (pruneRows > 0)) { 814 LogBufferElement *element = *it; 815 816 if (element->getLogId() != id) { 817 ++it; 818 continue; 819 } 820 821 if (!mLastSet[id] || ((*mLast[id])->getLogId() != id)) { 822 mLast[id] = it; 823 mLastSet[id] = true; 824 } 825 826 if (oldest && (oldest->mStart <= element->getSequence())) { 827 busy = true; 828 if (stats.sizes(id) > (2 * log_buffer_size(id))) { 829 // kick a misbehaving log reader client off the island 830 oldest->release_Locked(); 831 } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { 832 oldest->triggerReader_Locked(); 833 } else { 834 oldest->triggerSkip_Locked(id, pruneRows); 835 } 836 break; 837 } 838 839 it = erase(it); 840 pruneRows--; 841 } 842 } 843 844 LogTimeEntry::unlock(); 845 846 return (pruneRows > 0) && busy; 847 } 848 849 // clear all rows of type "id" from the buffer. 850 bool LogBuffer::clear(log_id_t id, uid_t uid) { 851 bool busy = true; 852 // If it takes more than 4 tries (seconds) to clear, then kill reader(s) 853 for (int retry = 4;;) { 854 if (retry == 1) { // last pass 855 // Check if it is still busy after the sleep, we say prune 856 // one entry, not another clear run, so we are looking for 857 // the quick side effect of the return value to tell us if 858 // we have a _blocked_ reader. 859 pthread_mutex_lock(&mLogElementsLock); 860 busy = prune(id, 1, uid); 861 pthread_mutex_unlock(&mLogElementsLock); 862 // It is still busy, blocked reader(s), lets kill them all! 863 // otherwise, lets be a good citizen and preserve the slow 864 // readers and let the clear run (below) deal with determining 865 // if we are still blocked and return an error code to caller. 866 if (busy) { 867 LogTimeEntry::lock(); 868 LastLogTimes::iterator times = mTimes.begin(); 869 while (times != mTimes.end()) { 870 LogTimeEntry *entry = (*times); 871 // Killer punch 872 if (entry->owned_Locked() && entry->isWatching(id)) { 873 entry->release_Locked(); 874 } 875 times++; 876 } 877 LogTimeEntry::unlock(); 878 } 879 } 880 pthread_mutex_lock(&mLogElementsLock); 881 busy = prune(id, ULONG_MAX, uid); 882 pthread_mutex_unlock(&mLogElementsLock); 883 if (!busy || !--retry) { 884 break; 885 } 886 sleep (1); // Let reader(s) catch up after notification 887 } 888 return busy; 889 } 890 891 // get the used space associated with "id". 892 unsigned long LogBuffer::getSizeUsed(log_id_t id) { 893 pthread_mutex_lock(&mLogElementsLock); 894 size_t retval = stats.sizes(id); 895 pthread_mutex_unlock(&mLogElementsLock); 896 return retval; 897 } 898 899 // set the total space allocated to "id" 900 int LogBuffer::setSize(log_id_t id, unsigned long size) { 901 // Reasonable limits ... 902 if (!valid_size(size)) { 903 return -1; 904 } 905 pthread_mutex_lock(&mLogElementsLock); 906 log_buffer_size(id) = size; 907 pthread_mutex_unlock(&mLogElementsLock); 908 return 0; 909 } 910 911 // get the total space allocated to "id" 912 unsigned long LogBuffer::getSize(log_id_t id) { 913 pthread_mutex_lock(&mLogElementsLock); 914 size_t retval = log_buffer_size(id); 915 pthread_mutex_unlock(&mLogElementsLock); 916 return retval; 917 } 918 919 uint64_t LogBuffer::flushTo( 920 SocketClient *reader, const uint64_t start, 921 bool privileged, bool security, 922 int (*filter)(const LogBufferElement *element, void *arg), void *arg) { 923 LogBufferElementCollection::iterator it; 924 uint64_t max = start; 925 uid_t uid = reader->getUid(); 926 927 pthread_mutex_lock(&mLogElementsLock); 928 929 if (start <= 1) { 930 // client wants to start from the beginning 931 it = mLogElements.begin(); 932 } else { 933 // Client wants to start from some specified time. Chances are 934 // we are better off starting from the end of the time sorted list. 935 for (it = mLogElements.end(); it != mLogElements.begin(); /* do nothing */) { 936 --it; 937 LogBufferElement *element = *it; 938 if (element->getSequence() <= start) { 939 it++; 940 break; 941 } 942 } 943 } 944 945 for (; it != mLogElements.end(); ++it) { 946 LogBufferElement *element = *it; 947 948 if (!privileged && (element->getUid() != uid)) { 949 continue; 950 } 951 952 if (!security && (element->getLogId() == LOG_ID_SECURITY)) { 953 continue; 954 } 955 956 if (element->getSequence() <= start) { 957 continue; 958 } 959 960 // NB: calling out to another object with mLogElementsLock held (safe) 961 if (filter) { 962 int ret = (*filter)(element, arg); 963 if (ret == false) { 964 continue; 965 } 966 if (ret != true) { 967 break; 968 } 969 } 970 971 pthread_mutex_unlock(&mLogElementsLock); 972 973 // range locking in LastLogTimes looks after us 974 max = element->flushTo(reader, this, privileged); 975 976 if (max == element->FLUSH_ERROR) { 977 return max; 978 } 979 980 pthread_mutex_lock(&mLogElementsLock); 981 } 982 pthread_mutex_unlock(&mLogElementsLock); 983 984 return max; 985 } 986 987 std::string LogBuffer::formatStatistics(uid_t uid, pid_t pid, 988 unsigned int logMask) { 989 pthread_mutex_lock(&mLogElementsLock); 990 991 std::string ret = stats.format(uid, pid, logMask); 992 993 pthread_mutex_unlock(&mLogElementsLock); 994 995 return ret; 996 } 997