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 49 using namespace WebCore; 50 using namespace WTF; 51 using namespace JSC; 52 53 namespace android { 54 55 uint32_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 73 static double sStartTotalTime; 74 static uint32_t sStartThreadTime; 75 static double sLastTotalTime; 76 static uint32_t sLastThreadTime; 77 78 uint32_t TimeCounter::sStartWebCoreThreadTime; 79 uint32_t TimeCounter::sEndWebCoreThreadTime; 80 bool TimeCounter::sRecordWebCoreTime; 81 uint32_t TimeCounter::sTotalTimeUsed[TimeCounter::TotalTimeCounterCount]; 82 uint32_t TimeCounter::sLastTimeUsed[TimeCounter::TotalTimeCounterCount]; 83 uint32_t TimeCounter::sCounter[TimeCounter::TotalTimeCounterCount]; 84 uint32_t TimeCounter::sLastCounter[TimeCounter::TotalTimeCounterCount]; 85 uint32_t TimeCounter::sStartTime[TimeCounter::TotalTimeCounterCount]; 86 87 int QemuTracerAuto::reentry_count = 0; 88 89 static 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 108 void TimeCounter::record(enum Type type, const char* functionName) 109 { 110 recordNoCounter(type, functionName); 111 sCounter[type]++; 112 } 113 114 void 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 123 void 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 151 void 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 179 void 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 187 void 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