1/*
2 * Copyright 2009, The Android Open Source Project
3 *
4 * Redistribution and use in source and binary forms, with or without
5 * modification, are permitted provided that the following conditions
6 * are met:
7 *  * Redistributions of source code must retain the above copyright
8 *    notice, this list of conditions and the following disclaimer.
9 *  * Redistributions in binary form must reproduce the above copyright
10 *    notice, this list of conditions and the following disclaimer in the
11 *    documentation and/or other materials provided with the distribution.
12 *
13 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS ``AS IS'' AND ANY
14 * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
15 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
16 * PURPOSE ARE DISCLAIMED.  IN NO EVENT SHALL THE COPYRIGHT OWNER OR
17 * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
18 * EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
19 * PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
20 * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY
21 * OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
22 * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
23 * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
24 */
25
26#define LOG_TAG "WebCore"
27
28#include "config.h"
29#include "TimeCounter.h"
30
31#include "CString.h"
32#include "Cache.h"
33#include "KURL.h"
34#include "Node.h"
35#include "SystemTime.h"
36#include "StyleBase.h"
37#include <utils/Log.h>
38#include <wtf/CurrentTime.h>
39
40#include <sys/time.h>
41#include <time.h>
42
43#if USE(JSC)
44#include "JSDOMWindow.h"
45#include <runtime/JSGlobalObject.h>
46#include <runtime/JSLock.h>
47#endif
48
49using namespace WebCore;
50using namespace WTF;
51using namespace JSC;
52
53namespace android {
54
55uint32_t getThreadMsec()
56{
57#if defined(HAVE_POSIX_CLOCKS)
58    struct timespec tm;
59
60    clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tm);
61    return tm.tv_sec * 1000LL + tm.tv_nsec / 1000000;
62#else
63    struct timeval now;
64    struct timezone zone;
65
66    gettimeofday(&now, &zone);
67    return now.tv_sec * 1000LL + now.tv_usec / 1000;
68#endif
69}
70
71#ifdef ANDROID_INSTRUMENT
72
73static double sStartTotalTime;
74static uint32_t sStartThreadTime;
75static double sLastTotalTime;
76static uint32_t sLastThreadTime;
77
78uint32_t TimeCounter::sStartWebCoreThreadTime;
79uint32_t TimeCounter::sEndWebCoreThreadTime;
80bool TimeCounter::sRecordWebCoreTime;
81uint32_t TimeCounter::sTotalTimeUsed[TimeCounter::TotalTimeCounterCount];
82uint32_t TimeCounter::sLastTimeUsed[TimeCounter::TotalTimeCounterCount];
83uint32_t TimeCounter::sCounter[TimeCounter::TotalTimeCounterCount];
84uint32_t TimeCounter::sLastCounter[TimeCounter::TotalTimeCounterCount];
85uint32_t TimeCounter::sStartTime[TimeCounter::TotalTimeCounterCount];
86
87int QemuTracerAuto::reentry_count = 0;
88
89static const char* timeCounterNames[] = {
90    "css parsing",
91    "javascript",
92    "javascript init",
93    "javascript parsing",
94    "javascript execution",
95    "calculate style",
96    "Java callback (frame bridge)",
97    "parsing (may include calcStyle or Java callback)",
98    "layout",
99    "native 1 (frame bridge)",
100    "native 2 (resource load)",
101    "native 3 (shared timer)",
102    "build nav (webview core)",
103    "record content (webview core)",
104    "native 4 (webview core)",
105    "draw content (webview ui)",
106};
107
108void TimeCounter::record(enum Type type, const char* functionName)
109{
110    recordNoCounter(type, functionName);
111    sCounter[type]++;
112}
113
114void TimeCounter::recordNoCounter(enum Type type, const char* functionName)
115{
116    uint32_t time = sEndWebCoreThreadTime = getThreadMsec();
117    uint32_t elapsed = time - sStartTime[type];
118    sTotalTimeUsed[type] += elapsed;
119    if (elapsed > 1000)
120        LOGW("***** %s() used %d ms\n", functionName, elapsed);
121}
122
123void TimeCounter::report(const KURL& url, int live, int dead, size_t arenaSize)
124{
125    String urlString = url;
126    int totalTime = static_cast<int>((currentTime() - sStartTotalTime) * 1000);
127    int threadTime = getThreadMsec() - sStartThreadTime;
128    LOGD("*-* Total load time: %d ms, thread time: %d ms for %s\n",
129        totalTime, threadTime, urlString.utf8().data());
130    for (Type type = (Type) 0; type < TotalTimeCounterCount; type
131            = (Type) (type + 1)) {
132        char scratch[256];
133        int index = sprintf(scratch, "*-* Total %s time: %d ms",
134            timeCounterNames[type], sTotalTimeUsed[type]);
135        if (sCounter[type] > 0)
136            sprintf(&scratch[index], " called %d times", sCounter[type]);
137        LOGD("%s", scratch);
138    }
139    LOGD("Current cache has %d bytes live and %d bytes dead", live, dead);
140    LOGD("Current render arena takes %d bytes", arenaSize);
141#if USE(JSC)
142    JSLock lock(false);
143    Heap::Statistics jsHeapStatistics = JSDOMWindow::commonJSGlobalData()->heap.statistics();
144    LOGD("Current JavaScript heap size is %d and has %d bytes free",
145            jsHeapStatistics.size, jsHeapStatistics.free);
146#endif
147    LOGD("Current CSS styles use %d bytes", StyleBase::reportStyleSize());
148    LOGD("Current DOM nodes use %d bytes", WebCore::Node::reportDOMNodesSize());
149}
150
151void TimeCounter::reportNow()
152{
153    double current = currentTime();
154    uint32_t currentThread = getThreadMsec();
155    int elapsedTime = static_cast<int>((current - sLastTotalTime) * 1000);
156    int elapsedThreadTime = currentThread - sLastThreadTime;
157    LOGD("*-* Elapsed time: %d ms, ui thread time: %d ms, webcore thread time:"
158        " %d ms\n", elapsedTime, elapsedThreadTime, sEndWebCoreThreadTime -
159        sStartWebCoreThreadTime);
160    for (Type type = (Type) 0; type < TotalTimeCounterCount; type
161            = (Type) (type + 1)) {
162        if (sTotalTimeUsed[type] == sLastTimeUsed[type])
163            continue;
164        char scratch[256];
165        int index = sprintf(scratch, "*-* Diff %s time: %d ms",
166            timeCounterNames[type], sTotalTimeUsed[type] - sLastTimeUsed[type]);
167        if (sCounter[type] > sLastCounter[type])
168            sprintf(&scratch[index], " called %d times", sCounter[type]
169                - sLastCounter[type]);
170        LOGD("%s", scratch);
171    }
172    memcpy(sLastTimeUsed, sTotalTimeUsed, sizeof(sTotalTimeUsed));
173    memcpy(sLastCounter, sCounter, sizeof(sCounter));
174    sLastTotalTime = current;
175    sLastThreadTime = currentThread;
176    sRecordWebCoreTime = true;
177}
178
179void TimeCounter::reset() {
180    bzero(sTotalTimeUsed, sizeof(sTotalTimeUsed));
181    bzero(sCounter, sizeof(sCounter));
182    LOGD("*-* Start browser instrument\n");
183    sStartTotalTime = currentTime();
184    sStartThreadTime = getThreadMsec();
185}
186
187void TimeCounter::start(enum Type type)
188{
189    uint32_t time = getThreadMsec();
190    if (sRecordWebCoreTime) {
191        sStartWebCoreThreadTime = time;
192        sRecordWebCoreTime = false;
193    }
194    sStartTime[type] = time;
195}
196
197#endif  // ANDROID_INSTRUMENT
198
199}
200