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