blob: 6f3a088693380eb2cd14f0cd2e856f91ee49cbca [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) {
Mark Salyzynf48ea7c2014-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 Salyzynf5fc5092014-09-21 14:22:18 -0700396 : mStatistics(false)
397 , dgramQlenStatistics(false)
Mark Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzyne72c6e42014-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 Salyzynf5fc5092014-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 Salyzynf5fc5092014-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 Antonovc3ce2242014-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 Salyzynf5fc5092014-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 Salyzynf5fc5092014-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 Salyzynf5fc5092014-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("");
Chih-Hung Hsieh634118e2014-09-12 16:02:28 -0700693 if (sizes == sizesTotal) {
694 sz.appendFormat("%zu", sizes);
695 } else {
696 sz.appendFormat("%zu/%zu", sizes, sizesTotal);
697 }
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700698
699 android::String8 pd("");
Mark Salyzynfdabe722014-04-21 10:09:42 -0700700 pd.appendFormat("%u%c", pid, p->pidGone() ? '?' : ' ');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700701
702 string.appendFormat("\n%-7s%-*s %-7s%s",
703 line ? "" : android_log_id_to_name(i),
704 spaces_total, sz.string(), pd.string(),
705 name ? name : "");
706 }
707
708 pids.clear();
709 }
710
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700711 if (dgramQlenStatistics) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800712 const unsigned short spaces_time = 6;
713 const unsigned long long max_seconds = 100000;
714 spaces = 0;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700715 string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
716 for(unsigned short i = 0; dgramQlen(i); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800717 oldLength = string.length();
718 if (spaces < 0) {
719 spaces = 0;
720 }
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700721 string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
Mark Salyzyne457b742014-02-19 17:18:31 -0800722 spaces += spaces_time + oldLength - string.length();
723 }
724 string.append("\n");
725 spaces = 0;
726 unsigned short n;
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700727 for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800728 unsigned long long duration = minimum(i);
729 if (duration) {
730 duration /= n;
731 if (duration >= (NS_PER_SEC * max_seconds)) {
732 duration = NS_PER_SEC * (max_seconds - 1);
733 }
734 oldLength = string.length();
735 if (spaces < 0) {
736 spaces = 0;
737 }
738 string.appendFormat("%*s", spaces, "");
739 if (duration >= (NS_PER_SEC * 10)) {
740 string.appendFormat("%llu",
741 (duration + (NS_PER_SEC / 2))
742 / NS_PER_SEC);
743 } else if (duration >= (NS_PER_SEC / (1000 / 10))) {
744 string.appendFormat("%llum",
745 (duration + (NS_PER_SEC / 2 / 1000))
746 / (NS_PER_SEC / 1000));
747 } else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
748 string.appendFormat("%lluu",
Mark Salyzyne72c6e42014-09-21 14:22:18 -0700749 (duration + (NS_PER_SEC / 2 / 1000000))
750 / (NS_PER_SEC / 1000000));
Mark Salyzyne457b742014-02-19 17:18:31 -0800751 } else {
752 string.appendFormat("%llun", duration);
753 }
754 spaces -= string.length() - oldLength;
755 }
756 spaces += spaces_time;
757 }
758 }
759
Mark Salyzyn34facab2014-02-06 14:48:50 -0800760 log_id_for_each(i) {
761 if (!(logMask & (1 << i))) {
762 continue;
763 }
764
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700765 header = false;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800766 bool first = true;
767
768 UidStatisticsCollection::iterator ut;
769 for(ut = id(i).begin(); ut != id(i).end(); ++ut) {
770 UidStatistics *up = *ut;
771 if ((uid != AID_ROOT) && (uid != up->getUid())) {
772 continue;
773 }
774
775 PidStatisticsCollection::iterator pt = up->begin();
776 if (pt == up->end()) {
777 continue;
778 }
779
780 android::String8 intermediate;
781
782 if (!header) {
783 // header below tuned to match spaces_total and spaces_current
784 spaces = 0;
785 intermediate = string.format("%s: UID/PID Total size/num",
786 android_log_id_to_name(i));
787 string.appendFormat("\n\n%-31sNow "
788 "UID/PID[?] Total Now",
789 intermediate.string());
790 intermediate.clear();
791 header = true;
792 }
793
794 bool oneline = ++pt == up->end();
795 --pt;
796
797 if (!oneline) {
798 first = true;
Mark Salyzyne457b742014-02-19 17:18:31 -0800799 } else if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800800 string.appendFormat("%*s", spaces, "");
801 }
802 spaces = 0;
803
804 uid_t u = up->getUid();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700805 PidStatistics *pp = *pt;
806 pid_t p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800807
Chih-Hung Hsieh634118e2014-09-12 16:02:28 -0700808 if (!oneline) {
809 intermediate = string.format("%d", u);
810 } else if (p == PidStatistics::gone) {
811 intermediate = string.format("%d/?", u);
812 } else if (pp->pidGone()) {
813 intermediate = string.format("%d/%d?", u, p);
814 } else {
815 intermediate = string.format("%d/%d", u, p);
816 }
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700817 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800818 intermediate.string());
819 intermediate.clear();
820
821 size_t elsTotal = up->elementsTotal();
822 oldLength = string.length();
823 string.appendFormat("%zu/%zu", up->sizesTotal(), elsTotal);
824 spaces += spaces_total + oldLength - string.length();
825
826 size_t els = up->elements();
827 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800828 if (spaces < 0) {
829 spaces = 0;
830 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800831 string.appendFormat("%*s=", spaces, "");
832 spaces = -1;
833 } else if (els) {
834 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800835 if (spaces < 0) {
836 spaces = 0;
837 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800838 string.appendFormat("%*s%zu/%zu", spaces, "", up->sizes(), els);
839 spaces -= string.length() - oldLength;
840 }
841 spaces += spaces_current;
842
843 first = !first;
844
845 if (oneline) {
846 continue;
847 }
848
849 size_t gone_szs = 0;
850 size_t gone_els = 0;
851
852 for(; pt != up->end(); ++pt) {
Mark Salyzynfdabe722014-04-21 10:09:42 -0700853 pp = *pt;
854 p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800855
856 // If a PID no longer has any current logs, and is not
857 // active anymore, skip & report totals for gone.
858 elsTotal = pp->elementsTotal();
859 size_t szsTotal = pp->sizesTotal();
860 if (p == pp->gone) {
861 gone_szs += szsTotal;
862 gone_els += elsTotal;
863 continue;
864 }
865 els = pp->elements();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700866 bool gone = pp->pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800867 if (gone && (els == 0)) {
868 // ToDo: garbage collection: move this statistical bucket
869 // from its current UID/PID to UID/? (races and
870 // wrap around are our achilles heel). Below is
871 // merely lipservice to catch PIDs that were still
872 // around when the stats were pruned to zero.
873 gone_szs += szsTotal;
874 gone_els += elsTotal;
875 continue;
876 }
877
Mark Salyzyne457b742014-02-19 17:18:31 -0800878 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800879 string.appendFormat("%*s", spaces, "");
880 }
881 spaces = 0;
882
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700883 intermediate = string.format(gone ? "%d/%d?" : "%d/%d", u, p);
884 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800885 intermediate.string());
886 intermediate.clear();
887
888 oldLength = string.length();
889 string.appendFormat("%zu/%zu", szsTotal, elsTotal);
890 spaces += spaces_total + oldLength - string.length();
891
892 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800893 if (spaces < 0) {
894 spaces = 0;
895 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800896 string.appendFormat("%*s=", spaces, "");
897 spaces = -1;
898 } else if (els) {
899 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800900 if (spaces < 0) {
901 spaces = 0;
902 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800903 string.appendFormat("%*s%zu/%zu", spaces, "",
904 pp->sizes(), els);
905 spaces -= string.length() - oldLength;
906 }
907 spaces += spaces_current;
908
909 first = !first;
910 }
911
912 if (gone_els) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800913 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800914 string.appendFormat("%*s", spaces, "");
915 }
916
917 intermediate = string.format("%d/?", u);
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700918 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800919 intermediate.string());
920 intermediate.clear();
921
922 spaces = spaces_total + spaces_current;
923
924 oldLength = string.length();
925 string.appendFormat("%zu/%zu", gone_szs, gone_els);
926 spaces -= string.length() - oldLength;
927
928 first = !first;
929 }
930 }
931 }
932
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800933 *buf = strdup(string.string());
Mark Salyzyn34facab2014-02-06 14:48:50 -0800934}
Mark Salyzyn4ba03872014-04-07 07:15:33 -0700935
936uid_t LogStatistics::pidToUid(pid_t pid) {
937 log_id_for_each(i) {
938 LidStatistics &l = id(i);
939 UidStatisticsCollection::iterator iu;
940 for (iu = l.begin(); iu != l.end(); ++iu) {
941 UidStatistics &u = *(*iu);
942 PidStatisticsCollection::iterator ip;
943 for (ip = u.begin(); ip != u.end(); ++ip) {
944 if ((*ip)->getPid() == pid) {
945 return u.getUid();
946 }
947 }
948 }
949 }
950 return getuid(); // associate this with the logger
951}