1 /*
2 * Copyright (C) 2014 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include "LogStatistics.h"
18
19 #include <ctype.h>
20 #include <fcntl.h>
21 #include <inttypes.h>
22 #include <pwd.h>
23 #include <stdio.h>
24 #include <string.h>
25 #include <sys/types.h>
26 #include <unistd.h>
27
28 #include <list>
29 #include <vector>
30
31 #include <android-base/logging.h>
32 #include <android-base/strings.h>
33 #include <private/android_logger.h>
34
35 #include "LogBufferElement.h"
36
37 static const uint64_t hourSec = 60 * 60;
38 static const uint64_t monthSec = 31 * 24 * hourSec;
39
40 std::atomic<size_t> LogStatistics::SizesTotal;
41
TagNameKey(const LogStatisticsElement & element)42 static std::string TagNameKey(const LogStatisticsElement& element) {
43 if (IsBinary(element.log_id)) {
44 uint32_t tag = element.tag;
45 if (tag) {
46 const char* cp = android::tagToName(tag);
47 if (cp) {
48 return std::string(cp);
49 }
50 }
51 return android::base::StringPrintf("[%" PRIu32 "]", tag);
52 }
53 const char* msg = element.msg;
54 if (!msg) {
55 return "chatty";
56 }
57 ++msg;
58 uint16_t len = element.msg_len;
59 len = (len <= 1) ? 0 : strnlen(msg, len - 1);
60 if (!len) {
61 return "<NULL>";
62 }
63 return std::string(msg, len);
64 }
65
LogStatistics(bool enable_statistics,bool track_total_size,std::optional<log_time> start_time)66 LogStatistics::LogStatistics(bool enable_statistics, bool track_total_size,
67 std::optional<log_time> start_time)
68 : enable(enable_statistics), track_total_size_(track_total_size) {
69 log_time now(CLOCK_REALTIME);
70 log_id_for_each(id) {
71 mSizes[id] = 0;
72 mElements[id] = 0;
73 mDroppedElements[id] = 0;
74 mSizesTotal[id] = 0;
75 mElementsTotal[id] = 0;
76 if (start_time) {
77 mOldest[id] = *start_time;
78 mNewest[id] = *start_time;
79 } else {
80 mOldest[id] = now;
81 mNewest[id] = now;
82 }
83 mNewestDropped[id] = now;
84 }
85 }
86
87 namespace android {
88
sizesTotal()89 size_t sizesTotal() {
90 return LogStatistics::sizesTotal();
91 }
92
93 // caller must own and free character string
pidToName(pid_t pid)94 char* pidToName(pid_t pid) {
95 char* retval = nullptr;
96 if (pid == 0) { // special case from auditd/klogd for kernel
97 retval = strdup("logd");
98 } else {
99 char buffer[512];
100 snprintf(buffer, sizeof(buffer), "/proc/%u/cmdline", pid);
101 int fd = open(buffer, O_RDONLY | O_CLOEXEC);
102 if (fd >= 0) {
103 ssize_t ret = read(fd, buffer, sizeof(buffer));
104 if (ret > 0) {
105 buffer[sizeof(buffer) - 1] = '\0';
106 // frameworks intermediate state
107 if (fastcmp<strcmp>(buffer, "<pre-initialized>")) {
108 retval = strdup(buffer);
109 }
110 }
111 close(fd);
112 }
113 }
114 return retval;
115 }
116 }
117
AddTotal(log_id_t log_id,uint16_t size)118 void LogStatistics::AddTotal(log_id_t log_id, uint16_t size) {
119 auto lock = std::lock_guard{lock_};
120
121 mSizesTotal[log_id] += size;
122 SizesTotal += size;
123 ++mElementsTotal[log_id];
124 }
125
Add(LogStatisticsElement element)126 void LogStatistics::Add(LogStatisticsElement element) {
127 auto lock = std::lock_guard{lock_};
128
129 if (!track_total_size_) {
130 element.total_len = element.msg_len;
131 }
132
133 log_id_t log_id = element.log_id;
134 uint16_t size = element.total_len;
135 mSizes[log_id] += size;
136 ++mElements[log_id];
137
138 // When caller adding a chatty entry, they will have already
139 // called add() and subtract() for each entry as they are
140 // evaluated and trimmed, thus recording size and number of
141 // elements, but we must recognize the manufactured dropped
142 // entry as not contributing to the lifetime totals.
143 if (element.dropped_count) {
144 ++mDroppedElements[log_id];
145 } else {
146 mSizesTotal[log_id] += size;
147 SizesTotal += size;
148 ++mElementsTotal[log_id];
149 }
150
151 log_time stamp(element.realtime);
152 if (mNewest[log_id] < stamp) {
153 // A major time update invalidates the statistics :-(
154 log_time diff = stamp - mNewest[log_id];
155 mNewest[log_id] = stamp;
156
157 if (diff.tv_sec > hourSec) {
158 // approximate Do-Your-Best fixup
159 diff += mOldest[log_id];
160 if ((diff > stamp) && ((diff - stamp).tv_sec < hourSec)) {
161 diff = stamp;
162 }
163 if (diff <= stamp) {
164 mOldest[log_id] = diff;
165 if (mNewestDropped[log_id] < diff) {
166 mNewestDropped[log_id] = diff;
167 }
168 }
169 }
170 }
171
172 if (log_id == LOG_ID_KERNEL) {
173 return;
174 }
175
176 uidTable[log_id].Add(element.uid, element);
177 if (element.uid == AID_SYSTEM) {
178 pidSystemTable[log_id].Add(element.pid, element);
179 }
180
181 if (!enable) {
182 return;
183 }
184
185 pidTable.Add(element.pid, element);
186 tidTable.Add(element.tid, element);
187
188 uint32_t tag = element.tag;
189 if (tag) {
190 if (log_id == LOG_ID_SECURITY) {
191 securityTagTable.Add(tag, element);
192 } else {
193 tagTable.Add(tag, element);
194 }
195 }
196
197 if (!element.dropped_count) {
198 tagNameTable.Add(TagNameKey(element), element);
199 }
200 }
201
Subtract(LogStatisticsElement element)202 void LogStatistics::Subtract(LogStatisticsElement element) {
203 auto lock = std::lock_guard{lock_};
204
205 if (!track_total_size_) {
206 element.total_len = element.msg_len;
207 }
208
209 log_id_t log_id = element.log_id;
210 uint16_t size = element.total_len;
211 mSizes[log_id] -= size;
212 --mElements[log_id];
213 if (element.dropped_count) {
214 --mDroppedElements[log_id];
215 }
216
217 if (mOldest[log_id] < element.realtime) {
218 mOldest[log_id] = element.realtime;
219 }
220
221 if (log_id == LOG_ID_KERNEL) {
222 return;
223 }
224
225 uidTable[log_id].Subtract(element.uid, element);
226 if (element.uid == AID_SYSTEM) {
227 pidSystemTable[log_id].Subtract(element.pid, element);
228 }
229
230 if (!enable) {
231 return;
232 }
233
234 pidTable.Subtract(element.pid, element);
235 tidTable.Subtract(element.tid, element);
236
237 uint32_t tag = element.tag;
238 if (tag) {
239 if (log_id == LOG_ID_SECURITY) {
240 securityTagTable.Subtract(tag, element);
241 } else {
242 tagTable.Subtract(tag, element);
243 }
244 }
245
246 if (!element.dropped_count) {
247 tagNameTable.Subtract(TagNameKey(element), element);
248 }
249 }
250
251 // Atomically set an entry to drop
252 // entry->setDropped(1) must follow this call, caller should do this explicitly.
Drop(LogStatisticsElement element)253 void LogStatistics::Drop(LogStatisticsElement element) {
254 CHECK_EQ(element.dropped_count, 0U);
255
256 auto lock = std::lock_guard{lock_};
257 log_id_t log_id = element.log_id;
258 uint16_t size = element.msg_len;
259 mSizes[log_id] -= size;
260 ++mDroppedElements[log_id];
261
262 if (mNewestDropped[log_id] < element.realtime) {
263 mNewestDropped[log_id] = element.realtime;
264 }
265
266 uidTable[log_id].Drop(element.uid, element);
267 if (element.uid == AID_SYSTEM) {
268 pidSystemTable[log_id].Drop(element.pid, element);
269 }
270
271 if (!enable) {
272 return;
273 }
274
275 pidTable.Drop(element.pid, element);
276 tidTable.Drop(element.tid, element);
277
278 uint32_t tag = element.tag;
279 if (tag) {
280 if (log_id == LOG_ID_SECURITY) {
281 securityTagTable.Drop(tag, element);
282 } else {
283 tagTable.Drop(tag, element);
284 }
285 }
286
287 tagNameTable.Subtract(TagNameKey(element), element);
288 }
289
Erase(LogStatisticsElement element)290 void LogStatistics::Erase(LogStatisticsElement element) {
291 CHECK_GT(element.dropped_count, 0U);
292 CHECK_EQ(element.msg_len, 0U);
293
294 auto lock = std::lock_guard{lock_};
295
296 if (!track_total_size_) {
297 element.total_len = 0;
298 }
299
300 log_id_t log_id = element.log_id;
301 --mElements[log_id];
302 --mDroppedElements[log_id];
303 mSizes[log_id] -= element.total_len;
304
305 uidTable[log_id].Erase(element.uid, element);
306 if (element.uid == AID_SYSTEM) {
307 pidSystemTable[log_id].Erase(element.pid, element);
308 }
309
310 if (!enable) {
311 return;
312 }
313
314 pidTable.Erase(element.pid, element);
315 tidTable.Erase(element.tid, element);
316
317 uint32_t tag = element.tag;
318 if (tag) {
319 if (log_id == LOG_ID_SECURITY) {
320 securityTagTable.Erase(tag, element);
321 } else {
322 tagTable.Erase(tag, element);
323 }
324 }
325 }
326
UidToName(uid_t uid) const327 const char* LogStatistics::UidToName(uid_t uid) const {
328 auto lock = std::lock_guard{lock_};
329 return UidToNameLocked(uid);
330 }
331
332 // caller must own and free character string
UidToNameLocked(uid_t uid) const333 const char* LogStatistics::UidToNameLocked(uid_t uid) const {
334 // Local hard coded favourites
335 if (uid == AID_LOGD) {
336 return strdup("auditd");
337 }
338
339 // Android system
340 if (uid < AID_APP) {
341 // in bionic, thread safe as long as we copy the results
342 struct passwd* pwd = getpwuid(uid);
343 if (pwd) {
344 return strdup(pwd->pw_name);
345 }
346 }
347
348 // Parse /data/system/packages.list
349 uid_t userId = uid % AID_USER_OFFSET;
350 const char* name = android::uidToName(userId);
351 if (!name && (userId > (AID_SHARED_GID_START - AID_APP))) {
352 name = android::uidToName(userId - (AID_SHARED_GID_START - AID_APP));
353 }
354 if (name) {
355 return name;
356 }
357
358 // Android application
359 if (uid >= AID_APP) {
360 struct passwd* pwd = getpwuid(uid);
361 if (pwd) {
362 return strdup(pwd->pw_name);
363 }
364 }
365
366 // report uid -> pid(s) -> pidToName if unique
367 for (pidTable_t::const_iterator it = pidTable.begin(); it != pidTable.end();
368 ++it) {
369 const PidEntry& entry = it->second;
370
371 if (entry.uid() == uid) {
372 const char* nameTmp = entry.name();
373
374 if (nameTmp) {
375 if (!name) {
376 name = strdup(nameTmp);
377 } else if (fastcmp<strcmp>(name, nameTmp)) {
378 free(const_cast<char*>(name));
379 name = nullptr;
380 break;
381 }
382 }
383 }
384 }
385
386 // No one
387 return name;
388 }
389
390 template <typename TKey, typename TEntry>
WorstTwoWithThreshold(const LogHashtable<TKey,TEntry> & table,size_t threshold,int * worst,size_t * worst_sizes,size_t * second_worst_sizes) const391 void LogStatistics::WorstTwoWithThreshold(const LogHashtable<TKey, TEntry>& table, size_t threshold,
392 int* worst, size_t* worst_sizes,
393 size_t* second_worst_sizes) const {
394 std::array<const TKey*, 2> max_keys;
395 std::array<const TEntry*, 2> max_entries;
396 table.MaxEntries(AID_ROOT, 0, max_keys, max_entries);
397 if (max_entries[0] == nullptr || max_entries[1] == nullptr) {
398 return;
399 }
400 *worst_sizes = max_entries[0]->getSizes();
401 // b/24782000: Allow time horizon to extend roughly tenfold, assume average entry length is
402 // 100 characters.
403 if (*worst_sizes > threshold && *worst_sizes > (10 * max_entries[0]->dropped_count())) {
404 *worst = *max_keys[0];
405 *second_worst_sizes = max_entries[1]->getSizes();
406 if (*second_worst_sizes < threshold) {
407 *second_worst_sizes = threshold;
408 }
409 }
410 }
411
WorstTwoUids(log_id id,size_t threshold,int * worst,size_t * worst_sizes,size_t * second_worst_sizes) const412 void LogStatistics::WorstTwoUids(log_id id, size_t threshold, int* worst, size_t* worst_sizes,
413 size_t* second_worst_sizes) const {
414 auto lock = std::lock_guard{lock_};
415 WorstTwoWithThreshold(uidTable[id], threshold, worst, worst_sizes, second_worst_sizes);
416 }
417
WorstTwoTags(size_t threshold,int * worst,size_t * worst_sizes,size_t * second_worst_sizes) const418 void LogStatistics::WorstTwoTags(size_t threshold, int* worst, size_t* worst_sizes,
419 size_t* second_worst_sizes) const {
420 auto lock = std::lock_guard{lock_};
421 WorstTwoWithThreshold(tagTable, threshold, worst, worst_sizes, second_worst_sizes);
422 }
423
WorstTwoSystemPids(log_id id,size_t worst_uid_sizes,int * worst,size_t * second_worst_sizes) const424 void LogStatistics::WorstTwoSystemPids(log_id id, size_t worst_uid_sizes, int* worst,
425 size_t* second_worst_sizes) const {
426 auto lock = std::lock_guard{lock_};
427 std::array<const pid_t*, 2> max_keys;
428 std::array<const PidEntry*, 2> max_entries;
429 pidSystemTable[id].MaxEntries(AID_SYSTEM, 0, max_keys, max_entries);
430 if (max_entries[0] == nullptr || max_entries[1] == nullptr) {
431 return;
432 }
433
434 *worst = *max_keys[0];
435 *second_worst_sizes = worst_uid_sizes - max_entries[0]->getSizes() + max_entries[1]->getSizes();
436 }
437
438 // Prune at most 10% of the log entries or maxPrune, whichever is less.
ShouldPrune(log_id id,unsigned long max_size,unsigned long * prune_rows) const439 bool LogStatistics::ShouldPrune(log_id id, unsigned long max_size,
440 unsigned long* prune_rows) const {
441 static constexpr size_t kMinPrune = 4;
442 static constexpr size_t kMaxPrune = 256;
443
444 auto lock = std::lock_guard{lock_};
445 size_t sizes = mSizes[id];
446 if (sizes <= max_size) {
447 return false;
448 }
449 size_t size_over = sizes - ((max_size * 9) / 10);
450 size_t elements = mElements[id] - mDroppedElements[id];
451 size_t min_elements = elements / 100;
452 if (min_elements < kMinPrune) {
453 min_elements = kMinPrune;
454 }
455 *prune_rows = elements * size_over / sizes;
456 if (*prune_rows < min_elements) {
457 *prune_rows = min_elements;
458 }
459 if (*prune_rows > kMaxPrune) {
460 *prune_rows = kMaxPrune;
461 }
462
463 return true;
464 }
465
formatHeader(const std::string & name,log_id_t id) const466 std::string UidEntry::formatHeader(const std::string& name, log_id_t id) const {
467 bool isprune = worstUidEnabledForLogid(id);
468 return formatLine(android::base::StringPrintf(name.c_str(),
469 android_log_id_to_name(id)),
470 std::string("Size"),
471 std::string(isprune ? "+/- Pruned" : "")) +
472 formatLine(std::string("UID PACKAGE"), std::string("BYTES"),
473 std::string(isprune ? "NUM" : ""));
474 }
475
476 // Helper to truncate name, if too long, and add name dressings
FormatTmp(const char * nameTmp,uid_t uid,std::string & name,std::string & size,size_t nameLen) const477 void LogStatistics::FormatTmp(const char* nameTmp, uid_t uid, std::string& name, std::string& size,
478 size_t nameLen) const {
479 const char* allocNameTmp = nullptr;
480 if (!nameTmp) nameTmp = allocNameTmp = UidToNameLocked(uid);
481 if (nameTmp) {
482 size_t lenSpace = std::max(nameLen - name.length(), (size_t)1);
483 size_t len = EntryBase::TOTAL_LEN - EntryBase::PRUNED_LEN - size.length() - name.length() -
484 lenSpace - 2;
485 size_t lenNameTmp = strlen(nameTmp);
486 while ((len < lenNameTmp) && (lenSpace > 1)) {
487 ++len;
488 --lenSpace;
489 }
490 name += android::base::StringPrintf("%*s", (int)lenSpace, "");
491 if (len < lenNameTmp) {
492 name += "...";
493 nameTmp += lenNameTmp - std::max(len - 3, (size_t)1);
494 }
495 name += nameTmp;
496 free(const_cast<char*>(allocNameTmp));
497 }
498 }
499
format(const LogStatistics & stat,log_id_t id,uid_t uid) const500 std::string UidEntry::format(const LogStatistics& stat, log_id_t id, uid_t uid) const
501 REQUIRES(stat.lock_) {
502 std::string name = android::base::StringPrintf("%u", uid);
503 std::string size = android::base::StringPrintf("%zu", getSizes());
504
505 stat.FormatTmp(nullptr, uid, name, size, 6);
506
507 std::string pruned = "";
508 if (worstUidEnabledForLogid(id)) {
509 size_t totalDropped = 0;
510 for (LogStatistics::uidTable_t::const_iterator it =
511 stat.uidTable[id].begin();
512 it != stat.uidTable[id].end(); ++it) {
513 totalDropped += it->second.dropped_count();
514 }
515 size_t sizes = stat.mSizes[id];
516 size_t totalSize = stat.mSizesTotal[id];
517 size_t totalElements = stat.mElementsTotal[id];
518 float totalVirtualSize =
519 (float)sizes + (float)totalDropped * totalSize / totalElements;
520 size_t entrySize = getSizes();
521 float virtualEntrySize = entrySize;
522 int realPermille = virtualEntrySize * 1000.0 / sizes;
523 size_t dropped = dropped_count();
524 if (dropped) {
525 pruned = android::base::StringPrintf("%zu", dropped);
526 virtualEntrySize += (float)dropped * totalSize / totalElements;
527 }
528 int virtualPermille = virtualEntrySize * 1000.0 / totalVirtualSize;
529 int permille =
530 (realPermille - virtualPermille) * 1000L / (virtualPermille ?: 1);
531 if ((permille < -1) || (1 < permille)) {
532 std::string change;
533 const char* units = "%";
534 const char* prefix = (permille > 0) ? "+" : "";
535
536 if (permille > 999) {
537 permille = (permille + 1000) / 100; // Now tenths fold
538 units = "X";
539 prefix = "";
540 }
541 if ((-99 < permille) && (permille < 99)) {
542 change = android::base::StringPrintf(
543 "%s%d.%u%s", prefix, permille / 10,
544 ((permille < 0) ? (-permille % 10) : (permille % 10)),
545 units);
546 } else {
547 change = android::base::StringPrintf(
548 "%s%d%s", prefix, (permille + 5) / 10, units);
549 }
550 ssize_t spaces = EntryBase::PRUNED_LEN - 2 - pruned.length() - change.length();
551 if ((spaces <= 0) && pruned.length()) {
552 spaces = 1;
553 }
554 if (spaces > 0) {
555 change += android::base::StringPrintf("%*s", (int)spaces, "");
556 }
557 pruned = change + pruned;
558 }
559 }
560
561 std::string output = formatLine(name, size, pruned);
562
563 if (uid != AID_SYSTEM) {
564 return output;
565 }
566
567 static const size_t maximum_sorted_entries = 32;
568 std::array<const pid_t*, maximum_sorted_entries> sorted_pids;
569 std::array<const PidEntry*, maximum_sorted_entries> sorted_entries;
570 stat.pidSystemTable[id].MaxEntries(uid, 0, sorted_pids, sorted_entries);
571
572 std::string byPid;
573 size_t index;
574 bool hasDropped = false;
575 for (index = 0; index < maximum_sorted_entries; ++index) {
576 const PidEntry* entry = sorted_entries[index];
577 if (!entry) {
578 break;
579 }
580 if (entry->getSizes() <= (getSizes() / 100)) {
581 break;
582 }
583 if (entry->dropped_count()) {
584 hasDropped = true;
585 }
586 byPid += entry->format(stat, id, *sorted_pids[index]);
587 }
588 if (index > 1) { // print this only if interesting
589 std::string ditto("\" ");
590 output += formatLine(std::string(" PID/UID COMMAND LINE"), ditto,
591 hasDropped ? ditto : std::string(""));
592 output += byPid;
593 }
594
595 return output;
596 }
597
formatHeader(const std::string & name,log_id_t) const598 std::string PidEntry::formatHeader(const std::string& name,
599 log_id_t /* id */) const {
600 return formatLine(name, std::string("Size"), std::string("Pruned")) +
601 formatLine(std::string(" PID/UID COMMAND LINE"),
602 std::string("BYTES"), std::string("NUM"));
603 }
604
format(const LogStatistics & stat,log_id_t,pid_t pid) const605 std::string PidEntry::format(const LogStatistics& stat, log_id_t, pid_t pid) const
606 REQUIRES(stat.lock_) {
607 std::string name = android::base::StringPrintf("%5u/%u", pid, uid_);
608 std::string size = android::base::StringPrintf("%zu", getSizes());
609
610 stat.FormatTmp(name_, uid_, name, size, 12);
611
612 std::string pruned = "";
613 size_t dropped = dropped_count();
614 if (dropped) {
615 pruned = android::base::StringPrintf("%zu", dropped);
616 }
617
618 return formatLine(name, size, pruned);
619 }
620
formatHeader(const std::string & name,log_id_t) const621 std::string TidEntry::formatHeader(const std::string& name,
622 log_id_t /* id */) const {
623 return formatLine(name, std::string("Size"), std::string("Pruned")) +
624 formatLine(std::string(" TID/UID COMM"), std::string("BYTES"),
625 std::string("NUM"));
626 }
627
format(const LogStatistics & stat,log_id_t,pid_t tid) const628 std::string TidEntry::format(const LogStatistics& stat, log_id_t, pid_t tid) const
629 REQUIRES(stat.lock_) {
630 std::string name = android::base::StringPrintf("%5u/%u", tid, uid_);
631 std::string size = android::base::StringPrintf("%zu", getSizes());
632
633 stat.FormatTmp(name_, uid_, name, size, 12);
634
635 std::string pruned = "";
636 size_t dropped = dropped_count();
637 if (dropped) {
638 pruned = android::base::StringPrintf("%zu", dropped);
639 }
640
641 return formatLine(name, size, pruned);
642 }
643
formatHeader(const std::string & name,log_id_t id) const644 std::string TagEntry::formatHeader(const std::string& name, log_id_t id) const {
645 bool isprune = worstUidEnabledForLogid(id);
646 return formatLine(name, std::string("Size"),
647 std::string(isprune ? "Prune" : "")) +
648 formatLine(std::string(" TAG/UID TAGNAME"),
649 std::string("BYTES"), std::string(isprune ? "NUM" : ""));
650 }
651
format(const LogStatistics &,log_id_t,uint32_t) const652 std::string TagEntry::format(const LogStatistics&, log_id_t, uint32_t) const {
653 std::string name;
654 if (uid_ == (uid_t)-1) {
655 name = android::base::StringPrintf("%7u", key());
656 } else {
657 name = android::base::StringPrintf("%7u/%u", key(), uid_);
658 }
659 const char* nameTmp = this->name();
660 if (nameTmp) {
661 name += android::base::StringPrintf(
662 "%*s%s", (int)std::max(14 - name.length(), (size_t)1), "", nameTmp);
663 }
664
665 std::string size = android::base::StringPrintf("%zu", getSizes());
666
667 std::string pruned = "";
668 size_t dropped = dropped_count();
669 if (dropped) {
670 pruned = android::base::StringPrintf("%zu", dropped);
671 }
672
673 return formatLine(name, size, pruned);
674 }
675
formatHeader(const std::string & name,log_id_t) const676 std::string TagNameEntry::formatHeader(const std::string& name,
677 log_id_t /* id */) const {
678 return formatLine(name, std::string("Size"), std::string("")) +
679 formatLine(std::string(" TID/PID/UID LOG_TAG NAME"),
680 std::string("BYTES"), std::string(""));
681 }
682
format(const LogStatistics &,log_id_t,const std::string & key_name) const683 std::string TagNameEntry::format(const LogStatistics&, log_id_t,
684 const std::string& key_name) const {
685 std::string name;
686 std::string pidstr;
687 if (pid_ != (pid_t)-1) {
688 pidstr = android::base::StringPrintf("%u", pid_);
689 if (tid_ != (pid_t)-1 && tid_ != pid_) pidstr = "/" + pidstr;
690 }
691 int len = 9 - pidstr.length();
692 if (len < 0) len = 0;
693 if (tid_ == (pid_t)-1 || tid_ == pid_) {
694 name = android::base::StringPrintf("%*s", len, "");
695 } else {
696 name = android::base::StringPrintf("%*u", len, tid_);
697 }
698 name += pidstr;
699 if (uid_ != (uid_t)-1) {
700 name += android::base::StringPrintf("/%u", uid_);
701 }
702
703 std::string size = android::base::StringPrintf("%zu", getSizes());
704
705 const char* nameTmp = key_name.data();
706 if (nameTmp) {
707 size_t lenSpace = std::max(16 - name.length(), (size_t)1);
708 size_t len = EntryBase::TOTAL_LEN - EntryBase::PRUNED_LEN - size.length() - name.length() -
709 lenSpace - 2;
710 size_t lenNameTmp = strlen(nameTmp);
711 while ((len < lenNameTmp) && (lenSpace > 1)) {
712 ++len;
713 --lenSpace;
714 }
715 name += android::base::StringPrintf("%*s", (int)lenSpace, "");
716 if (len < lenNameTmp) {
717 name += "...";
718 nameTmp += lenNameTmp - std::max(len - 3, (size_t)1);
719 }
720 name += nameTmp;
721 }
722
723 std::string pruned = "";
724
725 return formatLine(name, size, pruned);
726 }
727
formatMsec(uint64_t val)728 static std::string formatMsec(uint64_t val) {
729 static const unsigned subsecDigits = 3;
730 static const uint64_t sec = MS_PER_SEC;
731
732 static const uint64_t minute = 60 * sec;
733 static const uint64_t hour = 60 * minute;
734 static const uint64_t day = 24 * hour;
735
736 std::string output;
737 if (val < sec) return output;
738
739 if (val >= day) {
740 output = android::base::StringPrintf("%" PRIu64 "d ", val / day);
741 val = (val % day) + day;
742 }
743 if (val >= minute) {
744 if (val >= hour) {
745 output += android::base::StringPrintf("%" PRIu64 ":",
746 (val / hour) % (day / hour));
747 }
748 output += android::base::StringPrintf(
749 (val >= hour) ? "%02" PRIu64 ":" : "%" PRIu64 ":",
750 (val / minute) % (hour / minute));
751 }
752 output +=
753 android::base::StringPrintf((val >= minute) ? "%02" PRIu64 : "%" PRIu64,
754 (val / sec) % (minute / sec));
755 val %= sec;
756 unsigned digits = subsecDigits;
757 while (digits && ((val % 10) == 0)) {
758 val /= 10;
759 --digits;
760 }
761 if (digits) {
762 output += android::base::StringPrintf(".%0*" PRIu64, digits, val);
763 }
764 return output;
765 }
766
767 template <typename TKey, typename TEntry>
FormatTable(const LogHashtable<TKey,TEntry> & table,uid_t uid,pid_t pid,const std::string & name,log_id_t id) const768 std::string LogStatistics::FormatTable(const LogHashtable<TKey, TEntry>& table, uid_t uid,
769 pid_t pid, const std::string& name, log_id_t id) const
770 REQUIRES(lock_) {
771 static const size_t maximum_sorted_entries = 32;
772 std::string output;
773 std::array<const TKey*, maximum_sorted_entries> sorted_keys;
774 std::array<const TEntry*, maximum_sorted_entries> sorted_entries;
775 table.MaxEntries(uid, pid, sorted_keys, sorted_entries);
776 bool header_printed = false;
777 for (size_t index = 0; index < maximum_sorted_entries; ++index) {
778 const TEntry* entry = sorted_entries[index];
779 if (!entry) {
780 break;
781 }
782 if (entry->getSizes() <= (sorted_entries[0]->getSizes() / 100)) {
783 break;
784 }
785 if (!header_printed) {
786 output += "\n\n";
787 output += entry->formatHeader(name, id);
788 header_printed = true;
789 }
790 output += entry->format(*this, id, *sorted_keys[index]);
791 }
792 return output;
793 }
794
ReportInteresting() const795 std::string LogStatistics::ReportInteresting() const {
796 auto lock = std::lock_guard{lock_};
797
798 std::vector<std::string> items;
799
800 log_id_for_each(i) { items.emplace_back(std::to_string(mElements[i])); }
801
802 log_id_for_each(i) { items.emplace_back(std::to_string(mSizes[i])); }
803
804 log_id_for_each(i) {
805 items.emplace_back(std::to_string(overhead_[i] ? *overhead_[i] : mSizes[i]));
806 }
807
808 log_id_for_each(i) {
809 uint64_t oldest = mOldest[i].msec() / 1000;
810 uint64_t newest = mNewest[i].msec() / 1000;
811
812 int span = newest - oldest;
813
814 items.emplace_back(std::to_string(span));
815 }
816
817 return android::base::Join(items, ",");
818 }
819
Format(uid_t uid,pid_t pid,unsigned int logMask) const820 std::string LogStatistics::Format(uid_t uid, pid_t pid, unsigned int logMask) const {
821 auto lock = std::lock_guard{lock_};
822
823 static const uint16_t spaces_total = 19;
824
825 // Report on total logging, current and for all time
826
827 std::string output = "size/num";
828 size_t oldLength;
829 int16_t spaces = 1;
830
831 log_id_for_each(id) {
832 if (!(logMask & (1 << id))) continue;
833 oldLength = output.length();
834 if (spaces < 0) spaces = 0;
835 output += android::base::StringPrintf("%*s%s", spaces, "",
836 android_log_id_to_name(id));
837 spaces += spaces_total + oldLength - output.length();
838 }
839 if (spaces < 0) spaces = 0;
840 output += android::base::StringPrintf("%*sTotal", spaces, "");
841
842 static const char TotalStr[] = "\nTotal";
843 spaces = 10 - strlen(TotalStr);
844 output += TotalStr;
845
846 size_t totalSize = 0;
847 size_t totalEls = 0;
848 log_id_for_each(id) {
849 if (!(logMask & (1 << id))) continue;
850 oldLength = output.length();
851 if (spaces < 0) spaces = 0;
852 size_t szs = mSizesTotal[id];
853 totalSize += szs;
854 size_t els = mElementsTotal[id];
855 totalEls += els;
856 output +=
857 android::base::StringPrintf("%*s%zu/%zu", spaces, "", szs, els);
858 spaces += spaces_total + oldLength - output.length();
859 }
860 if (spaces < 0) spaces = 0;
861 output += android::base::StringPrintf("%*s%zu/%zu", spaces, "", totalSize,
862 totalEls);
863
864 static const char NowStr[] = "\nNow";
865 spaces = 10 - strlen(NowStr);
866 output += NowStr;
867
868 totalSize = 0;
869 totalEls = 0;
870 log_id_for_each(id) {
871 if (!(logMask & (1 << id))) continue;
872
873 size_t els = mElements[id];
874 if (els) {
875 oldLength = output.length();
876 if (spaces < 0) spaces = 0;
877 size_t szs = mSizes[id];
878 totalSize += szs;
879 totalEls += els;
880 output +=
881 android::base::StringPrintf("%*s%zu/%zu", spaces, "", szs, els);
882 spaces -= output.length() - oldLength;
883 }
884 spaces += spaces_total;
885 }
886 if (spaces < 0) spaces = 0;
887 output += android::base::StringPrintf("%*s%zu/%zu", spaces, "", totalSize,
888 totalEls);
889
890 static const char SpanStr[] = "\nLogspan";
891 spaces = 10 - strlen(SpanStr);
892 output += SpanStr;
893
894 // Total reports the greater of the individual maximum time span, or the
895 // validated minimum start and maximum end time span if it makes sense.
896 uint64_t minTime = UINT64_MAX;
897 uint64_t maxTime = 0;
898 uint64_t maxSpan = 0;
899 totalSize = 0;
900
901 log_id_for_each(id) {
902 if (!(logMask & (1 << id))) continue;
903
904 // validity checking
905 uint64_t oldest = mOldest[id].msec();
906 uint64_t newest = mNewest[id].msec();
907 if (newest <= oldest) {
908 spaces += spaces_total;
909 continue;
910 }
911
912 uint64_t span = newest - oldest;
913 if (span > (monthSec * MS_PER_SEC)) {
914 spaces += spaces_total;
915 continue;
916 }
917
918 // total span
919 if (minTime > oldest) minTime = oldest;
920 if (maxTime < newest) maxTime = newest;
921 if (span > maxSpan) maxSpan = span;
922 totalSize += span;
923
924 uint64_t dropped = mNewestDropped[id].msec();
925 if (dropped < oldest) dropped = oldest;
926 if (dropped > newest) dropped = newest;
927
928 oldLength = output.length();
929 output += android::base::StringPrintf("%*s%s", spaces, "",
930 formatMsec(span).c_str());
931 unsigned permille = ((newest - dropped) * 1000 + (span / 2)) / span;
932 if ((permille > 1) && (permille < 999)) {
933 output += android::base::StringPrintf("(%u", permille / 10);
934 permille %= 10;
935 if (permille) {
936 output += android::base::StringPrintf(".%u", permille);
937 }
938 output += android::base::StringPrintf("%%)");
939 }
940 spaces -= output.length() - oldLength;
941 spaces += spaces_total;
942 }
943 if ((maxTime > minTime) && ((maxTime -= minTime) < totalSize) &&
944 (maxTime > maxSpan)) {
945 maxSpan = maxTime;
946 }
947 if (spaces < 0) spaces = 0;
948 output += android::base::StringPrintf("%*s%s", spaces, "",
949 formatMsec(maxSpan).c_str());
950
951 static const char OverheadStr[] = "\nOverhead";
952 spaces = 10 - strlen(OverheadStr);
953 output += OverheadStr;
954
955 totalSize = 0;
956 log_id_for_each(id) {
957 if (!(logMask & (1 << id))) continue;
958
959 size_t els = mElements[id];
960 if (els) {
961 oldLength = output.length();
962 if (spaces < 0) spaces = 0;
963 size_t szs = 0;
964 if (overhead_[id]) {
965 szs = *overhead_[id];
966 } else if (track_total_size_) {
967 szs = mSizes[id];
968 } else {
969 // Legacy fallback for Chatty without track_total_size_
970 // Estimate the size of this element in the parent std::list<> by adding two void*'s
971 // corresponding to the next/prev pointers and aligning to 64 bit.
972 static const size_t overhead =
973 (sizeof(LogBufferElement) + 2 * sizeof(void*) + sizeof(uint64_t) - 1) &
974 -sizeof(uint64_t);
975 szs = mSizes[id] + els * overhead;
976 }
977 totalSize += szs;
978 output += android::base::StringPrintf("%*s%zu", spaces, "", szs);
979 spaces -= output.length() - oldLength;
980 }
981 spaces += spaces_total;
982 }
983 totalSize += sizeOf();
984 if (spaces < 0) spaces = 0;
985 output += android::base::StringPrintf("%*s%zu", spaces, "", totalSize);
986
987 // Report on Chattiest
988
989 std::string name;
990
991 // Chattiest by application (UID)
992 log_id_for_each(id) {
993 if (!(logMask & (1 << id))) continue;
994
995 name = (uid == AID_ROOT) ? "Chattiest UIDs in %s log buffer:"
996 : "Logging for your UID in %s log buffer:";
997 output += FormatTable(uidTable[id], uid, pid, name, id);
998 }
999
1000 if (enable) {
1001 name = ((uid == AID_ROOT) && !pid) ? "Chattiest PIDs:"
1002 : "Logging for this PID:";
1003 output += FormatTable(pidTable, uid, pid, name);
1004 name = "Chattiest TIDs";
1005 if (pid) name += android::base::StringPrintf(" for PID %d", pid);
1006 name += ":";
1007 output += FormatTable(tidTable, uid, pid, name);
1008 }
1009
1010 if (enable && (logMask & (1 << LOG_ID_EVENTS))) {
1011 name = "Chattiest events log buffer TAGs";
1012 if (pid) name += android::base::StringPrintf(" for PID %d", pid);
1013 name += ":";
1014 output += FormatTable(tagTable, uid, pid, name, LOG_ID_EVENTS);
1015 }
1016
1017 if (enable && (logMask & (1 << LOG_ID_SECURITY))) {
1018 name = "Chattiest security log buffer TAGs";
1019 if (pid) name += android::base::StringPrintf(" for PID %d", pid);
1020 name += ":";
1021 output += FormatTable(securityTagTable, uid, pid, name, LOG_ID_SECURITY);
1022 }
1023
1024 if (enable) {
1025 name = "Chattiest TAGs";
1026 if (pid) name += android::base::StringPrintf(" for PID %d", pid);
1027 name += ":";
1028 output += FormatTable(tagNameTable, uid, pid, name);
1029 }
1030
1031 return output;
1032 }
1033
1034 namespace android {
1035
pidToUid(pid_t pid)1036 uid_t pidToUid(pid_t pid) {
1037 char buffer[512];
1038 snprintf(buffer, sizeof(buffer), "/proc/%u/status", pid);
1039 FILE* fp = fopen(buffer, "re");
1040 if (fp) {
1041 while (fgets(buffer, sizeof(buffer), fp)) {
1042 int uid = AID_LOGD;
1043 char space = 0;
1044 if ((sscanf(buffer, "Uid: %d%c", &uid, &space) == 2) &&
1045 isspace(space)) {
1046 fclose(fp);
1047 return uid;
1048 }
1049 }
1050 fclose(fp);
1051 }
1052 return AID_LOGD; // associate this with the logger
1053 }
1054 }
1055
PidToUid(pid_t pid)1056 uid_t LogStatistics::PidToUid(pid_t pid) {
1057 auto lock = std::lock_guard{lock_};
1058 return pidTable.Add(pid)->second.uid();
1059 }
1060
1061 // caller must free character string
PidToName(pid_t pid) const1062 const char* LogStatistics::PidToName(pid_t pid) const {
1063 auto lock = std::lock_guard{lock_};
1064 // An inconvenient truth ... getName() can alter the object
1065 pidTable_t& writablePidTable = const_cast<pidTable_t&>(pidTable);
1066 const char* name = writablePidTable.Add(pid)->second.name();
1067 if (!name) {
1068 return nullptr;
1069 }
1070 return strdup(name);
1071 }
1072