blob: 792044cbfd0916b1de776f07ebffbac61a093c04 [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 }
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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-09-21 14:22:18 -0700146 if (insert_before_last) {
147 insert(last, p);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800148 } else {
Mark Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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 Salyzyn987f1e02014-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) {
Mark Salyzyn1e1d71e2014-09-22 10:58:36 -0700305 if (uid == (uid_t) -1) { // init
306 uid = (uid_t) AID_ROOT;
307 }
308
Mark Salyzyn34facab2014-02-06 14:48:50 -0800309 UidStatisticsCollection::iterator it;
310 for (it = begin(); it != end(); ++it) {
311 UidStatistics *u = *it;
312 if (uid == u->getUid()) {
313 u->subtract(size, pid);
314 return;
315 }
316 }
317}
318
Mark Salyzync8a576c2014-04-04 16:35:59 -0700319void LidStatistics::sort() {
320 for (bool pass = true; pass;) {
321 pass = false;
322 UidStatisticsCollection::iterator it = begin();
323 if (it != end()) {
324 UidStatisticsCollection::iterator lt = it;
325 UidStatistics *l = (*lt);
326 while (++it != end()) {
327 UidStatistics *n = (*it);
328 if (n->sizes() > l->sizes()) {
329 pass = true;
330 Uids.erase(it);
331 Uids.insert(lt, n);
332 it = lt;
333 n = l;
334 }
335 lt = it;
336 l = n;
337 }
338 }
339 }
340}
341
Mark Salyzyn34facab2014-02-06 14:48:50 -0800342size_t LidStatistics::sizes(uid_t uid, pid_t pid) {
343 size_t sizes = 0;
344 UidStatisticsCollection::iterator it;
345 for (it = begin(); it != end(); ++it) {
346 UidStatistics *u = *it;
347 if ((uid == uid_all) || (uid == u->getUid())) {
348 sizes += u->sizes(pid);
349 }
350 }
351 return sizes;
352}
353
354size_t LidStatistics::elements(uid_t uid, pid_t pid) {
355 size_t elements = 0;
356 UidStatisticsCollection::iterator it;
357 for (it = begin(); it != end(); ++it) {
358 UidStatistics *u = *it;
359 if ((uid == uid_all) || (uid == u->getUid())) {
360 elements += u->elements(pid);
361 }
362 }
363 return elements;
364}
365
366size_t LidStatistics::sizesTotal(uid_t uid, pid_t pid) {
367 size_t sizes = 0;
368 UidStatisticsCollection::iterator it;
369 for (it = begin(); it != end(); ++it) {
370 UidStatistics *u = *it;
371 if ((uid == uid_all) || (uid == u->getUid())) {
372 sizes += u->sizesTotal(pid);
373 }
374 }
375 return sizes;
376}
377
378size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) {
379 size_t elements = 0;
380 UidStatisticsCollection::iterator it;
381 for (it = begin(); it != end(); ++it) {
382 UidStatistics *u = *it;
383 if ((uid == uid_all) || (uid == u->getUid())) {
384 elements += u->elementsTotal(pid);
385 }
386 }
387 return elements;
388}
389
390LogStatistics::LogStatistics()
Mark Salyzyna0e53542014-09-21 14:22:18 -0700391 : mStatistics(false)
392 , dgramQlenStatistics(false)
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700393 , start(CLOCK_MONOTONIC) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800394 log_id_for_each(i) {
395 mSizes[i] = 0;
396 mElements[i] = 0;
397 }
Mark Salyzyne457b742014-02-19 17:18:31 -0800398
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700399 for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700400 mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max;
401 mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max;
Mark Salyzyne457b742014-02-19 17:18:31 -0800402 }
403}
404
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700405// Each bucket below represents a dgramQlen of log messages. By
Mark Salyzyne457b742014-02-19 17:18:31 -0800406// finding the minimum period of time from start to finish
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700407// of each dgramQlen, we can get a performance expectation for
Mark Salyzyne457b742014-02-19 17:18:31 -0800408// the user space logger. The net result is that the period
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700409// of time divided by the dgramQlen will give us the average time
Mark Salyzyne457b742014-02-19 17:18:31 -0800410// between log messages; at the point where the average time
411// is greater than the throughput capability of the logger
412// we will not longer require the benefits of the FIFO formed
413// by max_dgram_qlen. We will also expect to see a very visible
414// knee in the average time between log messages at this point,
415// so we do not necessarily have to compare the rate against the
416// measured performance (BM_log_maximum_retry) of the logger.
417//
418// for example (reformatted):
419//
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700420// Minimum time between log events per dgramQlen:
Mark Salyzyne457b742014-02-19 17:18:31 -0800421// 1 2 3 5 10 20 30 50 100 200 300 400 500 600
422// 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5
423//
424// demonstrates a clear knee rising at 100, so this means that for this
425// case max_dgram_qlen = 100 would be more than sufficient to handle the
426// worst that the system could stuff into the logger. The
427// BM_log_maximum_retry performance (derated by the log collection) on the
428// same system was 33.2us so we would almost be fine with max_dgram_qlen = 50.
429// BM_log_maxumum_retry with statistics off is roughly 20us, so
430// max_dgram_qlen = 20 would work. We will be more than willing to have
431// a large engineering margin so the rule of thumb that lead us to 100 is
432// fine.
433//
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700434// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300
Mark Salyzyne457b742014-02-19 17:18:31 -0800435const unsigned short LogStatistics::mBuckets[] = {
436 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600
437};
438
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700439unsigned short LogStatistics::dgramQlen(unsigned short bucket) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800440 if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) {
441 return 0;
442 }
443 return mBuckets[bucket];
444}
445
446unsigned long long LogStatistics::minimum(unsigned short bucket) {
Mark Salyzyn3cb54982014-04-30 09:21:54 -0700447 if (mMinimum[bucket].tv_sec == mMinimum[bucket].tv_sec_max) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800448 return 0;
449 }
450 return mMinimum[bucket].nsec();
451}
452
453void LogStatistics::recordDiff(log_time diff, unsigned short bucket) {
454 if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) {
455 mMinimum[bucket] = diff;
456 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800457}
458
459void LogStatistics::add(unsigned short size,
460 log_id_t log_id, uid_t uid, pid_t pid) {
461 mSizes[log_id] += size;
462 ++mElements[log_id];
Mark Salyzyna0e53542014-09-21 14:22:18 -0700463 if (!mStatistics) {
464 return;
465 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800466 id(log_id).add(size, uid, pid);
467}
468
469void LogStatistics::subtract(unsigned short size,
470 log_id_t log_id, uid_t uid, pid_t pid) {
471 mSizes[log_id] -= size;
472 --mElements[log_id];
Mark Salyzyna0e53542014-09-21 14:22:18 -0700473 if (!mStatistics) {
474 return;
475 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800476 id(log_id).subtract(size, uid, pid);
477}
478
479size_t LogStatistics::sizes(log_id_t log_id, uid_t uid, pid_t pid) {
480 if (log_id != log_id_all) {
481 return id(log_id).sizes(uid, pid);
482 }
483 size_t sizes = 0;
484 log_id_for_each(i) {
485 sizes += id(i).sizes(uid, pid);
486 }
487 return sizes;
488}
489
490size_t LogStatistics::elements(log_id_t log_id, uid_t uid, pid_t pid) {
491 if (log_id != log_id_all) {
492 return id(log_id).elements(uid, pid);
493 }
494 size_t elements = 0;
495 log_id_for_each(i) {
496 elements += id(i).elements(uid, pid);
497 }
498 return elements;
499}
500
501size_t LogStatistics::sizesTotal(log_id_t log_id, uid_t uid, pid_t pid) {
502 if (log_id != log_id_all) {
503 return id(log_id).sizesTotal(uid, pid);
504 }
505 size_t sizes = 0;
506 log_id_for_each(i) {
507 sizes += id(i).sizesTotal(uid, pid);
508 }
509 return sizes;
510}
511
512size_t LogStatistics::elementsTotal(log_id_t log_id, uid_t uid, pid_t pid) {
513 if (log_id != log_id_all) {
514 return id(log_id).elementsTotal(uid, pid);
515 }
516 size_t elements = 0;
517 log_id_for_each(i) {
518 elements += id(i).elementsTotal(uid, pid);
519 }
520 return elements;
521}
522
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800523void LogStatistics::format(char **buf,
524 uid_t uid, unsigned int logMask, log_time oldest) {
Mark Salyzyn9a038632014-04-07 07:05:40 -0700525 static const unsigned short spaces_current = 13;
526 static const unsigned short spaces_total = 19;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800527
528 if (*buf) {
Greg Hackmann239605e2014-04-06 21:25:58 -0700529 free(*buf);
Mark Salyzyn34facab2014-02-06 14:48:50 -0800530 *buf = NULL;
531 }
532
533 android::String8 string(" span -> size/num");
534 size_t oldLength;
535 short spaces = 2;
536
537 log_id_for_each(i) {
Arseniy Antonov3c8e92c2014-09-03 17:29:20 +0400538 if (!(logMask & (1 << i))) {
Mark Salyzync8a576c2014-04-04 16:35:59 -0700539 continue;
540 }
541 oldLength = string.length();
542 if (spaces < 0) {
543 spaces = 0;
544 }
545 string.appendFormat("%*s%s", spaces, "", android_log_id_to_name(i));
546 spaces += spaces_total + oldLength - string.length();
547
548 LidStatistics &l = id(i);
549 l.sort();
550
551 UidStatisticsCollection::iterator iu;
552 for (iu = l.begin(); iu != l.end(); ++iu) {
553 (*iu)->sort();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800554 }
555 }
556
557 spaces = 1;
558 log_time t(CLOCK_MONOTONIC);
Mark Salyzyna0e53542014-09-21 14:22:18 -0700559 unsigned long long d;
560 if (mStatistics) {
561 d = t.nsec() - start.nsec();
562 string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800563 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
564 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
565
Mark Salyzyna0e53542014-09-21 14:22:18 -0700566 log_id_for_each(i) {
567 if (!(logMask & (1 << i))) {
568 continue;
569 }
570 oldLength = string.length();
571 if (spaces < 0) {
572 spaces = 0;
573 }
574 string.appendFormat("%*s%zu/%zu", spaces, "",
575 sizesTotal(i), elementsTotal(i));
576 spaces += spaces_total + oldLength - string.length();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800577 }
Mark Salyzyna0e53542014-09-21 14:22:18 -0700578 spaces = 1;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800579 }
580
Mark Salyzyn34facab2014-02-06 14:48:50 -0800581 d = t.nsec() - oldest.nsec();
582 string.appendFormat("\nNow%6llu:%02llu:%02llu.%09llu",
583 d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60,
584 (d / NS_PER_SEC) % 60, d % NS_PER_SEC);
585
586 log_id_for_each(i) {
587 if (!(logMask & (1 << i))) {
588 continue;
589 }
590
591 size_t els = elements(i);
592 if (els) {
593 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800594 if (spaces < 0) {
595 spaces = 0;
596 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800597 string.appendFormat("%*s%zu/%zu", spaces, "", sizes(i), els);
598 spaces -= string.length() - oldLength;
599 }
600 spaces += spaces_total;
601 }
602
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700603 // Construct list of worst spammers by Pid
604 static const unsigned char num_spammers = 10;
605 bool header = false;
606
607 log_id_for_each(i) {
608 if (!(logMask & (1 << i))) {
609 continue;
610 }
611
612 PidStatisticsCollection pids;
613 pids.clear();
614
615 LidStatistics &l = id(i);
616 UidStatisticsCollection::iterator iu;
617 for (iu = l.begin(); iu != l.end(); ++iu) {
618 UidStatistics &u = *(*iu);
619 PidStatisticsCollection::iterator ip;
620 for (ip = u.begin(); ip != u.end(); ++ip) {
621 PidStatistics *p = (*ip);
622 if (p->getPid() == p->gone) {
623 break;
624 }
625
626 size_t mySizes = p->sizes();
627
628 PidStatisticsCollection::iterator q;
629 unsigned char num = 0;
630 for (q = pids.begin(); q != pids.end(); ++q) {
631 if (mySizes > (*q)->sizes()) {
632 pids.insert(q, p);
633 break;
634 }
635 // do we need to traverse deeper in the list?
636 if (++num > num_spammers) {
637 break;
638 }
639 }
640 if (q == pids.end()) {
641 pids.push_back(p);
642 }
643 }
644 }
645
646 size_t threshold = sizes(i);
647 if (threshold < 65536) {
648 threshold = 65536;
649 }
650 threshold /= 100;
651
652 PidStatisticsCollection::iterator pt = pids.begin();
653
654 for(int line = 0;
655 (pt != pids.end()) && (line < num_spammers);
656 ++line, pt = pids.erase(pt)) {
657 PidStatistics *p = *pt;
658
659 size_t sizes = p->sizes();
660 if (sizes < threshold) {
661 break;
662 }
663
664 char *name = p->getName();
665 pid_t pid = p->getPid();
666 if (!name || !*name) {
667 name = pidToName(pid);
668 if (name) {
669 if (*name) {
670 p->setName(name);
671 } else {
672 free(name);
673 name = NULL;
674 }
675 }
676 }
677
678 if (!header) {
679 string.appendFormat("\n\nChattiest clients:\n"
680 "log id %-*s PID[?] name",
681 spaces_total, "size/total");
682 header = true;
683 }
684
685 size_t sizesTotal = p->sizesTotal();
686
687 android::String8 sz("");
688 sz.appendFormat((sizes != sizesTotal) ? "%zu/%zu" : "%zu",
689 sizes, sizesTotal);
690
691 android::String8 pd("");
Mark Salyzynfdabe722014-04-21 10:09:42 -0700692 pd.appendFormat("%u%c", pid, p->pidGone() ? '?' : ' ');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700693
694 string.appendFormat("\n%-7s%-*s %-7s%s",
695 line ? "" : android_log_id_to_name(i),
696 spaces_total, sz.string(), pd.string(),
697 name ? name : "");
698 }
699
700 pids.clear();
701 }
702
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700703 if (dgramQlenStatistics) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800704 const unsigned short spaces_time = 6;
705 const unsigned long long max_seconds = 100000;
706 spaces = 0;
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700707 string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
708 for(unsigned short i = 0; dgramQlen(i); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800709 oldLength = string.length();
710 if (spaces < 0) {
711 spaces = 0;
712 }
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700713 string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
Mark Salyzyne457b742014-02-19 17:18:31 -0800714 spaces += spaces_time + oldLength - string.length();
715 }
716 string.append("\n");
717 spaces = 0;
718 unsigned short n;
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700719 for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800720 unsigned long long duration = minimum(i);
721 if (duration) {
722 duration /= n;
723 if (duration >= (NS_PER_SEC * max_seconds)) {
724 duration = NS_PER_SEC * (max_seconds - 1);
725 }
726 oldLength = string.length();
727 if (spaces < 0) {
728 spaces = 0;
729 }
730 string.appendFormat("%*s", spaces, "");
731 if (duration >= (NS_PER_SEC * 10)) {
732 string.appendFormat("%llu",
733 (duration + (NS_PER_SEC / 2))
734 / NS_PER_SEC);
735 } else if (duration >= (NS_PER_SEC / (1000 / 10))) {
736 string.appendFormat("%llum",
737 (duration + (NS_PER_SEC / 2 / 1000))
738 / (NS_PER_SEC / 1000));
739 } else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
740 string.appendFormat("%lluu",
Mark Salyzyn987f1e02014-09-21 14:22:18 -0700741 (duration + (NS_PER_SEC / 2 / 1000000))
742 / (NS_PER_SEC / 1000000));
Mark Salyzyne457b742014-02-19 17:18:31 -0800743 } else {
744 string.appendFormat("%llun", duration);
745 }
746 spaces -= string.length() - oldLength;
747 }
748 spaces += spaces_time;
749 }
750 }
751
Mark Salyzyn34facab2014-02-06 14:48:50 -0800752 log_id_for_each(i) {
753 if (!(logMask & (1 << i))) {
754 continue;
755 }
756
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700757 header = false;
Mark Salyzyn34facab2014-02-06 14:48:50 -0800758 bool first = true;
759
760 UidStatisticsCollection::iterator ut;
761 for(ut = id(i).begin(); ut != id(i).end(); ++ut) {
762 UidStatistics *up = *ut;
763 if ((uid != AID_ROOT) && (uid != up->getUid())) {
764 continue;
765 }
766
767 PidStatisticsCollection::iterator pt = up->begin();
768 if (pt == up->end()) {
769 continue;
770 }
771
772 android::String8 intermediate;
773
774 if (!header) {
775 // header below tuned to match spaces_total and spaces_current
776 spaces = 0;
777 intermediate = string.format("%s: UID/PID Total size/num",
778 android_log_id_to_name(i));
779 string.appendFormat("\n\n%-31sNow "
780 "UID/PID[?] Total Now",
781 intermediate.string());
782 intermediate.clear();
783 header = true;
784 }
785
786 bool oneline = ++pt == up->end();
787 --pt;
788
789 if (!oneline) {
790 first = true;
Mark Salyzyne457b742014-02-19 17:18:31 -0800791 } else if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800792 string.appendFormat("%*s", spaces, "");
793 }
794 spaces = 0;
795
796 uid_t u = up->getUid();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700797 PidStatistics *pp = *pt;
798 pid_t p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800799
800 intermediate = string.format(oneline
801 ? ((p == PidStatistics::gone)
802 ? "%d/?"
Mark Salyzynfdabe722014-04-21 10:09:42 -0700803 : "%d/%d%c")
Mark Salyzyn34facab2014-02-06 14:48:50 -0800804 : "%d",
Mark Salyzynfdabe722014-04-21 10:09:42 -0700805 u, p, pp->pidGone() ? '?' : '\0');
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700806 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800807 intermediate.string());
808 intermediate.clear();
809
810 size_t elsTotal = up->elementsTotal();
811 oldLength = string.length();
812 string.appendFormat("%zu/%zu", up->sizesTotal(), elsTotal);
813 spaces += spaces_total + oldLength - string.length();
814
815 size_t els = up->elements();
816 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800817 if (spaces < 0) {
818 spaces = 0;
819 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800820 string.appendFormat("%*s=", spaces, "");
821 spaces = -1;
822 } else if (els) {
823 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800824 if (spaces < 0) {
825 spaces = 0;
826 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800827 string.appendFormat("%*s%zu/%zu", spaces, "", up->sizes(), els);
828 spaces -= string.length() - oldLength;
829 }
830 spaces += spaces_current;
831
832 first = !first;
833
834 if (oneline) {
835 continue;
836 }
837
838 size_t gone_szs = 0;
839 size_t gone_els = 0;
840
841 for(; pt != up->end(); ++pt) {
Mark Salyzynfdabe722014-04-21 10:09:42 -0700842 pp = *pt;
843 p = pp->getPid();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800844
845 // If a PID no longer has any current logs, and is not
846 // active anymore, skip & report totals for gone.
847 elsTotal = pp->elementsTotal();
848 size_t szsTotal = pp->sizesTotal();
849 if (p == pp->gone) {
850 gone_szs += szsTotal;
851 gone_els += elsTotal;
852 continue;
853 }
854 els = pp->elements();
Mark Salyzynfdabe722014-04-21 10:09:42 -0700855 bool gone = pp->pidGone();
Mark Salyzyn34facab2014-02-06 14:48:50 -0800856 if (gone && (els == 0)) {
857 // ToDo: garbage collection: move this statistical bucket
858 // from its current UID/PID to UID/? (races and
859 // wrap around are our achilles heel). Below is
860 // merely lipservice to catch PIDs that were still
861 // around when the stats were pruned to zero.
862 gone_szs += szsTotal;
863 gone_els += elsTotal;
864 continue;
865 }
866
Mark Salyzyne457b742014-02-19 17:18:31 -0800867 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800868 string.appendFormat("%*s", spaces, "");
869 }
870 spaces = 0;
871
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700872 intermediate = string.format(gone ? "%d/%d?" : "%d/%d", u, p);
873 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800874 intermediate.string());
875 intermediate.clear();
876
877 oldLength = string.length();
878 string.appendFormat("%zu/%zu", szsTotal, elsTotal);
879 spaces += spaces_total + oldLength - string.length();
880
881 if (els == elsTotal) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800882 if (spaces < 0) {
883 spaces = 0;
884 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800885 string.appendFormat("%*s=", spaces, "");
886 spaces = -1;
887 } else if (els) {
888 oldLength = string.length();
Mark Salyzyne457b742014-02-19 17:18:31 -0800889 if (spaces < 0) {
890 spaces = 0;
891 }
Mark Salyzyn34facab2014-02-06 14:48:50 -0800892 string.appendFormat("%*s%zu/%zu", spaces, "",
893 pp->sizes(), els);
894 spaces -= string.length() - oldLength;
895 }
896 spaces += spaces_current;
897
898 first = !first;
899 }
900
901 if (gone_els) {
Mark Salyzyne457b742014-02-19 17:18:31 -0800902 if (!first && (spaces > 0)) {
Mark Salyzyn34facab2014-02-06 14:48:50 -0800903 string.appendFormat("%*s", spaces, "");
904 }
905
906 intermediate = string.format("%d/?", u);
Mark Salyzyn8e72c532014-03-26 10:46:39 -0700907 string.appendFormat(first ? "\n%-12s" : "%-12s",
Mark Salyzyn34facab2014-02-06 14:48:50 -0800908 intermediate.string());
909 intermediate.clear();
910
911 spaces = spaces_total + spaces_current;
912
913 oldLength = string.length();
914 string.appendFormat("%zu/%zu", gone_szs, gone_els);
915 spaces -= string.length() - oldLength;
916
917 first = !first;
918 }
919 }
920 }
921
Mark Salyzyndfa7a072014-02-11 12:29:31 -0800922 *buf = strdup(string.string());
Mark Salyzyn34facab2014-02-06 14:48:50 -0800923}
Mark Salyzyn4ba03872014-04-07 07:15:33 -0700924
925uid_t LogStatistics::pidToUid(pid_t pid) {
926 log_id_for_each(i) {
927 LidStatistics &l = id(i);
928 UidStatisticsCollection::iterator iu;
929 for (iu = l.begin(); iu != l.end(); ++iu) {
930 UidStatistics &u = *(*iu);
931 PidStatisticsCollection::iterator ip;
932 for (ip = u.begin(); ip != u.end(); ++ip) {
933 if ((*ip)->getPid() == pid) {
934 return u.getUid();
935 }
936 }
937 }
938 }
939 return getuid(); // associate this with the logger
940}