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 : dgramQlenStatistics(false) 97 , mTimes(*times) { 98 pthread_mutex_init(&mLogElementsLock, NULL); 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 (dgramQlenStatistics) { 154 LogBufferElementCollection::iterator ib = it; 155 unsigned short buckets, num = 1; 156 for (unsigned short i = 0; (buckets = stats.dgramQlen(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 stats.subtract(e->getMsgLen(), id, uid, e->getPid()); 271 delete e; 272 pruneRows--; 273 if (pruneRows == 0) { 274 break; 275 } 276 } else { 277 ++it; 278 } 279 } 280 LogTimeEntry::unlock(); 281 return; 282 } 283 284 // prune by worst offender by uid 285 while (pruneRows > 0) { 286 // recalculate the worst offender on every batched pass 287 uid_t worst = (uid_t) -1; 288 size_t worst_sizes = 0; 289 size_t second_worst_sizes = 0; 290 291 if ((id != LOG_ID_CRASH) && mPrune.worstUidEnabled()) { 292 LidStatistics &l = stats.id(id); 293 l.sort(); 294 UidStatisticsCollection::iterator iu = l.begin(); 295 if (iu != l.end()) { 296 UidStatistics *u = *iu; 297 worst = u->getUid(); 298 worst_sizes = u->sizes(); 299 if (++iu != l.end()) { 300 second_worst_sizes = (*iu)->sizes(); 301 } 302 } 303 } 304 305 bool kick = false; 306 for(it = mLogElements.begin(); it != mLogElements.end();) { 307 LogBufferElement *e = *it; 308 309 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 310 break; 311 } 312 313 if (e->getLogId() != id) { 314 ++it; 315 continue; 316 } 317 318 uid_t uid = e->getUid(); 319 320 if ((uid == worst) || mPrune.naughty(e)) { // Worst or BlackListed 321 it = mLogElements.erase(it); 322 unsigned short len = e->getMsgLen(); 323 stats.subtract(len, id, uid, e->getPid()); 324 delete e; 325 pruneRows--; 326 if (uid == worst) { 327 kick = true; 328 if ((pruneRows == 0) || (worst_sizes < second_worst_sizes)) { 329 break; 330 } 331 worst_sizes -= len; 332 } else if (pruneRows == 0) { 333 break; 334 } 335 } else { 336 ++it; 337 } 338 } 339 340 if (!kick || !mPrune.worstUidEnabled()) { 341 break; // the following loop will ask bad clients to skip/drop 342 } 343 } 344 345 bool whitelist = false; 346 it = mLogElements.begin(); 347 while((pruneRows > 0) && (it != mLogElements.end())) { 348 LogBufferElement *e = *it; 349 if (e->getLogId() == id) { 350 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 351 if (!whitelist) { 352 if (stats.sizes(id) > (2 * log_buffer_size(id))) { 353 // kick a misbehaving log reader client off the island 354 oldest->release_Locked(); 355 } else { 356 oldest->triggerSkip_Locked(pruneRows); 357 } 358 } 359 break; 360 } 361 362 if (mPrune.nice(e)) { // WhiteListed 363 whitelist = true; 364 it++; 365 continue; 366 } 367 368 it = mLogElements.erase(it); 369 stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid()); 370 delete e; 371 pruneRows--; 372 } else { 373 it++; 374 } 375 } 376 377 if (whitelist && (pruneRows > 0)) { 378 it = mLogElements.begin(); 379 while((it != mLogElements.end()) && (pruneRows > 0)) { 380 LogBufferElement *e = *it; 381 if (e->getLogId() == id) { 382 if (oldest && (oldest->mStart <= e->getMonotonicTime())) { 383 if (stats.sizes(id) > (2 * log_buffer_size(id))) { 384 // kick a misbehaving log reader client off the island 385 oldest->release_Locked(); 386 } else { 387 oldest->triggerSkip_Locked(pruneRows); 388 } 389 break; 390 } 391 it = mLogElements.erase(it); 392 stats.subtract(e->getMsgLen(), id, e->getUid(), e->getPid()); 393 delete e; 394 pruneRows--; 395 } else { 396 it++; 397 } 398 } 399 } 400 401 LogTimeEntry::unlock(); 402 } 403 404 // clear all rows of type "id" from the buffer. 405 void LogBuffer::clear(log_id_t id, uid_t uid) { 406 pthread_mutex_lock(&mLogElementsLock); 407 prune(id, ULONG_MAX, uid); 408 pthread_mutex_unlock(&mLogElementsLock); 409 } 410 411 // get the used space associated with "id". 412 unsigned long LogBuffer::getSizeUsed(log_id_t id) { 413 pthread_mutex_lock(&mLogElementsLock); 414 size_t retval = stats.sizes(id); 415 pthread_mutex_unlock(&mLogElementsLock); 416 return retval; 417 } 418 419 // set the total space allocated to "id" 420 int LogBuffer::setSize(log_id_t id, unsigned long size) { 421 // Reasonable limits ... 422 if (!valid_size(size)) { 423 return -1; 424 } 425 pthread_mutex_lock(&mLogElementsLock); 426 log_buffer_size(id) = size; 427 pthread_mutex_unlock(&mLogElementsLock); 428 return 0; 429 } 430 431 // get the total space allocated to "id" 432 unsigned long LogBuffer::getSize(log_id_t id) { 433 pthread_mutex_lock(&mLogElementsLock); 434 size_t retval = log_buffer_size(id); 435 pthread_mutex_unlock(&mLogElementsLock); 436 return retval; 437 } 438 439 log_time LogBuffer::flushTo( 440 SocketClient *reader, const log_time start, bool privileged, 441 bool (*filter)(const LogBufferElement *element, void *arg), void *arg) { 442 LogBufferElementCollection::iterator it; 443 log_time max = start; 444 uid_t uid = reader->getUid(); 445 446 pthread_mutex_lock(&mLogElementsLock); 447 for (it = mLogElements.begin(); it != mLogElements.end(); ++it) { 448 LogBufferElement *element = *it; 449 450 if (!privileged && (element->getUid() != uid)) { 451 continue; 452 } 453 454 if (element->getMonotonicTime() <= start) { 455 continue; 456 } 457 458 // NB: calling out to another object with mLogElementsLock held (safe) 459 if (filter && !(*filter)(element, arg)) { 460 continue; 461 } 462 463 pthread_mutex_unlock(&mLogElementsLock); 464 465 // range locking in LastLogTimes looks after us 466 max = element->flushTo(reader); 467 468 if (max == element->FLUSH_ERROR) { 469 return max; 470 } 471 472 pthread_mutex_lock(&mLogElementsLock); 473 } 474 pthread_mutex_unlock(&mLogElementsLock); 475 476 return max; 477 } 478 479 void LogBuffer::formatStatistics(char **strp, uid_t uid, unsigned int logMask) { 480 log_time oldest(CLOCK_MONOTONIC); 481 482 pthread_mutex_lock(&mLogElementsLock); 483 484 // Find oldest element in the log(s) 485 LogBufferElementCollection::iterator it; 486 for (it = mLogElements.begin(); it != mLogElements.end(); ++it) { 487 LogBufferElement *element = *it; 488 489 if ((logMask & (1 << element->getLogId()))) { 490 oldest = element->getMonotonicTime(); 491 break; 492 } 493 } 494 495 stats.format(strp, uid, logMask, oldest); 496 497 pthread_mutex_unlock(&mLogElementsLock); 498 } 499