| /* |
| * Copyright (C) 2014 The Android Open Source Project |
| * |
| * Licensed under the Apache License, Version 2.0 (the "License"); |
| * you may not use this file except in compliance with the License. |
| * You may obtain a copy of the License at |
| * |
| * http://www.apache.org/licenses/LICENSE-2.0 |
| * |
| * Unless required by applicable law or agreed to in writing, software |
| * distributed under the License is distributed on an "AS IS" BASIS, |
| * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| * See the License for the specific language governing permissions and |
| * limitations under the License. |
| */ |
| |
| #include <stdarg.h> |
| #include <time.h> |
| |
| #include <log/logger.h> |
| #include <private/android_filesystem_config.h> |
| #include <utils/String8.h> |
| |
| #include "LogStatistics.h" |
| |
| PidStatistics::PidStatistics(pid_t pid) |
| : pid(pid) |
| , mSizesTotal(0) |
| , mElementsTotal(0) |
| , mSizes(0) |
| , mElements(0) { } |
| |
| void PidStatistics::add(unsigned short size) { |
| mSizesTotal += size; |
| ++mElementsTotal; |
| mSizes += size; |
| ++mElements; |
| } |
| |
| bool PidStatistics::subtract(unsigned short size) { |
| mSizes -= size; |
| --mElements; |
| return mElements == 0 && kill(pid, 0); |
| } |
| |
| void PidStatistics::addTotal(size_t size, size_t element) { |
| if (pid == gone) { |
| mSizesTotal += size; |
| mElementsTotal += element; |
| } |
| } |
| |
| UidStatistics::UidStatistics(uid_t uid) |
| : uid(uid) { |
| Pids.clear(); |
| } |
| |
| UidStatistics::~UidStatistics() { |
| PidStatisticsCollection::iterator it; |
| for (it = begin(); it != end();) { |
| delete (*it); |
| it = Pids.erase(it); |
| } |
| } |
| |
| void UidStatistics::add(unsigned short size, pid_t pid) { |
| PidStatistics *p; |
| PidStatisticsCollection::iterator last; |
| PidStatisticsCollection::iterator it; |
| for (last = it = begin(); it != end(); last = it, ++it) { |
| p = *it; |
| if (pid == p->getPid()) { |
| p->add(size); |
| // poor-man sort, bubble upwards if bigger than last |
| if ((last != it) && ((*last)->sizesTotal() < p->sizesTotal())) { |
| Pids.erase(it); |
| Pids.insert(last, p); |
| } |
| return; |
| } |
| } |
| // poor-man sort, insert if bigger than last or last is the gone entry. |
| bool insert = (last != it) |
| && ((p->getPid() == p->gone) |
| || ((*last)->sizesTotal() < (size_t) size)); |
| p = new PidStatistics(pid); |
| if (insert) { |
| Pids.insert(last, p); |
| } else { |
| Pids.push_back(p); |
| } |
| p->add(size); |
| } |
| |
| void UidStatistics::subtract(unsigned short size, pid_t pid) { |
| PidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| PidStatistics *p = *it; |
| if (pid == p->getPid()) { |
| if (p->subtract(size)) { |
| size_t szsTotal = p->sizesTotal(); |
| size_t elsTotal = p->elementsTotal(); |
| delete p; |
| Pids.erase(it); |
| it = end(); |
| --it; |
| if (it == end()) { |
| p = new PidStatistics(p->gone); |
| Pids.push_back(p); |
| } else { |
| p = *it; |
| if (p->getPid() != p->gone) { |
| p = new PidStatistics(p->gone); |
| Pids.push_back(p); |
| } |
| } |
| p->addTotal(szsTotal, elsTotal); |
| } |
| return; |
| } |
| } |
| } |
| |
| size_t UidStatistics::sizes(pid_t pid) { |
| size_t sizes = 0; |
| PidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| PidStatistics *p = *it; |
| if ((pid == pid_all) || (pid == p->getPid())) { |
| sizes += p->sizes(); |
| } |
| } |
| return sizes; |
| } |
| |
| size_t UidStatistics::elements(pid_t pid) { |
| size_t elements = 0; |
| PidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| PidStatistics *p = *it; |
| if ((pid == pid_all) || (pid == p->getPid())) { |
| elements += p->elements(); |
| } |
| } |
| return elements; |
| } |
| |
| size_t UidStatistics::sizesTotal(pid_t pid) { |
| size_t sizes = 0; |
| PidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| PidStatistics *p = *it; |
| if ((pid == pid_all) || (pid == p->getPid())) { |
| sizes += p->sizesTotal(); |
| } |
| } |
| return sizes; |
| } |
| |
| size_t UidStatistics::elementsTotal(pid_t pid) { |
| size_t elements = 0; |
| PidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| PidStatistics *p = *it; |
| if ((pid == pid_all) || (pid == p->getPid())) { |
| elements += p->elementsTotal(); |
| } |
| } |
| return elements; |
| } |
| |
| LidStatistics::LidStatistics() { |
| Uids.clear(); |
| } |
| |
| LidStatistics::~LidStatistics() { |
| UidStatisticsCollection::iterator it; |
| for (it = begin(); it != end();) { |
| delete (*it); |
| it = Uids.erase(it); |
| } |
| } |
| |
| void LidStatistics::add(unsigned short size, uid_t uid, pid_t pid) { |
| UidStatistics *u; |
| UidStatisticsCollection::iterator it; |
| UidStatisticsCollection::iterator last; |
| |
| if (uid == (uid_t) -1) { // init |
| uid = (uid_t) AID_ROOT; |
| } |
| |
| for (last = it = begin(); it != end(); last = it, ++it) { |
| u = *it; |
| if (uid == u->getUid()) { |
| u->add(size, pid); |
| if ((last != it) && ((*last)->sizesTotal() < u->sizesTotal())) { |
| Uids.erase(it); |
| Uids.insert(last, u); |
| } |
| return; |
| } |
| } |
| u = new UidStatistics(uid); |
| if ((last != it) && ((*last)->sizesTotal() < (size_t) size)) { |
| Uids.insert(last, u); |
| } else { |
| Uids.push_back(u); |
| } |
| u->add(size, pid); |
| } |
| |
| void LidStatistics::subtract(unsigned short size, uid_t uid, pid_t pid) { |
| UidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| UidStatistics *u = *it; |
| if (uid == u->getUid()) { |
| u->subtract(size, pid); |
| return; |
| } |
| } |
| } |
| |
| size_t LidStatistics::sizes(uid_t uid, pid_t pid) { |
| size_t sizes = 0; |
| UidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| UidStatistics *u = *it; |
| if ((uid == uid_all) || (uid == u->getUid())) { |
| sizes += u->sizes(pid); |
| } |
| } |
| return sizes; |
| } |
| |
| size_t LidStatistics::elements(uid_t uid, pid_t pid) { |
| size_t elements = 0; |
| UidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| UidStatistics *u = *it; |
| if ((uid == uid_all) || (uid == u->getUid())) { |
| elements += u->elements(pid); |
| } |
| } |
| return elements; |
| } |
| |
| size_t LidStatistics::sizesTotal(uid_t uid, pid_t pid) { |
| size_t sizes = 0; |
| UidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| UidStatistics *u = *it; |
| if ((uid == uid_all) || (uid == u->getUid())) { |
| sizes += u->sizesTotal(pid); |
| } |
| } |
| return sizes; |
| } |
| |
| size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) { |
| size_t elements = 0; |
| UidStatisticsCollection::iterator it; |
| for (it = begin(); it != end(); ++it) { |
| UidStatistics *u = *it; |
| if ((uid == uid_all) || (uid == u->getUid())) { |
| elements += u->elementsTotal(pid); |
| } |
| } |
| return elements; |
| } |
| |
| LogStatistics::LogStatistics() |
| : start(CLOCK_MONOTONIC) { |
| log_id_for_each(i) { |
| mSizes[i] = 0; |
| mElements[i] = 0; |
| } |
| |
| dgram_qlen_statistics = false; |
| for(unsigned short bucket = 0; dgram_qlen(bucket); ++bucket) { |
| mMinimum[bucket].tv_sec = (uint32_t)-1; |
| mMinimum[bucket].tv_nsec = 999999999UL; |
| } |
| } |
| |
| // Each bucket below represents a dgram_qlen of log messages. By |
| // finding the minimum period of time from start to finish |
| // of each dgram_qlen, we can get a performance expectation for |
| // the user space logger. The net result is that the period |
| // of time divided by the dgram_qlen will give us the average time |
| // between log messages; at the point where the average time |
| // is greater than the throughput capability of the logger |
| // we will not longer require the benefits of the FIFO formed |
| // by max_dgram_qlen. We will also expect to see a very visible |
| // knee in the average time between log messages at this point, |
| // so we do not necessarily have to compare the rate against the |
| // measured performance (BM_log_maximum_retry) of the logger. |
| // |
| // for example (reformatted): |
| // |
| // Minimum time between log events per dgram_qlen: |
| // 1 2 3 5 10 20 30 50 100 200 300 400 500 600 |
| // 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5 |
| // |
| // demonstrates a clear knee rising at 100, so this means that for this |
| // case max_dgram_qlen = 100 would be more than sufficient to handle the |
| // worst that the system could stuff into the logger. The |
| // BM_log_maximum_retry performance (derated by the log collection) on the |
| // same system was 33.2us so we would almost be fine with max_dgram_qlen = 50. |
| // BM_log_maxumum_retry with statistics off is roughly 20us, so |
| // max_dgram_qlen = 20 would work. We will be more than willing to have |
| // a large engineering margin so the rule of thumb that lead us to 100 is |
| // fine. |
| // |
| // bucket dgram_qlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300 |
| const unsigned short LogStatistics::mBuckets[] = { |
| 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600 |
| }; |
| |
| unsigned short LogStatistics::dgram_qlen(unsigned short bucket) { |
| if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) { |
| return 0; |
| } |
| return mBuckets[bucket]; |
| } |
| |
| unsigned long long LogStatistics::minimum(unsigned short bucket) { |
| if (mMinimum[bucket].tv_sec == LONG_MAX) { |
| return 0; |
| } |
| return mMinimum[bucket].nsec(); |
| } |
| |
| void LogStatistics::recordDiff(log_time diff, unsigned short bucket) { |
| if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) { |
| mMinimum[bucket] = diff; |
| } |
| } |
| |
| void LogStatistics::add(unsigned short size, |
| log_id_t log_id, uid_t uid, pid_t pid) { |
| mSizes[log_id] += size; |
| ++mElements[log_id]; |
| id(log_id).add(size, uid, pid); |
| } |
| |
| void LogStatistics::subtract(unsigned short size, |
| log_id_t log_id, uid_t uid, pid_t pid) { |
| mSizes[log_id] -= size; |
| --mElements[log_id]; |
| id(log_id).subtract(size, uid, pid); |
| } |
| |
| size_t LogStatistics::sizes(log_id_t log_id, uid_t uid, pid_t pid) { |
| if (log_id != log_id_all) { |
| return id(log_id).sizes(uid, pid); |
| } |
| size_t sizes = 0; |
| log_id_for_each(i) { |
| sizes += id(i).sizes(uid, pid); |
| } |
| return sizes; |
| } |
| |
| size_t LogStatistics::elements(log_id_t log_id, uid_t uid, pid_t pid) { |
| if (log_id != log_id_all) { |
| return id(log_id).elements(uid, pid); |
| } |
| size_t elements = 0; |
| log_id_for_each(i) { |
| elements += id(i).elements(uid, pid); |
| } |
| return elements; |
| } |
| |
| size_t LogStatistics::sizesTotal(log_id_t log_id, uid_t uid, pid_t pid) { |
| if (log_id != log_id_all) { |
| return id(log_id).sizesTotal(uid, pid); |
| } |
| size_t sizes = 0; |
| log_id_for_each(i) { |
| sizes += id(i).sizesTotal(uid, pid); |
| } |
| return sizes; |
| } |
| |
| size_t LogStatistics::elementsTotal(log_id_t log_id, uid_t uid, pid_t pid) { |
| if (log_id != log_id_all) { |
| return id(log_id).elementsTotal(uid, pid); |
| } |
| size_t elements = 0; |
| log_id_for_each(i) { |
| elements += id(i).elementsTotal(uid, pid); |
| } |
| return elements; |
| } |
| |
| void LogStatistics::format(char **buf, |
| uid_t uid, unsigned int logMask, log_time oldest) { |
| const unsigned short spaces_current = 13; |
| const unsigned short spaces_total = 19; |
| |
| if (*buf) { |
| free(buf); |
| *buf = NULL; |
| } |
| |
| android::String8 string(" span -> size/num"); |
| size_t oldLength; |
| short spaces = 2; |
| |
| log_id_for_each(i) { |
| if (logMask & (1 << i)) { |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s%s", spaces, "", android_log_id_to_name(i)); |
| spaces += spaces_total + oldLength - string.length(); |
| } |
| } |
| |
| spaces = 1; |
| log_time t(CLOCK_MONOTONIC); |
| unsigned long long d = t.nsec() - start.nsec(); |
| string.appendFormat("\nTotal%4llu:%02llu:%02llu.%09llu", |
| d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60, |
| (d / NS_PER_SEC) % 60, d % NS_PER_SEC); |
| |
| log_id_for_each(i) { |
| if (!(logMask & (1 << i))) { |
| continue; |
| } |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s%zu/%zu", spaces, "", |
| sizesTotal(i), elementsTotal(i)); |
| spaces += spaces_total + oldLength - string.length(); |
| } |
| |
| spaces = 1; |
| d = t.nsec() - oldest.nsec(); |
| string.appendFormat("\nNow%6llu:%02llu:%02llu.%09llu", |
| d / NS_PER_SEC / 60 / 60, (d / NS_PER_SEC / 60) % 60, |
| (d / NS_PER_SEC) % 60, d % NS_PER_SEC); |
| |
| log_id_for_each(i) { |
| if (!(logMask & (1 << i))) { |
| continue; |
| } |
| |
| size_t els = elements(i); |
| if (els) { |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s%zu/%zu", spaces, "", sizes(i), els); |
| spaces -= string.length() - oldLength; |
| } |
| spaces += spaces_total; |
| } |
| |
| if (dgram_qlen_statistics) { |
| const unsigned short spaces_time = 6; |
| const unsigned long long max_seconds = 100000; |
| spaces = 0; |
| string.append("\n\nMinimum time between log events per dgram_qlen:\n"); |
| for(unsigned short i = 0; dgram_qlen(i); ++i) { |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s%u", spaces, "", dgram_qlen(i)); |
| spaces += spaces_time + oldLength - string.length(); |
| } |
| string.append("\n"); |
| spaces = 0; |
| unsigned short n; |
| for(unsigned short i = 0; (n = dgram_qlen(i)); ++i) { |
| unsigned long long duration = minimum(i); |
| if (duration) { |
| duration /= n; |
| if (duration >= (NS_PER_SEC * max_seconds)) { |
| duration = NS_PER_SEC * (max_seconds - 1); |
| } |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s", spaces, ""); |
| if (duration >= (NS_PER_SEC * 10)) { |
| string.appendFormat("%llu", |
| (duration + (NS_PER_SEC / 2)) |
| / NS_PER_SEC); |
| } else if (duration >= (NS_PER_SEC / (1000 / 10))) { |
| string.appendFormat("%llum", |
| (duration + (NS_PER_SEC / 2 / 1000)) |
| / (NS_PER_SEC / 1000)); |
| } else if (duration >= (NS_PER_SEC / (1000000 / 10))) { |
| string.appendFormat("%lluu", |
| (duration + (NS_PER_SEC / 2 / 1000000)) |
| / (NS_PER_SEC / 1000000)); |
| } else { |
| string.appendFormat("%llun", duration); |
| } |
| spaces -= string.length() - oldLength; |
| } |
| spaces += spaces_time; |
| } |
| } |
| |
| log_id_for_each(i) { |
| if (!(logMask & (1 << i))) { |
| continue; |
| } |
| |
| bool header = false; |
| bool first = true; |
| |
| UidStatisticsCollection::iterator ut; |
| for(ut = id(i).begin(); ut != id(i).end(); ++ut) { |
| UidStatistics *up = *ut; |
| if ((uid != AID_ROOT) && (uid != up->getUid())) { |
| continue; |
| } |
| |
| PidStatisticsCollection::iterator pt = up->begin(); |
| if (pt == up->end()) { |
| continue; |
| } |
| |
| android::String8 intermediate; |
| |
| if (!header) { |
| // header below tuned to match spaces_total and spaces_current |
| spaces = 0; |
| intermediate = string.format("%s: UID/PID Total size/num", |
| android_log_id_to_name(i)); |
| string.appendFormat("\n\n%-31sNow " |
| "UID/PID[?] Total Now", |
| intermediate.string()); |
| intermediate.clear(); |
| header = true; |
| } |
| |
| bool oneline = ++pt == up->end(); |
| --pt; |
| |
| if (!oneline) { |
| first = true; |
| } else if (!first && (spaces > 0)) { |
| string.appendFormat("%*s", spaces, ""); |
| } |
| spaces = 0; |
| |
| uid_t u = up->getUid(); |
| pid_t p = (*pt)->getPid(); |
| |
| intermediate = string.format(oneline |
| ? ((p == PidStatistics::gone) |
| ? "%d/?" |
| : "%d/%d") |
| : "%d", |
| u, p); |
| string.appendFormat((first) ? "\n%-12s" : "%-12s", |
| intermediate.string()); |
| intermediate.clear(); |
| |
| size_t elsTotal = up->elementsTotal(); |
| oldLength = string.length(); |
| string.appendFormat("%zu/%zu", up->sizesTotal(), elsTotal); |
| spaces += spaces_total + oldLength - string.length(); |
| |
| size_t els = up->elements(); |
| if (els == elsTotal) { |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s=", spaces, ""); |
| spaces = -1; |
| } else if (els) { |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s%zu/%zu", spaces, "", up->sizes(), els); |
| spaces -= string.length() - oldLength; |
| } |
| spaces += spaces_current; |
| |
| first = !first; |
| |
| if (oneline) { |
| continue; |
| } |
| |
| size_t gone_szs = 0; |
| size_t gone_els = 0; |
| |
| for(; pt != up->end(); ++pt) { |
| PidStatistics *pp = *pt; |
| pid_t p = pp->getPid(); |
| |
| // If a PID no longer has any current logs, and is not |
| // active anymore, skip & report totals for gone. |
| elsTotal = pp->elementsTotal(); |
| size_t szsTotal = pp->sizesTotal(); |
| if (p == pp->gone) { |
| gone_szs += szsTotal; |
| gone_els += elsTotal; |
| continue; |
| } |
| els = pp->elements(); |
| bool gone = kill(p, 0); |
| if (gone && (els == 0)) { |
| // ToDo: garbage collection: move this statistical bucket |
| // from its current UID/PID to UID/? (races and |
| // wrap around are our achilles heel). Below is |
| // merely lipservice to catch PIDs that were still |
| // around when the stats were pruned to zero. |
| gone_szs += szsTotal; |
| gone_els += elsTotal; |
| continue; |
| } |
| |
| if (!first && (spaces > 0)) { |
| string.appendFormat("%*s", spaces, ""); |
| } |
| spaces = 0; |
| |
| intermediate = string.format((gone) ? "%d/%d?" : "%d/%d", u, p); |
| string.appendFormat((first) ? "\n%-12s" : "%-12s", |
| intermediate.string()); |
| intermediate.clear(); |
| |
| oldLength = string.length(); |
| string.appendFormat("%zu/%zu", szsTotal, elsTotal); |
| spaces += spaces_total + oldLength - string.length(); |
| |
| if (els == elsTotal) { |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s=", spaces, ""); |
| spaces = -1; |
| } else if (els) { |
| oldLength = string.length(); |
| if (spaces < 0) { |
| spaces = 0; |
| } |
| string.appendFormat("%*s%zu/%zu", spaces, "", |
| pp->sizes(), els); |
| spaces -= string.length() - oldLength; |
| } |
| spaces += spaces_current; |
| |
| first = !first; |
| } |
| |
| if (gone_els) { |
| if (!first && (spaces > 0)) { |
| string.appendFormat("%*s", spaces, ""); |
| } |
| |
| intermediate = string.format("%d/?", u); |
| string.appendFormat((first) ? "\n%-12s" : "%-12s", |
| intermediate.string()); |
| intermediate.clear(); |
| |
| spaces = spaces_total + spaces_current; |
| |
| oldLength = string.length(); |
| string.appendFormat("%zu/%zu", gone_szs, gone_els); |
| spaces -= string.length() - oldLength; |
| |
| first = !first; |
| } |
| } |
| } |
| |
| *buf = strdup(string.string()); |
| } |
