/*
* Copyright (C) 2008 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 <utils/TimerProbe.h>
#if ENABLE_TIMER_PROBE
#ifdef LOG_TAG
#undef LOG_TAG
#endif
#define LOG_TAG "time"
namespace android {
Vector<TimerProbe::Bucket> TimerProbe::gBuckets;
TimerProbe* TimerProbe::gExecuteChain;
int TimerProbe::gIndent;
timespec TimerProbe::gRealBase;
TimerProbe::TimerProbe(const char tag[], int* slot) : mTag(tag)
{
mNext = gExecuteChain;
gExecuteChain = this;
mIndent = gIndent;
gIndent += 1;
if (mIndent > 0) {
if (*slot == 0) {
int count = gBuckets.add();
*slot = count;
Bucket& bucket = gBuckets.editItemAt(count);
memset(&bucket, 0, sizeof(Bucket));
bucket.mTag = tag;
bucket.mSlotPtr = slot;
bucket.mIndent = mIndent;
}
mBucket = *slot;
}
clock_gettime(CLOCK_REALTIME, &mRealStart);
if (gRealBase.tv_sec == 0)
gRealBase = mRealStart;
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &mPStart);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &mTStart);
}
void TimerProbe::end()
{
timespec realEnd, pEnd, tEnd;
clock_gettime(CLOCK_REALTIME, &realEnd);
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &pEnd);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tEnd);
print(realEnd, pEnd, tEnd);
mTag = NULL;
}
TimerProbe::~TimerProbe()
{
if (mTag != NULL)
end();
gExecuteChain = mNext;
gIndent--;
}
uint32_t TimerProbe::ElapsedTime(const timespec& start, const timespec& end)
{
int sec = end.tv_sec - start.tv_sec;
int nsec = end.tv_nsec - start.tv_nsec;
if (nsec < 0) {
sec--;
nsec += 1000000000;
}
return sec * 1000000 + nsec / 1000;
}
void TimerProbe::print(const timespec& r, const timespec& p,
const timespec& t) const
{
uint32_t es = ElapsedTime(gRealBase, mRealStart);
uint32_t er = ElapsedTime(mRealStart, r);
uint32_t ep = ElapsedTime(mPStart, p);
uint32_t et = ElapsedTime(mTStart, t);
if (mIndent > 0) {
Bucket& bucket = gBuckets.editItemAt(mBucket);
if (bucket.mStart == 0)
bucket.mStart = es;
bucket.mReal += er;
bucket.mProcess += ep;
bucket.mThread += et;
bucket.mCount++;
return;
}
int index = 0;
int buckets = gBuckets.size();
int count = 1;
const char* tag = mTag;
int indent = mIndent;
do {
LOGD("%-30.30s: (%3d) %-5.*s time=%-10.3f real=%7dus process=%7dus (%3d%%) thread=%7dus (%3d%%)\n",
tag, count, indent > 5 ? 5 : indent, "+++++", es / 1000000.0,
er, ep, ep * 100 / er, et, et * 100 / er);
if (index >= buckets)
break;
Bucket& bucket = gBuckets.editItemAt(index);
count = bucket.mCount;
es = bucket.mStart;
er = bucket.mReal;
ep = bucket.mProcess;
et = bucket.mThread;
tag = bucket.mTag;
indent = bucket.mIndent;
*bucket.mSlotPtr = 0;
} while (++index); // always true
gBuckets.clear();
}
}; // namespace android
#endif