blob: baf15fe2588301af46e784effee3125f087938e5 [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 }
57 if (kill(pid, 0) && (errno != EPERM)) {
58 mGone = true;
59 return true;
60 }
61 return false;
62}
63
Mark Salyzyn9a038632014-04-07 07:05:40 -070064void PidStatistics::setName(char *new_name) {
65 free(name);
66 name = new_name;
67}
Mark Salyzyn34facab2014-02-06 14:48:50 -080068
69void PidStatistics::add(unsigned short size) {
70 mSizesTotal += size;
71 ++mElementsTotal;
72 mSizes += size;
73 ++mElements;
74}
75
76bool PidStatistics::subtract(unsigned short size) {
77 mSizes -= size;
78 --mElements;
Mark Salyzynfdabe722014-04-21 10:09:42 -070079 return (mElements == 0) && pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -080080}
81
82void PidStatistics::addTotal(size_t size, size_t element) {
83 if (pid == gone) {
84 mSizesTotal += size;
85 mElementsTotal += element;
86 }
87}
88
Mark Salyzyn9a038632014-04-07 07:05:40 -070089// must call free to release return value
Mark Salyzyne72c6e42014-09-21 14:22:18 -070090// If only we could sniff our own logs for:
91// <time> <pid> <pid> E AndroidRuntime: Process: <name>, PID: <pid>
92// which debuggerd prints as a process is crashing.
Mark Salyzyn9a038632014-04-07 07:05:40 -070093char *PidStatistics::pidToName(pid_t pid) {
94 char *retval = NULL;
Mark Salyzynfdabe722014-04-21 10:09:42 -070095 if (pid != gone) {
Mark Salyzyn9a038632014-04-07 07:05:40 -070096 char buffer[512];
97 snprintf(buffer, sizeof(buffer), "/proc/%u/cmdline", pid);
98 int fd = open(buffer, O_RDONLY);
99 if (fd >= 0) {
100 ssize_t ret = read(fd, buffer, sizeof(buffer));
101 if (ret > 0) {
102 buffer[sizeof(buffer)-1] = '\0';
103 // frameworks intermediate state
104 if (strcmp(buffer, "<pre-initialized>")) {
105 retval = strdup(buffer);
106 }
107 }
108 close(fd);
109 }
110 }
111 return retval;
112}
113
Mark Salyzyn34facab2014-02-06 14:48:50 -0800114UidStatistics::UidStatistics(uid_t uid)
Mark Salyzync8a576c2014-04-04 16:35:59 -0700115 : uid(uid)
116 , mSizes(0)
117 , mElements(0) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800118 Pids.clear();
119}
120
121UidStatistics::~UidStatistics() {
122 PidStatisticsCollection::iterator it;
123 for (it = begin(); it != end();) {
124 delete (*it);
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700125 it = erase(it);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800126 }
127}
128
129void UidStatistics::add(unsigned short size, pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700130 mSizes += size;
131 ++mElements;
132
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700133 PidStatistics *p = NULL;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800134 PidStatisticsCollection::iterator last;
135 PidStatisticsCollection::iterator it;
136 for (last = it = begin(); it != end(); last = it, ++it) {
137 p = *it;
138 if (pid == p->getPid()) {
139 p->add(size);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800140 return;
141 }
142 }
Mark Salyzync8a576c2014-04-04 16:35:59 -0700143 // insert if the gone entry.
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700144 bool insert_before_last = (last != it) && p && (p->getPid() == p->gone);
Mark Salyzyn9a038632014-04-07 07:05:40 -0700145 p = new PidStatistics(pid, pidToName(pid));
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700146 if (insert_before_last) {
147 insert(last, p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800148 } else {
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700149 push_back(p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800150 }
151 p->add(size);
152}
153
154void UidStatistics::subtract(unsigned short size, pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700155 mSizes -= size;
156 --mElements;
157
Mark Salyzyn34facab2014-02-06 14:48:50 -0800158 PidStatisticsCollection::iterator it;
159 for (it = begin(); it != end(); ++it) {
160 PidStatistics *p = *it;
161 if (pid == p->getPid()) {
162 if (p->subtract(size)) {
163 size_t szsTotal = p->sizesTotal();
164 size_t elsTotal = p->elementsTotal();
165 delete p;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700166 erase(it);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800167 it = end();
168 --it;
169 if (it == end()) {
170 p = new PidStatistics(p->gone);
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700171 push_back(p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800172 } else {
173 p = *it;
174 if (p->getPid() != p->gone) {
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 }
178 }
179 p->addTotal(szsTotal, elsTotal);
180 }
181 return;
182 }
183 }
184}
185
Mark Salyzync8a576c2014-04-04 16:35:59 -0700186void UidStatistics::sort() {
187 for (bool pass = true; pass;) {
188 pass = false;
189 PidStatisticsCollection::iterator it = begin();
190 if (it != end()) {
191 PidStatisticsCollection::iterator lt = it;
192 PidStatistics *l = (*lt);
193 while (++it != end()) {
194 PidStatistics *n = (*it);
195 if ((n->getPid() != n->gone) && (n->sizes() > l->sizes())) {
196 pass = true;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700197 erase(it);
198 insert(lt, n);
Mark Salyzync8a576c2014-04-04 16:35:59 -0700199 it = lt;
200 n = l;
201 }
202 lt = it;
203 l = n;
204 }
205 }
206 }
207}
208
Mark Salyzyn34facab2014-02-06 14:48:50 -0800209size_t UidStatistics::sizes(pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700210 if (pid == pid_all) {
211 return sizes();
212 }
213
Mark Salyzyn34facab2014-02-06 14:48:50 -0800214 PidStatisticsCollection::iterator it;
215 for (it = begin(); it != end(); ++it) {
216 PidStatistics *p = *it;
Mark Salyzync8a576c2014-04-04 16:35:59 -0700217 if (pid == p->getPid()) {
218 return p->sizes();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800219 }
220 }
Mark Salyzync8a576c2014-04-04 16:35:59 -0700221 return 0;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800222}
223
224size_t UidStatistics::elements(pid_t pid) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700225 if (pid == pid_all) {
226 return elements();
227 }
228
Mark Salyzyn34facab2014-02-06 14:48:50 -0800229 PidStatisticsCollection::iterator it;
230 for (it = begin(); it != end(); ++it) {
231 PidStatistics *p = *it;
Mark Salyzync8a576c2014-04-04 16:35:59 -0700232 if (pid == p->getPid()) {
233 return p->elements();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800234 }
235 }
Mark Salyzync8a576c2014-04-04 16:35:59 -0700236 return 0;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800237}
238
239size_t UidStatistics::sizesTotal(pid_t pid) {
240 size_t sizes = 0;
241 PidStatisticsCollection::iterator it;
242 for (it = begin(); it != end(); ++it) {
243 PidStatistics *p = *it;
244 if ((pid == pid_all) || (pid == p->getPid())) {
245 sizes += p->sizesTotal();
246 }
247 }
248 return sizes;
249}
250
251size_t UidStatistics::elementsTotal(pid_t pid) {
252 size_t elements = 0;
253 PidStatisticsCollection::iterator it;
254 for (it = begin(); it != end(); ++it) {
255 PidStatistics *p = *it;
256 if ((pid == pid_all) || (pid == p->getPid())) {
257 elements += p->elementsTotal();
258 }
259 }
260 return elements;
261}
262
263LidStatistics::LidStatistics() {
264 Uids.clear();
265}
266
267LidStatistics::~LidStatistics() {
268 UidStatisticsCollection::iterator it;
269 for (it = begin(); it != end();) {
270 delete (*it);
271 it = Uids.erase(it);
272 }
273}
274
275void LidStatistics::add(unsigned short size, uid_t uid, pid_t pid) {
276 UidStatistics *u;
277 UidStatisticsCollection::iterator it;
278 UidStatisticsCollection::iterator last;
279
280 if (uid == (uid_t) -1) { // init
281 uid = (uid_t) AID_ROOT;
282 }
283
284 for (last = it = begin(); it != end(); last = it, ++it) {
285 u = *it;
286 if (uid == u->getUid()) {
287 u->add(size, pid);
288 if ((last != it) && ((*last)->sizesTotal() < u->sizesTotal())) {
289 Uids.erase(it);
290 Uids.insert(last, u);
291 }
292 return;
293 }
294 }
295 u = new UidStatistics(uid);
296 if ((last != it) && ((*last)->sizesTotal() < (size_t) size)) {
297 Uids.insert(last, u);
298 } else {
299 Uids.push_back(u);
300 }
301 u->add(size, pid);
302}
303
304void LidStatistics::subtract(unsigned short size, uid_t uid, pid_t pid) {
305 UidStatisticsCollection::iterator it;
306 for (it = begin(); it != end(); ++it) {
307 UidStatistics *u = *it;
308 if (uid == u->getUid()) {
309 u->subtract(size, pid);
310 return;
311 }
312 }
313}
314
Mark Salyzync8a576c2014-04-04 16:35:59 -0700315void LidStatistics::sort() {
316 for (bool pass = true; pass;) {
317 pass = false;
318 UidStatisticsCollection::iterator it = begin();
319 if (it != end()) {
320 UidStatisticsCollection::iterator lt = it;
321 UidStatistics *l = (*lt);
322 while (++it != end()) {
323 UidStatistics *n = (*it);
324 if (n->sizes() > l->sizes()) {
325 pass = true;
326 Uids.erase(it);
327 Uids.insert(lt, n);
328 it = lt;
329 n = l;
330 }
331 lt = it;
332 l = n;
333 }
334 }
335 }
336}
337
Mark Salyzyn34facab2014-02-06 14:48:50 -0800338size_t LidStatistics::sizes(uid_t uid, pid_t pid) {
339 size_t sizes = 0;
340 UidStatisticsCollection::iterator it;
341 for (it = begin(); it != end(); ++it) {
342 UidStatistics *u = *it;
343 if ((uid == uid_all) || (uid == u->getUid())) {
344 sizes += u->sizes(pid);
345 }
346 }
347 return sizes;
348}
349
350size_t LidStatistics::elements(uid_t uid, pid_t pid) {
351 size_t elements = 0;
352 UidStatisticsCollection::iterator it;
353 for (it = begin(); it != end(); ++it) {
354 UidStatistics *u = *it;
355 if ((uid == uid_all) || (uid == u->getUid())) {
356 elements += u->elements(pid);
357 }
358 }
359 return elements;
360}
361
362size_t LidStatistics::sizesTotal(uid_t uid, pid_t pid) {
363 size_t sizes = 0;
364 UidStatisticsCollection::iterator it;
365 for (it = begin(); it != end(); ++it) {
366 UidStatistics *u = *it;
367 if ((uid == uid_all) || (uid == u->getUid())) {
368 sizes += u->sizesTotal(pid);
369 }
370 }
371 return sizes;
372}
373
374size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) {
375 size_t elements = 0;
376 UidStatisticsCollection::iterator it;
377 for (it = begin(); it != end(); ++it) {
378 UidStatistics *u = *it;
379 if ((uid == uid_all) || (uid == u->getUid())) {
380 elements += u->elementsTotal(pid);
381 }
382 }
383 return elements;
384}
385
386LogStatistics::LogStatistics()
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700387 : mStatistics(false)
388 , dgramQlenStatistics(false)
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700389 , start(CLOCK_MONOTONIC) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800390 log_id_for_each(i) {
391 mSizes[i] = 0;
392 mElements[i] = 0;
393 }
Mark Salyzyne457b742014-02-19 17:18:31 -0800394
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700395 for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700396 mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max;
397 mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max;
Mark Salyzyne457b742014-02-19 17:18:31 -0800398 }
399}
400
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700401// Each bucket below represents a dgramQlen of log messages. By
Mark Salyzyne457b742014-02-19 17:18:31 -0800402// finding the minimum period of time from start to finish
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700403// of each dgramQlen, we can get a performance expectation for
Mark Salyzyne457b742014-02-19 17:18:31 -0800404// the user space logger. The net result is that the period
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700405// of time divided by the dgramQlen will give us the average time
Mark Salyzyne457b742014-02-19 17:18:31 -0800406// between log messages; at the point where the average time
407// is greater than the throughput capability of the logger
408// we will not longer require the benefits of the FIFO formed
409// by max_dgram_qlen. We will also expect to see a very visible
410// knee in the average time between log messages at this point,
411// so we do not necessarily have to compare the rate against the
412// measured performance (BM_log_maximum_retry) of the logger.
413//
414// for example (reformatted):
415//
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700416// Minimum time between log events per dgramQlen:
Mark Salyzyne457b742014-02-19 17:18:31 -0800417// 1 2 3 5 10 20 30 50 100 200 300 400 500 600
418// 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5
419//
420// demonstrates a clear knee rising at 100, so this means that for this
421// case max_dgram_qlen = 100 would be more than sufficient to handle the
422// worst that the system could stuff into the logger. The
423// BM_log_maximum_retry performance (derated by the log collection) on the
424// same system was 33.2us so we would almost be fine with max_dgram_qlen = 50.
425// BM_log_maxumum_retry with statistics off is roughly 20us, so
426// max_dgram_qlen = 20 would work. We will be more than willing to have
427// a large engineering margin so the rule of thumb that lead us to 100 is
428// fine.
429//
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700430// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300
Mark Salyzyne457b742014-02-19 17:18:31 -0800431const unsigned short LogStatistics::mBuckets[] = {
432 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600
433};
434
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700435unsigned short LogStatistics::dgramQlen(unsigned short bucket) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800436 if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) {
437 return 0;
438 }
439 return mBuckets[bucket];
440}
441
442unsigned long long LogStatistics::minimum(unsigned short bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700443 if (mMinimum[bucket].tv_sec == mMinimum[bucket].tv_sec_max) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800444 return 0;
445 }
446 return mMinimum[bucket].nsec();
447}
448
449void LogStatistics::recordDiff(log_time diff, unsigned short bucket) {
450 if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) {
451 mMinimum[bucket] = diff;
452 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800453}
454
455void LogStatistics::add(unsigned short size,
456 log_id_t log_id, uid_t uid, pid_t pid) {
457 mSizes[log_id] += size;
458 ++mElements[log_id];
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700459 if (!mStatistics) {
460 return;
461 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800462 id(log_id).add(size, uid, pid);
463}
464
465void LogStatistics::subtract(unsigned short size,
466 log_id_t log_id, uid_t uid, pid_t pid) {
467 mSizes[log_id] -= size;
468 --mElements[log_id];
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700469 if (!mStatistics) {
470 return;
471 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800472 id(log_id).subtract(size, uid, pid);
473}
474
475size_t LogStatistics::sizes(log_id_t log_id, uid_t uid, pid_t pid) {
476 if (log_id != log_id_all) {
477 return id(log_id).sizes(uid, pid);
478 }
479 size_t sizes = 0;
480 log_id_for_each(i) {
481 sizes += id(i).sizes(uid, pid);
482 }
483 return sizes;
484}
485
486size_t LogStatistics::elements(log_id_t log_id, uid_t uid, pid_t pid) {
487 if (log_id != log_id_all) {
488 return id(log_id).elements(uid, pid);
489 }
490 size_t elements = 0;
491 log_id_for_each(i) {
492 elements += id(i).elements(uid, pid);
493 }
494 return elements;
495}
496
497size_t LogStatistics::sizesTotal(log_id_t log_id, uid_t uid, pid_t pid) {
498 if (log_id != log_id_all) {
499 return id(log_id).sizesTotal(uid, pid);
500 }
501 size_t sizes = 0;
502 log_id_for_each(i) {
503 sizes += id(i).sizesTotal(uid, pid);
504 }
505 return sizes;
506}
507
508size_t LogStatistics::elementsTotal(log_id_t log_id, uid_t uid, pid_t pid) {
509 if (log_id != log_id_all) {
510 return id(log_id).elementsTotal(uid, pid);
511 }
512 size_t elements = 0;
513 log_id_for_each(i) {
514 elements += id(i).elementsTotal(uid, pid);
515 }
516 return elements;
517}
518
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800519void LogStatistics::format(char **buf,
520 uid_t uid, unsigned int logMask, log_time oldest) {
Mark Salyzyn9a038632014-04-07 07:05:40 -0700521 static const unsigned short spaces_current = 13;
522 static const unsigned short spaces_total = 19;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800523
524 if (*buf) {
Greg Hackmann239605e2014-04-06 21:25:58 -0700525 free(*buf);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800526 *buf = NULL;
527 }
528
529 android::String8 string(" span -> size/num");
530 size_t oldLength;
531 short spaces = 2;
532
533 log_id_for_each(i) {
Arseniy Antonovc3ce2242014-09-03 17:29:20 +0400534 if (!(logMask & (1 << i))) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700535 continue;
536 }
537 oldLength = string.length();
538 if (spaces < 0) {
539 spaces = 0;
540 }
541 string.appendFormat("%*s%s", spaces, "", android_log_id_to_name(i));
542 spaces += spaces_total + oldLength - string.length();
543
544 LidStatistics &l = id(i);
545 l.sort();
546
547 UidStatisticsCollection::iterator iu;
548 for (iu = l.begin(); iu != l.end(); ++iu) {
549 (*iu)->sort();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800550 }
551 }
552
553 spaces = 1;
554 log_time t(CLOCK_MONOTONIC);
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700555 unsigned long long d;
556 if (mStatistics) {
557 d = t.nsec() - start.nsec();
558 string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800559 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
560 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
561
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700562 log_id_for_each(i) {
563 if (!(logMask & (1 << i))) {
564 continue;
565 }
566 oldLength = string.length();
567 if (spaces < 0) {
568 spaces = 0;
569 }
570 string.appendFormat("%*s%zu/%zu", spaces, "",
571 sizesTotal(i), elementsTotal(i));
572 spaces += spaces_total + oldLength - string.length();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800573 }
Mark Salyzynf5fc5092014-09-21 14:22:18 -0700574 spaces = 1;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800575 }
576
Mark Salyzyn34facab2014-02-06 14:48:50 -0800577 d = t.nsec() - oldest.nsec();
578 string.appendFormat("\nNow%6llu:%02llu:%02llu.%09llu",
579 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
580 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
581
582 log_id_for_each(i) {
583 if (!(logMask & (1 << i))) {
584 continue;
585 }
586
587 size_t els = elements(i);
588 if (els) {
589 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800590 if (spaces < 0) {
591 spaces = 0;
592 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800593 string.appendFormat("%*s%zu/%zu", spaces, "", sizes(i), els);
594 spaces -= string.length() - oldLength;
595 }
596 spaces += spaces_total;
597 }
598
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700599 // Construct list of worst spammers by Pid
600 static const unsigned char num_spammers = 10;
601 bool header = false;
602
603 log_id_for_each(i) {
604 if (!(logMask & (1 << i))) {
605 continue;
606 }
607
608 PidStatisticsCollection pids;
609 pids.clear();
610
611 LidStatistics &l = id(i);
612 UidStatisticsCollection::iterator iu;
613 for (iu = l.begin(); iu != l.end(); ++iu) {
614 UidStatistics &u = *(*iu);
615 PidStatisticsCollection::iterator ip;
616 for (ip = u.begin(); ip != u.end(); ++ip) {
617 PidStatistics *p = (*ip);
618 if (p->getPid() == p->gone) {
619 break;
620 }
621
622 size_t mySizes = p->sizes();
623
624 PidStatisticsCollection::iterator q;
625 unsigned char num = 0;
626 for (q = pids.begin(); q != pids.end(); ++q) {
627 if (mySizes > (*q)->sizes()) {
628 pids.insert(q, p);
629 break;
630 }
631 // do we need to traverse deeper in the list?
632 if (++num > num_spammers) {
633 break;
634 }
635 }
636 if (q == pids.end()) {
637 pids.push_back(p);
638 }
639 }
640 }
641
642 size_t threshold = sizes(i);
643 if (threshold < 65536) {
644 threshold = 65536;
645 }
646 threshold /= 100;
647
648 PidStatisticsCollection::iterator pt = pids.begin();
649
650 for(int line = 0;
651 (pt != pids.end()) && (line < num_spammers);
652 ++line, pt = pids.erase(pt)) {
653 PidStatistics *p = *pt;
654
655 size_t sizes = p->sizes();
656 if (sizes < threshold) {
657 break;
658 }
659
660 char *name = p->getName();
661 pid_t pid = p->getPid();
662 if (!name || !*name) {
663 name = pidToName(pid);
664 if (name) {
665 if (*name) {
666 p->setName(name);
667 } else {
668 free(name);
669 name = NULL;
670 }
671 }
672 }
673
674 if (!header) {
675 string.appendFormat("\n\nChattiest clients:\n"
676 "log id %-*s PID[?] name",
677 spaces_total, "size/total");
678 header = true;
679 }
680
681 size_t sizesTotal = p->sizesTotal();
682
683 android::String8 sz("");
Chih-Hung Hsieh634118e2014-09-12 16:02:28 -0700684 if (sizes == sizesTotal) {
685 sz.appendFormat("%zu", sizes);
686 } else {
687 sz.appendFormat("%zu/%zu", sizes, sizesTotal);
688 }
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700689
690 android::String8 pd("");
Mark Salyzynfdabe722014-04-21 10:09:42 -0700691 pd.appendFormat("%u%c", pid, p->pidGone() ? '?' : ' ');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700692
693 string.appendFormat("\n%-7s%-*s %-7s%s",
694 line ? "" : android_log_id_to_name(i),
695 spaces_total, sz.string(), pd.string(),
696 name ? name : "");
697 }
698
699 pids.clear();
700 }
701
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700702 if (dgramQlenStatistics) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800703 const unsigned short spaces_time = 6;
704 const unsigned long long max_seconds = 100000;
705 spaces = 0;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700706 string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
707 for(unsigned short i = 0; dgramQlen(i); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800708 oldLength = string.length();
709 if (spaces < 0) {
710 spaces = 0;
711 }
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700712 string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
Mark Salyzyne457b742014-02-19 17:18:31 -0800713 spaces += spaces_time + oldLength - string.length();
714 }
715 string.append("\n");
716 spaces = 0;
717 unsigned short n;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700718 for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800719 unsigned long long duration = minimum(i);
720 if (duration) {
721 duration /= n;
722 if (duration >= (NS_PER_SEC * max_seconds)) {
723 duration = NS_PER_SEC * (max_seconds - 1);
724 }
725 oldLength = string.length();
726 if (spaces < 0) {
727 spaces = 0;
728 }
729 string.appendFormat("%*s", spaces, "");
730 if (duration >= (NS_PER_SEC * 10)) {
731 string.appendFormat("%llu",
732 (duration + (NS_PER_SEC / 2))
733 / NS_PER_SEC);
734 } else if (duration >= (NS_PER_SEC / (1000 / 10))) {
735 string.appendFormat("%llum",
736 (duration + (NS_PER_SEC / 2 / 1000))
737 / (NS_PER_SEC / 1000));
738 } else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
739 string.appendFormat("%lluu",
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700740 (duration + (NS_PER_SEC / 2 / 1000000))
741 / (NS_PER_SEC / 1000000));
Mark Salyzyne457b742014-02-19 17:18:31 -0800742 } else {
743 string.appendFormat("%llun", duration);
744 }
745 spaces -= string.length() - oldLength;
746 }
747 spaces += spaces_time;
748 }
749 }
750
Mark Salyzyn34facab2014-02-06 14:48:50 -0800751 log_id_for_each(i) {
752 if (!(logMask & (1 << i))) {
753 continue;
754 }
755
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700756 header = false;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800757 bool first = true;
758
759 UidStatisticsCollection::iterator ut;
760 for(ut = id(i).begin(); ut != id(i).end(); ++ut) {
761 UidStatistics *up = *ut;
762 if ((uid != AID_ROOT) && (uid != up->getUid())) {
763 continue;
764 }
765
766 PidStatisticsCollection::iterator pt = up->begin();
767 if (pt == up->end()) {
768 continue;
769 }
770
771 android::String8 intermediate;
772
773 if (!header) {
774 // header below tuned to match spaces_total and spaces_current
775 spaces = 0;
776 intermediate = string.format("%s: UID/PID Total size/num",
777 android_log_id_to_name(i));
778 string.appendFormat("\n\n%-31sNow "
779 "UID/PID[?] Total Now",
780 intermediate.string());
781 intermediate.clear();
782 header = true;
783 }
784
785 bool oneline = ++pt == up->end();
786 --pt;
787
788 if (!oneline) {
789 first = true;
Mark Salyzyne457b742014-02-19 17:18:31 -0800790 } else if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800791 string.appendFormat("%*s", spaces, "");
792 }
793 spaces = 0;
794
795 uid_t u = up->getUid();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700796 PidStatistics *pp = *pt;
797 pid_t p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800798
Chih-Hung Hsieh634118e2014-09-12 16:02:28 -0700799 if (!oneline) {
800 intermediate = string.format("%d", u);
801 } else if (p == PidStatistics::gone) {
802 intermediate = string.format("%d/?", u);
803 } else if (pp->pidGone()) {
804 intermediate = string.format("%d/%d?", u, p);
805 } else {
806 intermediate = string.format("%d/%d", u, p);
807 }
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700808 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800809 intermediate.string());
810 intermediate.clear();
811
812 size_t elsTotal = up->elementsTotal();
813 oldLength = string.length();
814 string.appendFormat("%zu/%zu", up->sizesTotal(), elsTotal);
815 spaces += spaces_total + oldLength - string.length();
816
817 size_t els = up->elements();
818 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800819 if (spaces < 0) {
820 spaces = 0;
821 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800822 string.appendFormat("%*s=", spaces, "");
823 spaces = -1;
824 } else if (els) {
825 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800826 if (spaces < 0) {
827 spaces = 0;
828 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800829 string.appendFormat("%*s%zu/%zu", spaces, "", up->sizes(), els);
830 spaces -= string.length() - oldLength;
831 }
832 spaces += spaces_current;
833
834 first = !first;
835
836 if (oneline) {
837 continue;
838 }
839
840 size_t gone_szs = 0;
841 size_t gone_els = 0;
842
843 for(; pt != up->end(); ++pt) {
Mark Salyzynfdabe722014-04-21 10:09:42 -0700844 pp = *pt;
845 p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800846
847 // If a PID no longer has any current logs, and is not
848 // active anymore, skip & report totals for gone.
849 elsTotal = pp->elementsTotal();
850 size_t szsTotal = pp->sizesTotal();
851 if (p == pp->gone) {
852 gone_szs += szsTotal;
853 gone_els += elsTotal;
854 continue;
855 }
856 els = pp->elements();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700857 bool gone = pp->pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800858 if (gone && (els == 0)) {
859 // ToDo: garbage collection: move this statistical bucket
860 // from its current UID/PID to UID/? (races and
861 // wrap around are our achilles heel). Below is
862 // merely lipservice to catch PIDs that were still
863 // around when the stats were pruned to zero.
864 gone_szs += szsTotal;
865 gone_els += elsTotal;
866 continue;
867 }
868
Mark Salyzyne457b742014-02-19 17:18:31 -0800869 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800870 string.appendFormat("%*s", spaces, "");
871 }
872 spaces = 0;
873
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700874 intermediate = string.format(gone ? "%d/%d?" : "%d/%d", u, p);
875 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800876 intermediate.string());
877 intermediate.clear();
878
879 oldLength = string.length();
880 string.appendFormat("%zu/%zu", szsTotal, elsTotal);
881 spaces += spaces_total + oldLength - string.length();
882
883 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800884 if (spaces < 0) {
885 spaces = 0;
886 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800887 string.appendFormat("%*s=", spaces, "");
888 spaces = -1;
889 } else if (els) {
890 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800891 if (spaces < 0) {
892 spaces = 0;
893 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800894 string.appendFormat("%*s%zu/%zu", spaces, "",
895 pp->sizes(), els);
896 spaces -= string.length() - oldLength;
897 }
898 spaces += spaces_current;
899
900 first = !first;
901 }
902
903 if (gone_els) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800904 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800905 string.appendFormat("%*s", spaces, "");
906 }
907
908 intermediate = string.format("%d/?", u);
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700909 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800910 intermediate.string());
911 intermediate.clear();
912
913 spaces = spaces_total + spaces_current;
914
915 oldLength = string.length();
916 string.appendFormat("%zu/%zu", gone_szs, gone_els);
917 spaces -= string.length() - oldLength;
918
919 first = !first;
920 }
921 }
922 }
923
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800924 *buf = strdup(string.string());
Mark Salyzyn34facab2014-02-06 14:48:50 -0800925}
Mark Salyzyn4ba03872014-04-07 07:15:33 -0700926
927uid_t LogStatistics::pidToUid(pid_t pid) {
928 log_id_for_each(i) {
929 LidStatistics &l = id(i);
930 UidStatisticsCollection::iterator iu;
931 for (iu = l.begin(); iu != l.end(); ++iu) {
932 UidStatistics &u = *(*iu);
933 PidStatisticsCollection::iterator ip;
934 for (ip = u.begin(); ip != u.end(); ++ip) {
935 if ((*ip)->getPid() == pid) {
936 return u.getUid();
937 }
938 }
939 }
940 }
941 return getuid(); // associate this with the logger
942}