blob: 1305b0ac93a3d721b9ea6d7f12c49274aeaab9dd [file] [log] [blame]
Mark Salyzyn34facab2014-02-06 14:48:50 -08001/*
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
Mark Salyzyn9a038632014-04-07 07:05:40 -070017#include <fcntl.h>
Mark Salyzyn34facab2014-02-06 14:48:50 -080018#include <stdarg.h>
19#include <time.h>
20
21#include <log/logger.h>
22#include <private/android_filesystem_config.h>
23#include <utils/String8.h>
24
25#include "LogStatistics.h"
26
Mark Salyzyn9a038632014-04-07 07:05:40 -070027PidStatistics::PidStatistics(pid_t pid, char *name)
Mark Salyzyn34facab2014-02-06 14:48:50 -080028 : pid(pid)
29 , mSizesTotal(0)
30 , mElementsTotal(0)
31 , mSizes(0)
Mark Salyzyn9a038632014-04-07 07:05:40 -070032 , mElements(0)
33 , name(name)
Mark Salyzynfdabe722014-04-21 10:09:42 -070034 , mGone(false)
Mark Salyzyn9a038632014-04-07 07:05:40 -070035{ }
36
37#ifdef DO_NOT_ERROR_IF_PIDSTATISTICS_USES_A_COPY_CONSTRUCTOR
38PidStatistics::PidStatistics(const PidStatistics &copy)
39 : pid(copy->pid)
40 , name(copy->name ? strdup(copy->name) : NULL)
41 , mSizesTotal(copy->mSizesTotal)
42 , mElementsTotal(copy->mElementsTotal)
43 , mSizes(copy->mSizes)
44 , mElements(copy->mElements)
Mark Salyzynfdabe722014-04-21 10:09:42 -070045 , mGone(copy->mGone)
Mark Salyzyn9a038632014-04-07 07:05:40 -070046{ }
47#endif
48
49PidStatistics::~PidStatistics() {
50 free(name);
51}
52
Mark Salyzynfdabe722014-04-21 10:09:42 -070053bool PidStatistics::pidGone() {
Mark Salyzyne72c6e42014-09-21 14:22:18 -070054 if (mGone || (pid == gone)) {
Mark Salyzynfdabe722014-04-21 10:09:42 -070055 return true;
56 }
Mark Salyzyndf5aa612014-09-21 14:22:18 -070057 if (pid == 0) {
58 return false;
59 }
Mark Salyzynfdabe722014-04-21 10:09:42 -070060 if (kill(pid, 0) && (errno != EPERM)) {
61 mGone = true;
62 return true;
63 }
64 return false;
65}
66
Mark Salyzyn9a038632014-04-07 07:05:40 -070067void PidStatistics::setName(char *new_name) {
68 free(name);
69 name = new_name;
70}
Mark Salyzyn34facab2014-02-06 14:48:50 -080071
72void PidStatistics::add(unsigned short size) {
73 mSizesTotal += size;
74 ++mElementsTotal;
75 mSizes += size;
76 ++mElements;
77}
78
79bool PidStatistics::subtract(unsigned short size) {
80 mSizes -= size;
81 --mElements;
Mark Salyzynfdabe722014-04-21 10:09:42 -070082 return (mElements == 0) && pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -080083}
84
85void PidStatistics::addTotal(size_t size, size_t element) {
86 if (pid == gone) {
87 mSizesTotal += size;
88 mElementsTotal += element;
89 }
90}
91
Mark Salyzyn9a038632014-04-07 07:05:40 -070092// must call free to release return value
Mark Salyzyne72c6e42014-09-21 14:22:18 -070093// If only we could sniff our own logs for:
94// <time> <pid> <pid> E AndroidRuntime: Process: <name>, PID: <pid>
95// which debuggerd prints as a process is crashing.
Mark Salyzyn9a038632014-04-07 07:05:40 -070096char *PidStatistics::pidToName(pid_t pid) {
97 char *retval = NULL;
Mark Salyzyndf5aa612014-09-21 14:22:18 -070098 if (pid == 0) { // special case from auditd for kernel
99 retval = strdup("logd.auditd");
100 } else if (pid != gone) {
Mark Salyzyn9a038632014-04-07 07:05:40 -0700101 char buffer[512];
102 snprintf(buffer, sizeof(buffer), "/proc/%u/cmdline", pid);
103 int fd = open(buffer, O_RDONLY);
104 if (fd >= 0) {
105 ssize_t ret = read(fd, buffer, sizeof(buffer));
106 if (ret > 0) {
107 buffer[sizeof(buffer)-1] = '\0';
108 // frameworks intermediate state
109 if (strcmp(buffer, "<pre-initialized>")) {
110 retval = strdup(buffer);
111 }
112 }
113 close(fd);
114 }
115 }
116 return retval;
117}
118
Mark Salyzyn34facab2014-02-06 14:48:50 -0800119UidStatistics::UidStatistics(uid_t uid)
Mark Salyzync8a576c2014-04-04 16:35:59 -0700120 : uid(uid)
121 , mSizes(0)
122 , mElements(0) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800123 Pids.clear();
124}
125
126UidStatistics::~UidStatistics() {
127 PidStatisticsCollection::iterator it;
128 for (it = begin(); it != end();) {
129 delete (*it);
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700130 it = erase(it);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800131 }
132}
133
134void UidStatistics::add(unsigned short size, pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700135 mSizes += size;
136 ++mElements;
137
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700138 PidStatistics *p = NULL;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800139 PidStatisticsCollection::iterator last;
140 PidStatisticsCollection::iterator it;
141 for (last = it = begin(); it != end(); last = it, ++it) {
142 p = *it;
143 if (pid == p->getPid()) {
144 p->add(size);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800145 return;
146 }
147 }
Mark Salyzync8a576c2014-04-04 16:35:59 -0700148 // insert if the gone entry.
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700149 bool insert_before_last = (last != it) && p && (p->getPid() == p->gone);
Mark Salyzyn9a038632014-04-07 07:05:40 -0700150 p = new PidStatistics(pid, pidToName(pid));
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700151 if (insert_before_last) {
152 insert(last, p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800153 } else {
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700154 push_back(p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800155 }
156 p->add(size);
157}
158
159void UidStatistics::subtract(unsigned short size, pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700160 mSizes -= size;
161 --mElements;
162
Mark Salyzyn34facab2014-02-06 14:48:50 -0800163 PidStatisticsCollection::iterator it;
164 for (it = begin(); it != end(); ++it) {
165 PidStatistics *p = *it;
166 if (pid == p->getPid()) {
167 if (p->subtract(size)) {
168 size_t szsTotal = p->sizesTotal();
169 size_t elsTotal = p->elementsTotal();
170 delete p;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700171 erase(it);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800172 it = end();
173 --it;
174 if (it == end()) {
175 p = new PidStatistics(p->gone);
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700176 push_back(p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800177 } else {
178 p = *it;
179 if (p->getPid() != p->gone) {
180 p = new PidStatistics(p->gone);
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700181 push_back(p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800182 }
183 }
184 p->addTotal(szsTotal, elsTotal);
185 }
186 return;
187 }
188 }
189}
190
Mark Salyzync8a576c2014-04-04 16:35:59 -0700191void UidStatistics::sort() {
192 for (bool pass = true; pass;) {
193 pass = false;
194 PidStatisticsCollection::iterator it = begin();
195 if (it != end()) {
196 PidStatisticsCollection::iterator lt = it;
197 PidStatistics *l = (*lt);
198 while (++it != end()) {
199 PidStatistics *n = (*it);
200 if ((n->getPid() != n->gone) && (n->sizes() > l->sizes())) {
201 pass = true;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700202 erase(it);
203 insert(lt, n);
Mark Salyzync8a576c2014-04-04 16:35:59 -0700204 it = lt;
205 n = l;
206 }
207 lt = it;
208 l = n;
209 }
210 }
211 }
212}
213
Mark Salyzyn34facab2014-02-06 14:48:50 -0800214size_t UidStatistics::sizes(pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700215 if (pid == pid_all) {
216 return sizes();
217 }
218
Mark Salyzyn34facab2014-02-06 14:48:50 -0800219 PidStatisticsCollection::iterator it;
220 for (it = begin(); it != end(); ++it) {
221 PidStatistics *p = *it;
Mark Salyzync8a576c2014-04-04 16:35:59 -0700222 if (pid == p->getPid()) {
223 return p->sizes();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800224 }
225 }
Mark Salyzync8a576c2014-04-04 16:35:59 -0700226 return 0;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800227}
228
229size_t UidStatistics::elements(pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700230 if (pid == pid_all) {
231 return elements();
232 }
233
Mark Salyzyn34facab2014-02-06 14:48:50 -0800234 PidStatisticsCollection::iterator it;
235 for (it = begin(); it != end(); ++it) {
236 PidStatistics *p = *it;
Mark Salyzync8a576c2014-04-04 16:35:59 -0700237 if (pid == p->getPid()) {
238 return p->elements();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800239 }
240 }
Mark Salyzync8a576c2014-04-04 16:35:59 -0700241 return 0;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800242}
243
244size_t UidStatistics::sizesTotal(pid_t pid) {
245 size_t sizes = 0;
246 PidStatisticsCollection::iterator it;
247 for (it = begin(); it != end(); ++it) {
248 PidStatistics *p = *it;
249 if ((pid == pid_all) || (pid == p->getPid())) {
250 sizes += p->sizesTotal();
251 }
252 }
253 return sizes;
254}
255
256size_t UidStatistics::elementsTotal(pid_t pid) {
257 size_t elements = 0;
258 PidStatisticsCollection::iterator it;
259 for (it = begin(); it != end(); ++it) {
260 PidStatistics *p = *it;
261 if ((pid == pid_all) || (pid == p->getPid())) {
262 elements += p->elementsTotal();
263 }
264 }
265 return elements;
266}
267
268LidStatistics::LidStatistics() {
269 Uids.clear();
270}
271
272LidStatistics::~LidStatistics() {
273 UidStatisticsCollection::iterator it;
274 for (it = begin(); it != end();) {
275 delete (*it);
276 it = Uids.erase(it);
277 }
278}
279
280void LidStatistics::add(unsigned short size, uid_t uid, pid_t pid) {
281 UidStatistics *u;
282 UidStatisticsCollection::iterator it;
283 UidStatisticsCollection::iterator last;
284
285 if (uid == (uid_t) -1) { // init
286 uid = (uid_t) AID_ROOT;
287 }
288
289 for (last = it = begin(); it != end(); last = it, ++it) {
290 u = *it;
291 if (uid == u->getUid()) {
292 u->add(size, pid);
293 if ((last != it) && ((*last)->sizesTotal() < u->sizesTotal())) {
294 Uids.erase(it);
295 Uids.insert(last, u);
296 }
297 return;
298 }
299 }
300 u = new UidStatistics(uid);
301 if ((last != it) && ((*last)->sizesTotal() < (size_t) size)) {
302 Uids.insert(last, u);
303 } else {
304 Uids.push_back(u);
305 }
306 u->add(size, pid);
307}
308
309void LidStatistics::subtract(unsigned short size, uid_t uid, pid_t pid) {
310 UidStatisticsCollection::iterator it;
311 for (it = begin(); it != end(); ++it) {
312 UidStatistics *u = *it;
313 if (uid == u->getUid()) {
314 u->subtract(size, pid);
315 return;
316 }
317 }
318}
319
Mark Salyzync8a576c2014-04-04 16:35:59 -0700320void LidStatistics::sort() {
321 for (bool pass = true; pass;) {
322 pass = false;
323 UidStatisticsCollection::iterator it = begin();
324 if (it != end()) {
325 UidStatisticsCollection::iterator lt = it;
326 UidStatistics *l = (*lt);
327 while (++it != end()) {
328 UidStatistics *n = (*it);
329 if (n->sizes() > l->sizes()) {
330 pass = true;
331 Uids.erase(it);
332 Uids.insert(lt, n);
333 it = lt;
334 n = l;
335 }
336 lt = it;
337 l = n;
338 }
339 }
340 }
341}
342
Mark Salyzyn34facab2014-02-06 14:48:50 -0800343size_t LidStatistics::sizes(uid_t uid, pid_t pid) {
344 size_t sizes = 0;
345 UidStatisticsCollection::iterator it;
346 for (it = begin(); it != end(); ++it) {
347 UidStatistics *u = *it;
348 if ((uid == uid_all) || (uid == u->getUid())) {
349 sizes += u->sizes(pid);
350 }
351 }
352 return sizes;
353}
354
355size_t LidStatistics::elements(uid_t uid, pid_t pid) {
356 size_t elements = 0;
357 UidStatisticsCollection::iterator it;
358 for (it = begin(); it != end(); ++it) {
359 UidStatistics *u = *it;
360 if ((uid == uid_all) || (uid == u->getUid())) {
361 elements += u->elements(pid);
362 }
363 }
364 return elements;
365}
366
367size_t LidStatistics::sizesTotal(uid_t uid, pid_t pid) {
368 size_t sizes = 0;
369 UidStatisticsCollection::iterator it;
370 for (it = begin(); it != end(); ++it) {
371 UidStatistics *u = *it;
372 if ((uid == uid_all) || (uid == u->getUid())) {
373 sizes += u->sizesTotal(pid);
374 }
375 }
376 return sizes;
377}
378
379size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) {
380 size_t elements = 0;
381 UidStatisticsCollection::iterator it;
382 for (it = begin(); it != end(); ++it) {
383 UidStatistics *u = *it;
384 if ((uid == uid_all) || (uid == u->getUid())) {
385 elements += u->elementsTotal(pid);
386 }
387 }
388 return elements;
389}
390
391LogStatistics::LogStatistics()
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700392 : mStatistics(false)
393 , dgramQlenStatistics(false)
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700394 , start(CLOCK_MONOTONIC) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800395 log_id_for_each(i) {
396 mSizes[i] = 0;
397 mElements[i] = 0;
398 }
Mark Salyzyne457b742014-02-19 17:18:31 -0800399
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700400 for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700401 mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max;
402 mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max;
Mark Salyzyne457b742014-02-19 17:18:31 -0800403 }
404}
405
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700406// Each bucket below represents a dgramQlen of log messages. By
Mark Salyzyne457b742014-02-19 17:18:31 -0800407// finding the minimum period of time from start to finish
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700408// of each dgramQlen, we can get a performance expectation for
Mark Salyzyne457b742014-02-19 17:18:31 -0800409// the user space logger. The net result is that the period
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700410// of time divided by the dgramQlen will give us the average time
Mark Salyzyne457b742014-02-19 17:18:31 -0800411// between log messages; at the point where the average time
412// is greater than the throughput capability of the logger
413// we will not longer require the benefits of the FIFO formed
414// by max_dgram_qlen. We will also expect to see a very visible
415// knee in the average time between log messages at this point,
416// so we do not necessarily have to compare the rate against the
417// measured performance (BM_log_maximum_retry) of the logger.
418//
419// for example (reformatted):
420//
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700421// Minimum time between log events per dgramQlen:
Mark Salyzyne457b742014-02-19 17:18:31 -0800422// 1 2 3 5 10 20 30 50 100 200 300 400 500 600
423// 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5
424//
425// demonstrates a clear knee rising at 100, so this means that for this
426// case max_dgram_qlen = 100 would be more than sufficient to handle the
427// worst that the system could stuff into the logger. The
428// BM_log_maximum_retry performance (derated by the log collection) on the
429// same system was 33.2us so we would almost be fine with max_dgram_qlen = 50.
430// BM_log_maxumum_retry with statistics off is roughly 20us, so
431// max_dgram_qlen = 20 would work. We will be more than willing to have
432// a large engineering margin so the rule of thumb that lead us to 100 is
433// fine.
434//
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700435// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300
Mark Salyzyne457b742014-02-19 17:18:31 -0800436const unsigned short LogStatistics::mBuckets[] = {
437 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600
438};
439
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700440unsigned short LogStatistics::dgramQlen(unsigned short bucket) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800441 if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) {
442 return 0;
443 }
444 return mBuckets[bucket];
445}
446
447unsigned long long LogStatistics::minimum(unsigned short bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700448 if (mMinimum[bucket].tv_sec == mMinimum[bucket].tv_sec_max) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800449 return 0;
450 }
451 return mMinimum[bucket].nsec();
452}
453
454void LogStatistics::recordDiff(log_time diff, unsigned short bucket) {
455 if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) {
456 mMinimum[bucket] = diff;
457 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800458}
459
460void LogStatistics::add(unsigned short size,
461 log_id_t log_id, uid_t uid, pid_t pid) {
462 mSizes[log_id] += size;
463 ++mElements[log_id];
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700464 if (!mStatistics) {
465 return;
466 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800467 id(log_id).add(size, uid, pid);
468}
469
470void LogStatistics::subtract(unsigned short size,
471 log_id_t log_id, uid_t uid, pid_t pid) {
472 mSizes[log_id] -= size;
473 --mElements[log_id];
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700474 if (!mStatistics) {
475 return;
476 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800477 id(log_id).subtract(size, uid, pid);
478}
479
480size_t LogStatistics::sizes(log_id_t log_id, uid_t uid, pid_t pid) {
481 if (log_id != log_id_all) {
482 return id(log_id).sizes(uid, pid);
483 }
484 size_t sizes = 0;
485 log_id_for_each(i) {
486 sizes += id(i).sizes(uid, pid);
487 }
488 return sizes;
489}
490
491size_t LogStatistics::elements(log_id_t log_id, uid_t uid, pid_t pid) {
492 if (log_id != log_id_all) {
493 return id(log_id).elements(uid, pid);
494 }
495 size_t elements = 0;
496 log_id_for_each(i) {
497 elements += id(i).elements(uid, pid);
498 }
499 return elements;
500}
501
502size_t LogStatistics::sizesTotal(log_id_t log_id, uid_t uid, pid_t pid) {
503 if (log_id != log_id_all) {
504 return id(log_id).sizesTotal(uid, pid);
505 }
506 size_t sizes = 0;
507 log_id_for_each(i) {
508 sizes += id(i).sizesTotal(uid, pid);
509 }
510 return sizes;
511}
512
513size_t LogStatistics::elementsTotal(log_id_t log_id, uid_t uid, pid_t pid) {
514 if (log_id != log_id_all) {
515 return id(log_id).elementsTotal(uid, pid);
516 }
517 size_t elements = 0;
518 log_id_for_each(i) {
519 elements += id(i).elementsTotal(uid, pid);
520 }
521 return elements;
522}
523
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800524void LogStatistics::format(char **buf,
525 uid_t uid, unsigned int logMask, log_time oldest) {
Mark Salyzyn9a038632014-04-07 07:05:40 -0700526 static const unsigned short spaces_current = 13;
527 static const unsigned short spaces_total = 19;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800528
529 if (*buf) {
Greg Hackmann239605e2014-04-06 21:25:58 -0700530 free(*buf);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800531 *buf = NULL;
532 }
533
534 android::String8 string(" span -> size/num");
535 size_t oldLength;
536 short spaces = 2;
537
538 log_id_for_each(i) {
Arseniy Antonovc3ce2242014-09-03 17:29:20 +0400539 if (!(logMask & (1 << i))) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700540 continue;
541 }
542 oldLength = string.length();
543 if (spaces < 0) {
544 spaces = 0;
545 }
546 string.appendFormat("%*s%s", spaces, "", android_log_id_to_name(i));
547 spaces += spaces_total + oldLength - string.length();
548
549 LidStatistics &l = id(i);
550 l.sort();
551
552 UidStatisticsCollection::iterator iu;
553 for (iu = l.begin(); iu != l.end(); ++iu) {
554 (*iu)->sort();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800555 }
556 }
557
558 spaces = 1;
559 log_time t(CLOCK_MONOTONIC);
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700560 unsigned long long d;
561 if (mStatistics) {
562 d = t.nsec() - start.nsec();
563 string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800564 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
565 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
566
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700567 log_id_for_each(i) {
568 if (!(logMask & (1 << i))) {
569 continue;
570 }
571 oldLength = string.length();
572 if (spaces < 0) {
573 spaces = 0;
574 }
575 string.appendFormat("%*s%zu/%zu", spaces, "",
576 sizesTotal(i), elementsTotal(i));
577 spaces += spaces_total + oldLength - string.length();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800578 }
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700579 spaces = 1;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800580 }
581
Mark Salyzyn34facab2014-02-06 14:48:50 -0800582 d = t.nsec() - oldest.nsec();
583 string.appendFormat("\nNow%6llu:%02llu:%02llu.%09llu",
584 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
585 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
586
587 log_id_for_each(i) {
588 if (!(logMask & (1 << i))) {
589 continue;
590 }
591
592 size_t els = elements(i);
593 if (els) {
594 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800595 if (spaces < 0) {
596 spaces = 0;
597 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800598 string.appendFormat("%*s%zu/%zu", spaces, "", sizes(i), els);
599 spaces -= string.length() - oldLength;
600 }
601 spaces += spaces_total;
602 }
603
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700604 // Construct list of worst spammers by Pid
605 static const unsigned char num_spammers = 10;
606 bool header = false;
607
608 log_id_for_each(i) {
609 if (!(logMask & (1 << i))) {
610 continue;
611 }
612
613 PidStatisticsCollection pids;
614 pids.clear();
615
616 LidStatistics &l = id(i);
617 UidStatisticsCollection::iterator iu;
618 for (iu = l.begin(); iu != l.end(); ++iu) {
619 UidStatistics &u = *(*iu);
620 PidStatisticsCollection::iterator ip;
621 for (ip = u.begin(); ip != u.end(); ++ip) {
622 PidStatistics *p = (*ip);
623 if (p->getPid() == p->gone) {
624 break;
625 }
626
627 size_t mySizes = p->sizes();
628
629 PidStatisticsCollection::iterator q;
630 unsigned char num = 0;
631 for (q = pids.begin(); q != pids.end(); ++q) {
632 if (mySizes > (*q)->sizes()) {
633 pids.insert(q, p);
634 break;
635 }
636 // do we need to traverse deeper in the list?
637 if (++num > num_spammers) {
638 break;
639 }
640 }
641 if (q == pids.end()) {
642 pids.push_back(p);
643 }
644 }
645 }
646
647 size_t threshold = sizes(i);
648 if (threshold < 65536) {
649 threshold = 65536;
650 }
651 threshold /= 100;
652
653 PidStatisticsCollection::iterator pt = pids.begin();
654
655 for(int line = 0;
656 (pt != pids.end()) && (line < num_spammers);
657 ++line, pt = pids.erase(pt)) {
658 PidStatistics *p = *pt;
659
660 size_t sizes = p->sizes();
661 if (sizes < threshold) {
662 break;
663 }
664
665 char *name = p->getName();
666 pid_t pid = p->getPid();
667 if (!name || !*name) {
668 name = pidToName(pid);
669 if (name) {
670 if (*name) {
671 p->setName(name);
672 } else {
673 free(name);
674 name = NULL;
675 }
676 }
677 }
678
679 if (!header) {
680 string.appendFormat("\n\nChattiest clients:\n"
681 "log id %-*s PID[?] name",
682 spaces_total, "size/total");
683 header = true;
684 }
685
686 size_t sizesTotal = p->sizesTotal();
687
688 android::String8 sz("");
Chih-Hung Hsieh634118e2014-09-12 16:02:28 -0700689 if (sizes == sizesTotal) {
690 sz.appendFormat("%zu", sizes);
691 } else {
692 sz.appendFormat("%zu/%zu", sizes, sizesTotal);
693 }
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700694
695 android::String8 pd("");
Mark Salyzynfdabe722014-04-21 10:09:42 -0700696 pd.appendFormat("%u%c", pid, p->pidGone() ? '?' : ' ');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700697
698 string.appendFormat("\n%-7s%-*s %-7s%s",
699 line ? "" : android_log_id_to_name(i),
700 spaces_total, sz.string(), pd.string(),
701 name ? name : "");
702 }
703
704 pids.clear();
705 }
706
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700707 if (dgramQlenStatistics) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800708 const unsigned short spaces_time = 6;
709 const unsigned long long max_seconds = 100000;
710 spaces = 0;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700711 string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
712 for(unsigned short i = 0; dgramQlen(i); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800713 oldLength = string.length();
714 if (spaces < 0) {
715 spaces = 0;
716 }
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700717 string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
Mark Salyzyne457b742014-02-19 17:18:31 -0800718 spaces += spaces_time + oldLength - string.length();
719 }
720 string.append("\n");
721 spaces = 0;
722 unsigned short n;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700723 for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800724 unsigned long long duration = minimum(i);
725 if (duration) {
726 duration /= n;
727 if (duration >= (NS_PER_SEC * max_seconds)) {
728 duration = NS_PER_SEC * (max_seconds - 1);
729 }
730 oldLength = string.length();
731 if (spaces < 0) {
732 spaces = 0;
733 }
734 string.appendFormat("%*s", spaces, "");
735 if (duration >= (NS_PER_SEC * 10)) {
736 string.appendFormat("%llu",
737 (duration + (NS_PER_SEC / 2))
738 / NS_PER_SEC);
739 } else if (duration >= (NS_PER_SEC / (1000 / 10))) {
740 string.appendFormat("%llum",
741 (duration + (NS_PER_SEC / 2 / 1000))
742 / (NS_PER_SEC / 1000));
743 } else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
744 string.appendFormat("%lluu",
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700745 (duration + (NS_PER_SEC / 2 / 1000000))
746 / (NS_PER_SEC / 1000000));
Mark Salyzyne457b742014-02-19 17:18:31 -0800747 } else {
748 string.appendFormat("%llun", duration);
749 }
750 spaces -= string.length() - oldLength;
751 }
752 spaces += spaces_time;
753 }
754 }
755
Mark Salyzyn34facab2014-02-06 14:48:50 -0800756 log_id_for_each(i) {
757 if (!(logMask & (1 << i))) {
758 continue;
759 }
760
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700761 header = false;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800762 bool first = true;
763
764 UidStatisticsCollection::iterator ut;
765 for(ut = id(i).begin(); ut != id(i).end(); ++ut) {
766 UidStatistics *up = *ut;
767 if ((uid != AID_ROOT) && (uid != up->getUid())) {
768 continue;
769 }
770
771 PidStatisticsCollection::iterator pt = up->begin();
772 if (pt == up->end()) {
773 continue;
774 }
775
776 android::String8 intermediate;
777
778 if (!header) {
779 // header below tuned to match spaces_total and spaces_current
780 spaces = 0;
781 intermediate = string.format("%s: UID/PID Total size/num",
782 android_log_id_to_name(i));
783 string.appendFormat("\n\n%-31sNow "
784 "UID/PID[?] Total Now",
785 intermediate.string());
786 intermediate.clear();
787 header = true;
788 }
789
790 bool oneline = ++pt == up->end();
791 --pt;
792
793 if (!oneline) {
794 first = true;
Mark Salyzyne457b742014-02-19 17:18:31 -0800795 } else if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800796 string.appendFormat("%*s", spaces, "");
797 }
798 spaces = 0;
799
800 uid_t u = up->getUid();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700801 PidStatistics *pp = *pt;
802 pid_t p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800803
Chih-Hung Hsieh634118e2014-09-12 16:02:28 -0700804 if (!oneline) {
805 intermediate = string.format("%d", u);
806 } else if (p == PidStatistics::gone) {
807 intermediate = string.format("%d/?", u);
808 } else if (pp->pidGone()) {
809 intermediate = string.format("%d/%d?", u, p);
810 } else {
811 intermediate = string.format("%d/%d", u, p);
812 }
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700813 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800814 intermediate.string());
815 intermediate.clear();
816
817 size_t elsTotal = up->elementsTotal();
818 oldLength = string.length();
819 string.appendFormat("%zu/%zu", up->sizesTotal(), elsTotal);
820 spaces += spaces_total + oldLength - string.length();
821
822 size_t els = up->elements();
823 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800824 if (spaces < 0) {
825 spaces = 0;
826 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800827 string.appendFormat("%*s=", spaces, "");
828 spaces = -1;
829 } else if (els) {
830 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800831 if (spaces < 0) {
832 spaces = 0;
833 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800834 string.appendFormat("%*s%zu/%zu", spaces, "", up->sizes(), els);
835 spaces -= string.length() - oldLength;
836 }
837 spaces += spaces_current;
838
839 first = !first;
840
841 if (oneline) {
842 continue;
843 }
844
845 size_t gone_szs = 0;
846 size_t gone_els = 0;
847
848 for(; pt != up->end(); ++pt) {
Mark Salyzynfdabe722014-04-21 10:09:42 -0700849 pp = *pt;
850 p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800851
852 // If a PID no longer has any current logs, and is not
853 // active anymore, skip & report totals for gone.
854 elsTotal = pp->elementsTotal();
855 size_t szsTotal = pp->sizesTotal();
856 if (p == pp->gone) {
857 gone_szs += szsTotal;
858 gone_els += elsTotal;
859 continue;
860 }
861 els = pp->elements();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700862 bool gone = pp->pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800863 if (gone && (els == 0)) {
864 // ToDo: garbage collection: move this statistical bucket
865 // from its current UID/PID to UID/? (races and
866 // wrap around are our achilles heel). Below is
867 // merely lipservice to catch PIDs that were still
868 // around when the stats were pruned to zero.
869 gone_szs += szsTotal;
870 gone_els += elsTotal;
871 continue;
872 }
873
Mark Salyzyne457b742014-02-19 17:18:31 -0800874 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800875 string.appendFormat("%*s", spaces, "");
876 }
877 spaces = 0;
878
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700879 intermediate = string.format(gone ? "%d/%d?" : "%d/%d", u, p);
880 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800881 intermediate.string());
882 intermediate.clear();
883
884 oldLength = string.length();
885 string.appendFormat("%zu/%zu", szsTotal, elsTotal);
886 spaces += spaces_total + oldLength - string.length();
887
888 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800889 if (spaces < 0) {
890 spaces = 0;
891 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800892 string.appendFormat("%*s=", spaces, "");
893 spaces = -1;
894 } else if (els) {
895 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800896 if (spaces < 0) {
897 spaces = 0;
898 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800899 string.appendFormat("%*s%zu/%zu", spaces, "",
900 pp->sizes(), els);
901 spaces -= string.length() - oldLength;
902 }
903 spaces += spaces_current;
904
905 first = !first;
906 }
907
908 if (gone_els) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800909 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800910 string.appendFormat("%*s", spaces, "");
911 }
912
913 intermediate = string.format("%d/?", u);
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700914 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800915 intermediate.string());
916 intermediate.clear();
917
918 spaces = spaces_total + spaces_current;
919
920 oldLength = string.length();
921 string.appendFormat("%zu/%zu", gone_szs, gone_els);
922 spaces -= string.length() - oldLength;
923
924 first = !first;
925 }
926 }
927 }
928
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800929 *buf = strdup(string.string());
Mark Salyzyn34facab2014-02-06 14:48:50 -0800930}
Mark Salyzyn4ba03872014-04-07 07:15:33 -0700931
932uid_t LogStatistics::pidToUid(pid_t pid) {
933 log_id_for_each(i) {
934 LidStatistics &l = id(i);
935 UidStatisticsCollection::iterator iu;
936 for (iu = l.begin(); iu != l.end(); ++iu) {
937 UidStatistics &u = *(*iu);
938 PidStatisticsCollection::iterator ip;
939 for (ip = u.begin(); ip != u.end(); ++ip) {
940 if ((*ip)->getPid() == pid) {
941 return u.getUid();
942 }
943 }
944 }
945 }
946 return getuid(); // associate this with the logger
947}