blob: 2a45590baf2f0f48b602d74df5f46a53a03cc5d1 [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 Salyzyn987f1e02014-09-21 14:22:18 -070054 if (mGone || (pid == gone)) {
Mark Salyzynfdabe722014-04-21 10:09:42 -070055 return true;
56 }
Mark Salyzyn260f3be2014-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 Salyzyn987f1e02014-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 Salyzyn260f3be2014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-09-21 14:22:18 -0700151 if (insert_before_last) {
152 insert(last, p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800153 } else {
Mark Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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) {
Mark Salyzyn1e1d71e2014-09-22 10:58:36 -0700310 if (uid == (uid_t) -1) { // init
311 uid = (uid_t) AID_ROOT;
312 }
313
Mark Salyzyn34facab2014-02-06 14:48:50 -0800314 UidStatisticsCollection::iterator it;
315 for (it = begin(); it != end(); ++it) {
316 UidStatistics *u = *it;
317 if (uid == u->getUid()) {
318 u->subtract(size, pid);
319 return;
320 }
321 }
322}
323
Mark Salyzync8a576c2014-04-04 16:35:59 -0700324void LidStatistics::sort() {
325 for (bool pass = true; pass;) {
326 pass = false;
327 UidStatisticsCollection::iterator it = begin();
328 if (it != end()) {
329 UidStatisticsCollection::iterator lt = it;
330 UidStatistics *l = (*lt);
331 while (++it != end()) {
332 UidStatistics *n = (*it);
333 if (n->sizes() > l->sizes()) {
334 pass = true;
335 Uids.erase(it);
336 Uids.insert(lt, n);
337 it = lt;
338 n = l;
339 }
340 lt = it;
341 l = n;
342 }
343 }
344 }
345}
346
Mark Salyzyn34facab2014-02-06 14:48:50 -0800347size_t LidStatistics::sizes(uid_t uid, pid_t pid) {
348 size_t sizes = 0;
349 UidStatisticsCollection::iterator it;
350 for (it = begin(); it != end(); ++it) {
351 UidStatistics *u = *it;
352 if ((uid == uid_all) || (uid == u->getUid())) {
353 sizes += u->sizes(pid);
354 }
355 }
356 return sizes;
357}
358
359size_t LidStatistics::elements(uid_t uid, pid_t pid) {
360 size_t elements = 0;
361 UidStatisticsCollection::iterator it;
362 for (it = begin(); it != end(); ++it) {
363 UidStatistics *u = *it;
364 if ((uid == uid_all) || (uid == u->getUid())) {
365 elements += u->elements(pid);
366 }
367 }
368 return elements;
369}
370
371size_t LidStatistics::sizesTotal(uid_t uid, pid_t pid) {
372 size_t sizes = 0;
373 UidStatisticsCollection::iterator it;
374 for (it = begin(); it != end(); ++it) {
375 UidStatistics *u = *it;
376 if ((uid == uid_all) || (uid == u->getUid())) {
377 sizes += u->sizesTotal(pid);
378 }
379 }
380 return sizes;
381}
382
383size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) {
384 size_t elements = 0;
385 UidStatisticsCollection::iterator it;
386 for (it = begin(); it != end(); ++it) {
387 UidStatistics *u = *it;
388 if ((uid == uid_all) || (uid == u->getUid())) {
389 elements += u->elementsTotal(pid);
390 }
391 }
392 return elements;
393}
394
395LogStatistics::LogStatistics()
Mark Salyzyna0e53542014-09-21 14:22:18 -0700396 : mStatistics(false)
397 , dgramQlenStatistics(false)
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700398 , start(CLOCK_MONOTONIC) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800399 log_id_for_each(i) {
400 mSizes[i] = 0;
401 mElements[i] = 0;
402 }
Mark Salyzyne457b742014-02-19 17:18:31 -0800403
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700404 for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700405 mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max;
406 mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max;
Mark Salyzyne457b742014-02-19 17:18:31 -0800407 }
408}
409
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700410// Each bucket below represents a dgramQlen of log messages. By
Mark Salyzyne457b742014-02-19 17:18:31 -0800411// finding the minimum period of time from start to finish
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700412// of each dgramQlen, we can get a performance expectation for
Mark Salyzyne457b742014-02-19 17:18:31 -0800413// the user space logger. The net result is that the period
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700414// of time divided by the dgramQlen will give us the average time
Mark Salyzyne457b742014-02-19 17:18:31 -0800415// between log messages; at the point where the average time
416// is greater than the throughput capability of the logger
417// we will not longer require the benefits of the FIFO formed
418// by max_dgram_qlen. We will also expect to see a very visible
419// knee in the average time between log messages at this point,
420// so we do not necessarily have to compare the rate against the
421// measured performance (BM_log_maximum_retry) of the logger.
422//
423// for example (reformatted):
424//
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700425// Minimum time between log events per dgramQlen:
Mark Salyzyne457b742014-02-19 17:18:31 -0800426// 1 2 3 5 10 20 30 50 100 200 300 400 500 600
427// 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5
428//
429// demonstrates a clear knee rising at 100, so this means that for this
430// case max_dgram_qlen = 100 would be more than sufficient to handle the
431// worst that the system could stuff into the logger. The
432// BM_log_maximum_retry performance (derated by the log collection) on the
433// same system was 33.2us so we would almost be fine with max_dgram_qlen = 50.
434// BM_log_maxumum_retry with statistics off is roughly 20us, so
435// max_dgram_qlen = 20 would work. We will be more than willing to have
436// a large engineering margin so the rule of thumb that lead us to 100 is
437// fine.
438//
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700439// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300
Mark Salyzyne457b742014-02-19 17:18:31 -0800440const unsigned short LogStatistics::mBuckets[] = {
441 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600
442};
443
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700444unsigned short LogStatistics::dgramQlen(unsigned short bucket) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800445 if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) {
446 return 0;
447 }
448 return mBuckets[bucket];
449}
450
451unsigned long long LogStatistics::minimum(unsigned short bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700452 if (mMinimum[bucket].tv_sec == mMinimum[bucket].tv_sec_max) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800453 return 0;
454 }
455 return mMinimum[bucket].nsec();
456}
457
458void LogStatistics::recordDiff(log_time diff, unsigned short bucket) {
459 if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) {
460 mMinimum[bucket] = diff;
461 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800462}
463
464void LogStatistics::add(unsigned short size,
465 log_id_t log_id, uid_t uid, pid_t pid) {
466 mSizes[log_id] += size;
467 ++mElements[log_id];
Mark Salyzyna0e53542014-09-21 14:22:18 -0700468 if (!mStatistics) {
469 return;
470 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800471 id(log_id).add(size, uid, pid);
472}
473
474void LogStatistics::subtract(unsigned short size,
475 log_id_t log_id, uid_t uid, pid_t pid) {
476 mSizes[log_id] -= size;
477 --mElements[log_id];
Mark Salyzyna0e53542014-09-21 14:22:18 -0700478 if (!mStatistics) {
479 return;
480 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800481 id(log_id).subtract(size, uid, pid);
482}
483
484size_t LogStatistics::sizes(log_id_t log_id, uid_t uid, pid_t pid) {
485 if (log_id != log_id_all) {
486 return id(log_id).sizes(uid, pid);
487 }
488 size_t sizes = 0;
489 log_id_for_each(i) {
490 sizes += id(i).sizes(uid, pid);
491 }
492 return sizes;
493}
494
495size_t LogStatistics::elements(log_id_t log_id, uid_t uid, pid_t pid) {
496 if (log_id != log_id_all) {
497 return id(log_id).elements(uid, pid);
498 }
499 size_t elements = 0;
500 log_id_for_each(i) {
501 elements += id(i).elements(uid, pid);
502 }
503 return elements;
504}
505
506size_t LogStatistics::sizesTotal(log_id_t log_id, uid_t uid, pid_t pid) {
507 if (log_id != log_id_all) {
508 return id(log_id).sizesTotal(uid, pid);
509 }
510 size_t sizes = 0;
511 log_id_for_each(i) {
512 sizes += id(i).sizesTotal(uid, pid);
513 }
514 return sizes;
515}
516
517size_t LogStatistics::elementsTotal(log_id_t log_id, uid_t uid, pid_t pid) {
518 if (log_id != log_id_all) {
519 return id(log_id).elementsTotal(uid, pid);
520 }
521 size_t elements = 0;
522 log_id_for_each(i) {
523 elements += id(i).elementsTotal(uid, pid);
524 }
525 return elements;
526}
527
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800528void LogStatistics::format(char **buf,
529 uid_t uid, unsigned int logMask, log_time oldest) {
Mark Salyzyn9a038632014-04-07 07:05:40 -0700530 static const unsigned short spaces_current = 13;
531 static const unsigned short spaces_total = 19;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800532
533 if (*buf) {
Greg Hackmann239605e2014-04-06 21:25:58 -0700534 free(*buf);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800535 *buf = NULL;
536 }
537
538 android::String8 string(" span -> size/num");
539 size_t oldLength;
540 short spaces = 2;
541
542 log_id_for_each(i) {
Arseniy Antonov3c8e92c2014-09-03 17:29:20 +0400543 if (!(logMask & (1 << i))) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700544 continue;
545 }
546 oldLength = string.length();
547 if (spaces < 0) {
548 spaces = 0;
549 }
550 string.appendFormat("%*s%s", spaces, "", android_log_id_to_name(i));
551 spaces += spaces_total + oldLength - string.length();
552
553 LidStatistics &l = id(i);
554 l.sort();
555
556 UidStatisticsCollection::iterator iu;
557 for (iu = l.begin(); iu != l.end(); ++iu) {
558 (*iu)->sort();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800559 }
560 }
561
562 spaces = 1;
563 log_time t(CLOCK_MONOTONIC);
Mark Salyzyna0e53542014-09-21 14:22:18 -0700564 unsigned long long d;
565 if (mStatistics) {
566 d = t.nsec() - start.nsec();
567 string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800568 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
569 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
570
Mark Salyzyna0e53542014-09-21 14:22:18 -0700571 log_id_for_each(i) {
572 if (!(logMask & (1 << i))) {
573 continue;
574 }
575 oldLength = string.length();
576 if (spaces < 0) {
577 spaces = 0;
578 }
579 string.appendFormat("%*s%zu/%zu", spaces, "",
580 sizesTotal(i), elementsTotal(i));
581 spaces += spaces_total + oldLength - string.length();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800582 }
Mark Salyzyna0e53542014-09-21 14:22:18 -0700583 spaces = 1;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800584 }
585
Mark Salyzyn34facab2014-02-06 14:48:50 -0800586 d = t.nsec() - oldest.nsec();
587 string.appendFormat("\nNow%6llu:%02llu:%02llu.%09llu",
588 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
589 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
590
591 log_id_for_each(i) {
592 if (!(logMask & (1 << i))) {
593 continue;
594 }
595
596 size_t els = elements(i);
597 if (els) {
598 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800599 if (spaces < 0) {
600 spaces = 0;
601 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800602 string.appendFormat("%*s%zu/%zu", spaces, "", sizes(i), els);
603 spaces -= string.length() - oldLength;
604 }
605 spaces += spaces_total;
606 }
607
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700608 // Construct list of worst spammers by Pid
609 static const unsigned char num_spammers = 10;
610 bool header = false;
611
612 log_id_for_each(i) {
613 if (!(logMask & (1 << i))) {
614 continue;
615 }
616
617 PidStatisticsCollection pids;
618 pids.clear();
619
620 LidStatistics &l = id(i);
621 UidStatisticsCollection::iterator iu;
622 for (iu = l.begin(); iu != l.end(); ++iu) {
623 UidStatistics &u = *(*iu);
624 PidStatisticsCollection::iterator ip;
625 for (ip = u.begin(); ip != u.end(); ++ip) {
626 PidStatistics *p = (*ip);
627 if (p->getPid() == p->gone) {
628 break;
629 }
630
631 size_t mySizes = p->sizes();
632
633 PidStatisticsCollection::iterator q;
634 unsigned char num = 0;
635 for (q = pids.begin(); q != pids.end(); ++q) {
636 if (mySizes > (*q)->sizes()) {
637 pids.insert(q, p);
638 break;
639 }
640 // do we need to traverse deeper in the list?
641 if (++num > num_spammers) {
642 break;
643 }
644 }
645 if (q == pids.end()) {
646 pids.push_back(p);
647 }
648 }
649 }
650
651 size_t threshold = sizes(i);
652 if (threshold < 65536) {
653 threshold = 65536;
654 }
655 threshold /= 100;
656
657 PidStatisticsCollection::iterator pt = pids.begin();
658
659 for(int line = 0;
660 (pt != pids.end()) && (line < num_spammers);
661 ++line, pt = pids.erase(pt)) {
662 PidStatistics *p = *pt;
663
664 size_t sizes = p->sizes();
665 if (sizes < threshold) {
666 break;
667 }
668
669 char *name = p->getName();
670 pid_t pid = p->getPid();
671 if (!name || !*name) {
672 name = pidToName(pid);
673 if (name) {
674 if (*name) {
675 p->setName(name);
676 } else {
677 free(name);
678 name = NULL;
679 }
680 }
681 }
682
683 if (!header) {
684 string.appendFormat("\n\nChattiest clients:\n"
685 "log id %-*s PID[?] name",
686 spaces_total, "size/total");
687 header = true;
688 }
689
690 size_t sizesTotal = p->sizesTotal();
691
692 android::String8 sz("");
693 sz.appendFormat((sizes != sizesTotal) ? "%zu/%zu" : "%zu",
694 sizes, sizesTotal);
695
696 android::String8 pd("");
Mark Salyzynfdabe722014-04-21 10:09:42 -0700697 pd.appendFormat("%u%c", pid, p->pidGone() ? '?' : ' ');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700698
699 string.appendFormat("\n%-7s%-*s %-7s%s",
700 line ? "" : android_log_id_to_name(i),
701 spaces_total, sz.string(), pd.string(),
702 name ? name : "");
703 }
704
705 pids.clear();
706 }
707
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700708 if (dgramQlenStatistics) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800709 const unsigned short spaces_time = 6;
710 const unsigned long long max_seconds = 100000;
711 spaces = 0;
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700712 string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
713 for(unsigned short i = 0; dgramQlen(i); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800714 oldLength = string.length();
715 if (spaces < 0) {
716 spaces = 0;
717 }
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700718 string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
Mark Salyzyne457b742014-02-19 17:18:31 -0800719 spaces += spaces_time + oldLength - string.length();
720 }
721 string.append("\n");
722 spaces = 0;
723 unsigned short n;
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700724 for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800725 unsigned long long duration = minimum(i);
726 if (duration) {
727 duration /= n;
728 if (duration >= (NS_PER_SEC * max_seconds)) {
729 duration = NS_PER_SEC * (max_seconds - 1);
730 }
731 oldLength = string.length();
732 if (spaces < 0) {
733 spaces = 0;
734 }
735 string.appendFormat("%*s", spaces, "");
736 if (duration >= (NS_PER_SEC * 10)) {
737 string.appendFormat("%llu",
738 (duration + (NS_PER_SEC / 2))
739 / NS_PER_SEC);
740 } else if (duration >= (NS_PER_SEC / (1000 / 10))) {
741 string.appendFormat("%llum",
742 (duration + (NS_PER_SEC / 2 / 1000))
743 / (NS_PER_SEC / 1000));
744 } else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
745 string.appendFormat("%lluu",
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700746 (duration + (NS_PER_SEC / 2 / 1000000))
747 / (NS_PER_SEC / 1000000));
Mark Salyzyne457b742014-02-19 17:18:31 -0800748 } else {
749 string.appendFormat("%llun", duration);
750 }
751 spaces -= string.length() - oldLength;
752 }
753 spaces += spaces_time;
754 }
755 }
756
Mark Salyzyn34facab2014-02-06 14:48:50 -0800757 log_id_for_each(i) {
758 if (!(logMask & (1 << i))) {
759 continue;
760 }
761
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700762 header = false;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800763 bool first = true;
764
765 UidStatisticsCollection::iterator ut;
766 for(ut = id(i).begin(); ut != id(i).end(); ++ut) {
767 UidStatistics *up = *ut;
768 if ((uid != AID_ROOT) && (uid != up->getUid())) {
769 continue;
770 }
771
772 PidStatisticsCollection::iterator pt = up->begin();
773 if (pt == up->end()) {
774 continue;
775 }
776
777 android::String8 intermediate;
778
779 if (!header) {
780 // header below tuned to match spaces_total and spaces_current
781 spaces = 0;
782 intermediate = string.format("%s: UID/PID Total size/num",
783 android_log_id_to_name(i));
784 string.appendFormat("\n\n%-31sNow "
785 "UID/PID[?] Total Now",
786 intermediate.string());
787 intermediate.clear();
788 header = true;
789 }
790
791 bool oneline = ++pt == up->end();
792 --pt;
793
794 if (!oneline) {
795 first = true;
Mark Salyzyne457b742014-02-19 17:18:31 -0800796 } else if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800797 string.appendFormat("%*s", spaces, "");
798 }
799 spaces = 0;
800
801 uid_t u = up->getUid();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700802 PidStatistics *pp = *pt;
803 pid_t p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800804
805 intermediate = string.format(oneline
806 ? ((p == PidStatistics::gone)
807 ? "%d/?"
Mark Salyzynfdabe722014-04-21 10:09:42 -0700808 : "%d/%d%c")
Mark Salyzyn34facab2014-02-06 14:48:50 -0800809 : "%d",
Mark Salyzynfdabe722014-04-21 10:09:42 -0700810 u, p, pp->pidGone() ? '?' : '\0');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700811 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800812 intermediate.string());
813 intermediate.clear();
814
815 size_t elsTotal = up->elementsTotal();
816 oldLength = string.length();
817 string.appendFormat("%zu/%zu", up->sizesTotal(), elsTotal);
818 spaces += spaces_total + oldLength - string.length();
819
820 size_t els = up->elements();
821 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800822 if (spaces < 0) {
823 spaces = 0;
824 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800825 string.appendFormat("%*s=", spaces, "");
826 spaces = -1;
827 } else if (els) {
828 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800829 if (spaces < 0) {
830 spaces = 0;
831 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800832 string.appendFormat("%*s%zu/%zu", spaces, "", up->sizes(), els);
833 spaces -= string.length() - oldLength;
834 }
835 spaces += spaces_current;
836
837 first = !first;
838
839 if (oneline) {
840 continue;
841 }
842
843 size_t gone_szs = 0;
844 size_t gone_els = 0;
845
846 for(; pt != up->end(); ++pt) {
Mark Salyzynfdabe722014-04-21 10:09:42 -0700847 pp = *pt;
848 p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800849
850 // If a PID no longer has any current logs, and is not
851 // active anymore, skip & report totals for gone.
852 elsTotal = pp->elementsTotal();
853 size_t szsTotal = pp->sizesTotal();
854 if (p == pp->gone) {
855 gone_szs += szsTotal;
856 gone_els += elsTotal;
857 continue;
858 }
859 els = pp->elements();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700860 bool gone = pp->pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800861 if (gone && (els == 0)) {
862 // ToDo: garbage collection: move this statistical bucket
863 // from its current UID/PID to UID/? (races and
864 // wrap around are our achilles heel). Below is
865 // merely lipservice to catch PIDs that were still
866 // around when the stats were pruned to zero.
867 gone_szs += szsTotal;
868 gone_els += elsTotal;
869 continue;
870 }
871
Mark Salyzyne457b742014-02-19 17:18:31 -0800872 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800873 string.appendFormat("%*s", spaces, "");
874 }
875 spaces = 0;
876
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700877 intermediate = string.format(gone ? "%d/%d?" : "%d/%d", u, p);
878 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800879 intermediate.string());
880 intermediate.clear();
881
882 oldLength = string.length();
883 string.appendFormat("%zu/%zu", szsTotal, elsTotal);
884 spaces += spaces_total + oldLength - string.length();
885
886 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800887 if (spaces < 0) {
888 spaces = 0;
889 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800890 string.appendFormat("%*s=", spaces, "");
891 spaces = -1;
892 } else if (els) {
893 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800894 if (spaces < 0) {
895 spaces = 0;
896 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800897 string.appendFormat("%*s%zu/%zu", spaces, "",
898 pp->sizes(), els);
899 spaces -= string.length() - oldLength;
900 }
901 spaces += spaces_current;
902
903 first = !first;
904 }
905
906 if (gone_els) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800907 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800908 string.appendFormat("%*s", spaces, "");
909 }
910
911 intermediate = string.format("%d/?", u);
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700912 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800913 intermediate.string());
914 intermediate.clear();
915
916 spaces = spaces_total + spaces_current;
917
918 oldLength = string.length();
919 string.appendFormat("%zu/%zu", gone_szs, gone_els);
920 spaces -= string.length() - oldLength;
921
922 first = !first;
923 }
924 }
925 }
926
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800927 *buf = strdup(string.string());
Mark Salyzyn34facab2014-02-06 14:48:50 -0800928}
Mark Salyzyn4ba03872014-04-07 07:15:33 -0700929
930uid_t LogStatistics::pidToUid(pid_t pid) {
931 log_id_for_each(i) {
932 LidStatistics &l = id(i);
933 UidStatisticsCollection::iterator iu;
934 for (iu = l.begin(); iu != l.end(); ++iu) {
935 UidStatistics &u = *(*iu);
936 PidStatisticsCollection::iterator ip;
937 for (ip = u.begin(); ip != u.end(); ++ip) {
938 if ((*ip)->getPid() == pid) {
939 return u.getUid();
940 }
941 }
942 }
943 }
944 return getuid(); // associate this with the logger
945}