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 "MemoryCache.h"
32#include "KURL.h"
33#include "Node.h"
34#include "SystemTime.h"
35#include "StyleBase.h"
36#include <sys/time.h>
37#include <time.h>
38#include <utils/Log.h>
39#include <wtf/CurrentTime.h>
40#include <wtf/text/CString.h>
41
42#if USE(JSC)
43#include "JSDOMWindow.h"
44#include <runtime/JSGlobalObject.h>
45#include <runtime/JSLock.h>
46#endif
47
48using namespace WebCore;
49using namespace WTF;
50using namespace JSC;
51
52namespace android {
53
54uint32_t getThreadMsec()
55{
56#if defined(HAVE_POSIX_CLOCKS)
57    struct timespec tm;
58
59    clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tm);
60    return tm.tv_sec * 1000LL + tm.tv_nsec / 1000000;
61#else
62    struct timeval now;
63    struct timezone zone;
64
65    gettimeofday(&now, &zone);
66    return now.tv_sec * 1000LL + now.tv_usec / 1000;
67#endif
68}
69
70#ifdef ANDROID_INSTRUMENT
71
72static double sStartTotalTime;
73static uint32_t sStartThreadTime;
74static double sLastTotalTime;
75static uint32_t sLastThreadTime;
76
77uint32_t TimeCounter::sStartWebCoreThreadTime;
78uint32_t TimeCounter::sEndWebCoreThreadTime;
79bool TimeCounter::sRecordWebCoreTime;
80uint32_t TimeCounter::sTotalTimeUsed[TimeCounter::TotalTimeCounterCount];
81uint32_t TimeCounter::sLastTimeUsed[TimeCounter::TotalTimeCounterCount];
82uint32_t TimeCounter::sCounter[TimeCounter::TotalTimeCounterCount];
83uint32_t TimeCounter::sLastCounter[TimeCounter::TotalTimeCounterCount];
84uint32_t TimeCounter::sStartTime[TimeCounter::TotalTimeCounterCount];
85
86int QemuTracerAuto::reentry_count = 0;
87
88static const char* timeCounterNames[] = {
89    "css parsing",
90    "javascript",
91    "javascript init",
92    "javascript parsing",
93    "javascript execution",
94    "calculate style",
95    "Java callback (frame bridge)",
96    "parsing (may include calcStyle, Java callback or inline script execution)",
97    "layout",
98    "native 1 (frame bridge)",
99    "native 2 (resource load)",
100    "native 3 (shared timer)",
101    "build nav (webview core)",
102    "record content (webview core)",
103    "native 4 (webview core)",
104    "draw content (webview ui)",
105};
106
107void TimeCounter::record(enum Type type, const char* functionName)
108{
109    recordNoCounter(type, functionName);
110    sCounter[type]++;
111}
112
113void TimeCounter::recordNoCounter(enum Type type, const char* functionName)
114{
115    uint32_t time = sEndWebCoreThreadTime = getThreadMsec();
116    uint32_t elapsed = time - sStartTime[type];
117    sTotalTimeUsed[type] += elapsed;
118    if (elapsed > 1000)
119        LOGW("***** %s() used %d ms\n", functionName, elapsed);
120}
121
122void TimeCounter::report(const KURL& url, int live, int dead, size_t arenaSize)
123{
124    String urlString = url;
125    int totalTime = static_cast<int>((currentTime() - sStartTotalTime) * 1000);
126    int threadTime = getThreadMsec() - sStartThreadTime;
127    LOGD("*-* Total load time: %d ms, thread time: %d ms for %s\n",
128        totalTime, threadTime, urlString.utf8().data());
129    for (Type type = (Type) 0; type < TotalTimeCounterCount; type
130            = (Type) (type + 1)) {
131        char scratch[256];
132        int index = sprintf(scratch, "*-* Total %s time: %d ms",
133            timeCounterNames[type], sTotalTimeUsed[type]);
134        if (sCounter[type] > 0)
135            sprintf(&scratch[index], " called %d times", sCounter[type]);
136        LOGD("%s", scratch);
137    }
138    LOGD("Current cache has %d bytes live and %d bytes dead", live, dead);
139    LOGD("Current render arena takes %d bytes", arenaSize);
140#if USE(JSC)
141    JSLock lock(false);
142    Heap::Statistics jsHeapStatistics = JSDOMWindow::commonJSGlobalData()->heap.statistics();
143    LOGD("Current JavaScript heap size is %d and has %d bytes free",
144            jsHeapStatistics.size, jsHeapStatistics.free);
145#endif
146    LOGD("Current CSS styles use %d bytes", StyleBase::reportStyleSize());
147    LOGD("Current DOM nodes use %d bytes", WebCore::Node::reportDOMNodesSize());
148}
149
150void TimeCounter::reportNow()
151{
152    double current = currentTime();
153    uint32_t currentThread = getThreadMsec();
154    int elapsedTime = static_cast<int>((current - sLastTotalTime) * 1000);
155    int elapsedThreadTime = currentThread - sLastThreadTime;
156    LOGD("*-* Elapsed time: %d ms, ui thread time: %d ms, webcore thread time:"
157        " %d ms\n", elapsedTime, elapsedThreadTime, sEndWebCoreThreadTime -
158        sStartWebCoreThreadTime);
159    for (Type type = (Type) 0; type < TotalTimeCounterCount; type
160            = (Type) (type + 1)) {
161        if (sTotalTimeUsed[type] == sLastTimeUsed[type])
162            continue;
163        char scratch[256];
164        int index = sprintf(scratch, "*-* Diff %s time: %d ms",
165            timeCounterNames[type], sTotalTimeUsed[type] - sLastTimeUsed[type]);
166        if (sCounter[type] > sLastCounter[type])
167            sprintf(&scratch[index], " called %d times", sCounter[type]
168                - sLastCounter[type]);
169        LOGD("%s", scratch);
170    }
171    memcpy(sLastTimeUsed, sTotalTimeUsed, sizeof(sTotalTimeUsed));
172    memcpy(sLastCounter, sCounter, sizeof(sCounter));
173    sLastTotalTime = current;
174    sLastThreadTime = currentThread;
175    sRecordWebCoreTime = true;
176}
177
178void TimeCounter::reset() {
179    bzero(sTotalTimeUsed, sizeof(sTotalTimeUsed));
180    bzero(sCounter, sizeof(sCounter));
181    LOGD("*-* Start browser instrument\n");
182    sStartTotalTime = currentTime();
183    sStartThreadTime = getThreadMsec();
184}
185
186void TimeCounter::start(enum Type type)
187{
188    uint32_t time = getThreadMsec();
189    if (sRecordWebCoreTime) {
190        sStartWebCoreThreadTime = time;
191        sRecordWebCoreTime = false;
192    }
193    sStartTime[type] = time;
194}
195
196#endif  // ANDROID_INSTRUMENT
197
198}
199