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 <stdio.h> 19 #include <stdlib.h> 20 #include <string.h> 21 #include <sys/user.h> 22 #include <time.h> 23 #include <unistd.h> 24 25 #include <cutils/properties.h> 26 #include <log/logger.h> 27 28 #include "LogBuffer.h" 29 #include "LogReader.h" 30 #include "LogStatistics.h" 31 #include "LogWhiteBlackList.h" 32 33 // Default 34 #define LOG_BUFFER_SIZE (256 * 1024) // Tuned on a per-platform basis here? 35 #define log_buffer_size(id) mMaxSize[id] 36 #define LOG_BUFFER_MIN_SIZE (64 * 1024UL) 37 #define LOG_BUFFER_MAX_SIZE (256 * 1024 * 1024UL) 38 39 static bool valid_size(unsigned long value) { 40 if ((value < LOG_BUFFER_MIN_SIZE) || (LOG_BUFFER_MAX_SIZE < value)) { 41 return false; 42 } 43 44 long pages = sysconf(_SC_PHYS_PAGES); 45 if (pages < 1) { 46 return true; 47 } 48 49 long pagesize = sysconf(_SC_PAGESIZE); 50 if (pagesize <= 1) { 51 pagesize = PAGE_SIZE; 52 } 53 54 // maximum memory impact a somewhat arbitrary ~3% 55 pages = (pages + 31) / 32; 56 unsigned long maximum = pages * pagesize; 57 58 if ((maximum < LOG_BUFFER_MIN_SIZE) || (LOG_BUFFER_MAX_SIZE < maximum)) { 59 return true; 60 } 61 62 return value <= maximum; 63 } 64 65 static unsigned long property_get_size(const char *key) { 66 char property[PROPERTY_VALUE_MAX]; 67 property_get(key, property, ""); 68 69 char *cp; 70 unsigned long value = strtoul(property, &cp, 10); 71 72 switch(*cp) { 73 case 'm': 74 case 'M': 75 value *= 1024; 76 /* FALLTHRU */ 77 case 'k': 78 case 'K': 79 value *= 1024; 80 /* FALLTHRU */ 81 case '\0': 82 break; 83 84 default: 85 value = 0; 86 } 87 88 if (!valid_size(value)) { 89 value = 0; 90 } 91 92 return value; 93 } 94 95 LogBuffer::LogBuffer(LastLogTimes *times) 96 : mTimes(*times) { 97 pthread_mutex_init(&mLogElementsLock, NULL); 98 dgram_qlen_statistics = false; 99 100 static const char global_tuneable[] = "persist.logd.size"; // Settings App 101 static const char global_default[] = "ro.logd.size"; // BoardConfig.mk 102 103 unsigned long default_size = property_get_size(global_tuneable); 104 if (!default_size) { 105 default_size = property_get_size(global_default); 106 } 107 108 log_id_for_each(i) { 109 char key[PROP_NAME_MAX]; 110 111 snprintf(key, sizeof(key), "%s.%s", 112 global_tuneable, android_log_id_to_name(i)); 113 unsigned long property_size = property_get_size(key); 114 115 if (!property_size) { 116 snprintf(key, sizeof(key), "%s.%s", 117 global_default, android_log_id_to_name(i)); 118 property_size = property_get_size(key); 119 } 120 121 if (!property_size) { 122 property_size = default_size; 123 } 124 125 if (!property_size) { 126 property_size = LOG_BUFFER_SIZE; 127 } 128 129 if (setSize(i, property_size)) { 130 setSize(i, LOG_BUFFER_MIN_SIZE); 131 } 132 } 133 } 134 135 void LogBuffer::log(log_id_t log_id, log_time realtime, 136 uid_t uid, pid_t pid, pid_t tid, 137 const char *msg, unsigned short len) { 138 if ((log_id >= LOG_ID_MAX) || (log_id < 0)) { 139 return; 140 } 141 LogBufferElement *elem = new LogBufferElement(log_id, realtime, 142 uid, pid, tid, msg, len); 143 144 pthread_mutex_lock(&mLogElementsLock); 145 146 // Insert elements in time sorted order if possible 147 // NB: if end is region locked, place element at end of list 148 LogBufferElementCollection::iterator it = mLogElements.end(); 149 LogBufferElementCollection::iterator last = it; 150 while (--it != mLogElements.begin()) { 151 if ((*it)->getRealTime() <= realtime) { 152 // halves the peak performance, use with caution 153 if (dgram_qlen_statistics) { 154 LogBufferElementCollection::iterator ib = it; 155 unsigned short buckets, num = 1; 156 for (unsigned short i = 0; (buckets = stats.dgram_qlen(i)); ++i) { 157 buckets -= num; 158 num += buckets; 159 while (buckets && (--ib != mLogElements.begin())) { 160 --buckets; 161 } 162 if (buckets) { 163 break; 164 } 165 stats.recordDiff( 166 elem->getRealTime() - (*ib)->getRealTime(), i); 167 } 168 } 169 break; 170 } 171 last = it; 172 } 173 174 if (last == mLogElements.end()) { 175 mLogElements.push_back(elem); 176 } else { 177 log_time end = log_time::EPOCH; 178 bool end_set = false; 179 bool end_always = false; 180 181 LogTimeEntry::lock(); 182 183 LastLogTimes::iterator t = mTimes.begin(); 184 while(t != mTimes.end()) { 185 LogTimeEntry *entry = (*t); 186 if (entry->owned_Locked()) { 187 if (!entry->mNonBlock) { 188 end_always = true; 189 break; 190 } 191 if (!end_set || (end <= entry->mEnd)) { 192 end = entry->mEnd; 193 end_set = true; 194 } 195 } 196 t++; 197 } 198 199 if (end_always 200 || (end_set && (end >= (*last)->getMonotonicTime()))) { 201 mLogElements.push_back(elem); 202 } else { 203 mLogElements.insert(last,elem); 204 } 205 206 LogTimeEntry::unlock(); 207 } 208 209 stats.add(len, log_id, uid, pid); 210 maybePrune(log_id); 211 pthread_mutex_unlock(&mLogElementsLock); 212 } 213 214 // If we're using more than 256K of memory for log entries, prune 215 // at least 10% of the log entries. 216 // 217 // mLogElementsLock must be held when this function is called. 218 void LogBuffer::maybePrune(log_id_t id) { 219 size_t sizes = stats.sizes(id); 220 if (sizes > log_buffer_size(id)) { 221 size_t sizeOver90Percent = sizes - ((log_buffer_size(id) * 9) / 10); 222 size_t elements = stats.elements(id); 223 unsigned long pruneRows = elements * sizeOver90Percent / sizes; 224 elements /= 10; 225 if (pruneRows <= elements) { 226 pruneRows = elements; 227 } 228 prune(id, pruneRows); 229 } 230 } 231 232 // prune "pruneRows" of type "id" from the buffer. 233 // 234 // mLogElementsLock must be held when this function is called. 235 void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { 236 LogTimeEntry *oldest = NULL; 237 238 LogTimeEntry::lock(); 239 240 // Region locked? 241 LastLogTimes::iterator t = mTimes.begin(); 242 while(t != mTimes.end()) { 243 LogTimeEntry *entry = (*t); 244 if (entry->owned_Locked() 245 && (!oldest || (oldest->mStart > entry->mStart))) { 246 oldest = entry; 247 } 248 t++; 249 } 250 251 LogBufferElementCollection::iterator it; 252 253 if (caller_uid != AID_ROOT) { 254 for(it = mLogElements.begin(); it != mLogElements.end();) { 255 LogBufferElement *e = *it; 256 257 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 258 break; 259 } 260 261 if (e->getLogId() != id) { 262 ++it; 263 continue; 264 } 265 266 uid_t uid = e->getUid(); 267 268 if (uid == caller_uid) { 269 it = mLogElements.erase(it); 270 unsigned short len = e->getMsgLen(); 271 stats.subtract(len, id, uid, e->getPid()); 272 delete e; 273 pruneRows--; 274 if (pruneRows == 0) { 275 break; 276 } 277 } else { 278 ++it; 279 } 280 } 281 LogTimeEntry::unlock(); 282 return; 283 } 284 285 // prune by worst offender by uid 286 while (pruneRows > 0) { 287 // recalculate the worst offender on every batched pass 288 uid_t worst = (uid_t) -1; 289 size_t worst_sizes = 0; 290 size_t second_worst_sizes = 0; 291 292 if ((id != LOG_ID_CRASH) && mPrune.worstUidEnabled()) { 293 LidStatistics &l = stats.id(id); 294 l.sort(); 295 UidStatisticsCollection::iterator iu = l.begin(); 296 if (iu != l.end()) { 297 UidStatistics *u = *iu; 298 worst = u->getUid(); 299 worst_sizes = u->sizes(); 300 if (++iu != l.end()) { 301 second_worst_sizes = (*iu)->sizes(); 302 } 303 } 304 } 305 306 bool kick = false; 307 for(it = mLogElements.begin(); it != mLogElements.end();) { 308 LogBufferElement *e = *it; 309 310 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 311 break; 312 } 313 314 if (e->getLogId() != id) { 315 ++it; 316 continue; 317 } 318 319 uid_t uid = e->getUid(); 320 321 if (uid == worst) { 322 it = mLogElements.erase(it); 323 unsigned short len = e->getMsgLen(); 324 stats.subtract(len, id, worst, e->getPid()); 325 delete e; 326 kick = true; 327 pruneRows--; 328 if ((pruneRows == 0) || (worst_sizes < second_worst_sizes)) { 329 break; 330 } 331 worst_sizes -= len; 332 } else if (mPrune.naughty(e)) { // BlackListed 333 it = mLogElements.erase(it); 334 stats.subtract(e->getMsgLen(), id, uid, e->getPid()); 335 delete e; 336 pruneRows--; 337 if (pruneRows == 0) { 338 break; 339 } 340 } else { 341 ++it; 342 } 343 } 344 345 if (!kick || !mPrune.worstUidEnabled()) { 346 break; // the following loop will ask bad clients to skip/drop 347 } 348 } 349 350 bool whitelist = false; 351 it = mLogElements.begin(); 352 while((pruneRows > 0) && (it != mLogElements.end())) { 353 LogBufferElement *e = *it; 354 if (e->getLogId() == id) { 355 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 356 if (!whitelist) { 357 if (stats.sizes(id) > (2 * log_buffer_size(id))) { 358 // kick a misbehaving log reader client off the island 359 oldest->release_Locked(); 360 } else { 361 oldest->triggerSkip_Locked(pruneRows); 362 } 363 } 364 break; 365 } 366 367 if (mPrune.nice(e)) { // WhiteListed 368 whitelist = true; 369 it++; 370 continue; 371 } 372 373 it = mLogElements.erase(it); 374 stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid()); 375 delete e; 376 pruneRows--; 377 } else { 378 it++; 379 } 380 } 381 382 if (whitelist && (pruneRows > 0)) { 383 it = mLogElements.begin(); 384 while((it != mLogElements.end()) && (pruneRows > 0)) { 385 LogBufferElement *e = *it; 386 if (e->getLogId() == id) { 387 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 388 if (stats.sizes(id) > (2 * log_buffer_size(id))) { 389 // kick a misbehaving log reader client off the island 390 oldest->release_Locked(); 391 } else { 392 oldest->triggerSkip_Locked(pruneRows); 393 } 394 break; 395 } 396 it = mLogElements.erase(it); 397 stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid()); 398 delete e; 399 pruneRows--; 400 } else { 401 it++; 402 } 403 } 404 } 405 406 LogTimeEntry::unlock(); 407 } 408 409 // clear all rows of type "id" from the buffer. 410 void LogBuffer::clear(log_id_t id, uid_t uid) { 411 pthread_mutex_lock(&mLogElementsLock); 412 prune(id, ULONG_MAX, uid); 413 pthread_mutex_unlock(&mLogElementsLock); 414 } 415 416 // get the used space associated with "id". 417 unsigned long LogBuffer::getSizeUsed(log_id_t id) { 418 pthread_mutex_lock(&mLogElementsLock); 419 size_t retval = stats.sizes(id); 420 pthread_mutex_unlock(&mLogElementsLock); 421 return retval; 422 } 423 424 // set the total space allocated to "id" 425 int LogBuffer::setSize(log_id_t id, unsigned long size) { 426 // Reasonable limits ... 427 if (!valid_size(size)) { 428 return -1; 429 } 430 pthread_mutex_lock(&mLogElementsLock); 431 log_buffer_size(id) = size; 432 pthread_mutex_unlock(&mLogElementsLock); 433 return 0; 434 } 435 436 // get the total space allocated to "id" 437 unsigned long LogBuffer::getSize(log_id_t id) { 438 pthread_mutex_lock(&mLogElementsLock); 439 size_t retval = log_buffer_size(id); 440 pthread_mutex_unlock(&mLogElementsLock); 441 return retval; 442 } 443 444 log_time LogBuffer::flushTo( 445 SocketClient *reader, const log_time start, bool privileged, 446 bool (*filter)(const LogBufferElement *element, void *arg), void *arg) { 447 LogBufferElementCollection::iterator it; 448 log_time max = start; 449 uid_t uid = reader->getUid(); 450 451 pthread_mutex_lock(&mLogElementsLock); 452 for (it = mLogElements.begin(); it != mLogElements.end(); ++it) { 453 LogBufferElement *element = *it; 454 455 if (!privileged && (element->getUid() != uid)) { 456 continue; 457 } 458 459 if (element->getMonotonicTime() <= start) { 460 continue; 461 } 462 463 // NB: calling out to another object with mLogElementsLock held (safe) 464 if (filter && !(*filter)(element, arg)) { 465 continue; 466 } 467 468 pthread_mutex_unlock(&mLogElementsLock); 469 470 // range locking in LastLogTimes looks after us 471 max = element->flushTo(reader); 472 473 if (max == element->FLUSH_ERROR) { 474 return max; 475 } 476 477 pthread_mutex_lock(&mLogElementsLock); 478 } 479 pthread_mutex_unlock(&mLogElementsLock); 480 481 return max; 482 } 483 484 void LogBuffer::formatStatistics(char **strp, uid_t uid, unsigned int logMask) { 485 log_time oldest(CLOCK_MONOTONIC); 486 487 pthread_mutex_lock(&mLogElementsLock); 488 489 // Find oldest element in the log(s) 490 LogBufferElementCollection::iterator it; 491 for (it = mLogElements.begin(); it != mLogElements.end(); ++it) { 492 LogBufferElement *element = *it; 493 494 if ((logMask & (1 << element->getLogId()))) { 495 oldest = element->getMonotonicTime(); 496 break; 497 } 498 } 499 500 stats.format(strp, uid, logMask, oldest); 501 502 pthread_mutex_unlock(&mLogElementsLock); 503 } 504