1 /* 2 * Copyright (C) 2006 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package com.android.traceview; 18 19 import java.io.BufferedReader; 20 import java.io.File; 21 import java.io.FileInputStream; 22 import java.io.FileNotFoundException; 23 import java.io.FileReader; 24 import java.io.IOException; 25 import java.nio.BufferUnderflowException; 26 import java.nio.ByteOrder; 27 import java.nio.MappedByteBuffer; 28 import java.nio.channels.FileChannel; 29 import java.util.ArrayList; 30 import java.util.Arrays; 31 import java.util.Collection; 32 import java.util.Comparator; 33 import java.util.HashMap; 34 import java.util.regex.Matcher; 35 import java.util.regex.Pattern; 36 37 public class DmTraceReader extends TraceReader { 38 39 private int mVersionNumber = 0; 40 private boolean mDebug = false; 41 private static final int TRACE_MAGIC = 0x574f4c53; 42 private boolean mRegression; 43 private ProfileProvider mProfileProvider; 44 private String mTraceFileName; 45 private MethodData mTopLevel; 46 private ArrayList<Call> mCallList; 47 private ArrayList<Call> mSwitchList; 48 private HashMap<Integer, MethodData> mMethodMap; 49 private HashMap<Integer, ThreadData> mThreadMap; 50 private ThreadData[] mSortedThreads; 51 private MethodData[] mSortedMethods; 52 private long mGlobalEndTime; 53 private MethodData mContextSwitch; 54 private int mOffsetToData; 55 private byte[] mBytes = new byte[8]; 56 57 // A regex for matching the thread "id name" lines in the .key file 58 private static final Pattern mIdNamePattern = Pattern.compile("(\\d+)\t(.*)"); // $NON-NLS-1$ 59 DmTraceReader(String traceFileName, boolean regression)60 DmTraceReader(String traceFileName, boolean regression) { 61 mTraceFileName = traceFileName; 62 mRegression = regression; 63 mMethodMap = new HashMap<Integer, MethodData>(); 64 mThreadMap = new HashMap<Integer, ThreadData>(); 65 66 // Create a single top-level MethodData object to hold the profile data 67 // for time spent in the unknown caller. 68 mTopLevel = new MethodData(0, "(toplevel)"); 69 mContextSwitch = new MethodData(-1, "(context switch)"); 70 mMethodMap.put(0, mTopLevel); 71 generateTrees(); 72 // dumpTrees(); 73 } 74 generateTrees()75 void generateTrees() { 76 try { 77 long offset = parseKeys(); 78 parseData(offset); 79 analyzeData(); 80 } catch (IOException e) { 81 System.err.println(e.getMessage()); 82 System.exit(1); 83 } 84 } 85 86 @Override getProfileProvider()87 public ProfileProvider getProfileProvider() { 88 if (mProfileProvider == null) 89 mProfileProvider = new ProfileProvider(this); 90 return mProfileProvider; 91 } 92 readCall(MappedByteBuffer buffer, Call call)93 Call readCall(MappedByteBuffer buffer, Call call) { 94 int threadId; 95 int methodId; 96 long time; 97 98 try { 99 if (mVersionNumber == 1) 100 threadId = buffer.get(); 101 else 102 threadId = buffer.getShort(); 103 methodId = buffer.getInt(); 104 time = buffer.getInt(); 105 } catch (BufferUnderflowException ex) { 106 return null; 107 } 108 109 int methodAction = methodId & 0x03; 110 methodId = methodId & ~0x03; 111 MethodData methodData = mMethodMap.get(methodId); 112 if (methodData == null) { 113 String name = String.format("(0x%1$x)", methodId); // $NON-NLS-1$ 114 methodData = new MethodData(methodId, name); 115 } 116 117 if (call != null) { 118 call.set(threadId, methodData, time, methodAction); 119 } else { 120 call = new Call(threadId, methodData, time, methodAction); 121 } 122 return call; 123 } 124 mapFile(String filename, long offset)125 private MappedByteBuffer mapFile(String filename, long offset) { 126 MappedByteBuffer buffer = null; 127 try { 128 FileInputStream dataFile = new FileInputStream(filename); 129 File file = new File(filename); 130 FileChannel fc = dataFile.getChannel(); 131 buffer = fc.map(FileChannel.MapMode.READ_ONLY, offset, file.length() - offset); 132 buffer.order(ByteOrder.LITTLE_ENDIAN); 133 } catch (FileNotFoundException ex) { 134 System.err.println(ex.getMessage()); 135 System.exit(1); 136 } catch (IOException ex) { 137 System.err.println(ex.getMessage()); 138 System.exit(1); 139 } 140 141 return buffer; 142 } 143 readDataFileHeader(MappedByteBuffer buffer)144 private void readDataFileHeader(MappedByteBuffer buffer) { 145 int magic = buffer.getInt(); 146 if (magic != TRACE_MAGIC) { 147 System.err.printf( 148 "Error: magic number mismatch; got 0x%x, expected 0x%x\n", 149 magic, TRACE_MAGIC); 150 throw new RuntimeException(); 151 } 152 // read version 153 int version = buffer.getShort(); 154 155 // read offset 156 mOffsetToData = buffer.getShort() - 16; 157 158 // read startWhen 159 buffer.getLong(); 160 161 // Skip over "mOffsetToData" bytes 162 for (int ii = 0; ii < mOffsetToData; ii++) { 163 buffer.get(); 164 } 165 166 // Save this position so that we can re-read the data later 167 buffer.mark(); 168 } 169 parseData(long offset)170 private void parseData(long offset) { 171 MappedByteBuffer buffer = mapFile(mTraceFileName, offset); 172 readDataFileHeader(buffer); 173 parseDataPass1(buffer); 174 175 buffer.reset(); 176 parseDataPass2(buffer); 177 } 178 parseDataPass1(MappedByteBuffer buffer)179 private void parseDataPass1(MappedByteBuffer buffer) { 180 mSwitchList = new ArrayList<Call>(); 181 182 // Read the first call so that we can set "prevThreadData" 183 Call call = new Call(); 184 call = readCall(buffer, call); 185 if (call == null) 186 return; 187 long callTime = call.mThreadStartTime; 188 long prevCallTime = 0; 189 ThreadData threadData = mThreadMap.get(call.getThreadId()); 190 if (threadData == null) { 191 String name = String.format("[%1$d]", call.getThreadId()); // $NON-NLS-1$ 192 threadData = new ThreadData(call.getThreadId(), name, mTopLevel); 193 mThreadMap.put(call.getThreadId(), threadData); 194 } 195 ThreadData prevThreadData = threadData; 196 while (true) { 197 // If a context switch occurred, then insert a placeholder "call" 198 // record so that we can do something reasonable with the global 199 // timestamps. 200 if (prevThreadData != threadData) { 201 Call switchEnter = new Call(prevThreadData.getId(), 202 mContextSwitch, prevCallTime, 0); 203 prevThreadData.setLastContextSwitch(switchEnter); 204 mSwitchList.add(switchEnter); 205 Call contextSwitch = threadData.getLastContextSwitch(); 206 if (contextSwitch != null) { 207 long prevStartTime = contextSwitch.mThreadStartTime; 208 long elapsed = callTime - prevStartTime; 209 long beforeSwitch = elapsed / 2; 210 long afterSwitch = elapsed - beforeSwitch; 211 long exitTime = callTime - afterSwitch; 212 contextSwitch.mThreadStartTime = prevStartTime + beforeSwitch; 213 Call switchExit = new Call(threadData.getId(), 214 mContextSwitch, exitTime, 1); 215 216 mSwitchList.add(switchExit); 217 } 218 prevThreadData = threadData; 219 } 220 221 // Read the next call 222 call = readCall(buffer, call); 223 if (call == null) { 224 break; 225 } 226 prevCallTime = callTime; 227 callTime = call.mThreadStartTime; 228 229 threadData = mThreadMap.get(call.getThreadId()); 230 if (threadData == null) { 231 String name = String.format("[%d]", call.getThreadId()); 232 threadData = new ThreadData(call.getThreadId(), name, mTopLevel); 233 mThreadMap.put(call.getThreadId(), threadData); 234 } 235 } 236 } 237 parseDataPass2(MappedByteBuffer buffer)238 void parseDataPass2(MappedByteBuffer buffer) { 239 mCallList = new ArrayList<Call>(); 240 241 // Read the first call so that we can set "prevThreadData" 242 Call call = readCall(buffer, null); 243 long callTime = call.mThreadStartTime; 244 long prevCallTime = callTime; 245 ThreadData threadData = mThreadMap.get(call.getThreadId()); 246 ThreadData prevThreadData = threadData; 247 threadData.setGlobalStartTime(0); 248 249 int nthContextSwitch = 0; 250 251 // Assign a global timestamp to each event. 252 long globalTime = 0; 253 while (true) { 254 long elapsed = callTime - prevCallTime; 255 if (threadData != prevThreadData) { 256 // Get the next context switch. This one is entered 257 // by the previous thread. 258 Call contextSwitch = mSwitchList.get(nthContextSwitch++); 259 mCallList.add(contextSwitch); 260 elapsed = contextSwitch.mThreadStartTime - prevCallTime; 261 globalTime += elapsed; 262 elapsed = 0; 263 contextSwitch.mGlobalStartTime = globalTime; 264 prevThreadData.handleCall(contextSwitch, globalTime); 265 266 if (!threadData.isEmpty()) { 267 // This context switch is exited by the current thread. 268 contextSwitch = mSwitchList.get(nthContextSwitch++); 269 mCallList.add(contextSwitch); 270 contextSwitch.mGlobalStartTime = globalTime; 271 elapsed = callTime - contextSwitch.mThreadStartTime; 272 threadData.handleCall(contextSwitch, globalTime); 273 } 274 275 // If the thread's global start time has not been set yet, 276 // then set it. 277 if (threadData.getGlobalStartTime() == -1) 278 threadData.setGlobalStartTime(globalTime); 279 prevThreadData = threadData; 280 } 281 282 globalTime += elapsed; 283 call.mGlobalStartTime = globalTime; 284 285 threadData.handleCall(call, globalTime); 286 mCallList.add(call); 287 288 // Read the next call 289 call = readCall(buffer, null); 290 if (call == null) { 291 break; 292 } 293 prevCallTime = callTime; 294 callTime = call.mThreadStartTime; 295 threadData = mThreadMap.get(call.getThreadId()); 296 } 297 298 // Allow each thread to do any cleanup of the call stack. 299 // Also add the elapsed time for each thread to the toplevel 300 // method's inclusive time. 301 for (int id : mThreadMap.keySet()) { 302 threadData = mThreadMap.get(id); 303 long endTime = threadData.endTrace(); 304 if (endTime > 0) 305 mTopLevel.addElapsedInclusive(endTime, false, null); 306 } 307 308 mGlobalEndTime = globalTime; 309 310 if (mRegression) { 311 dumpCallTimes(); 312 } 313 } 314 315 static final int PARSE_VERSION = 0; 316 static final int PARSE_THREADS = 1; 317 static final int PARSE_METHODS = 2; 318 static final int PARSE_OPTIONS = 4; 319 parseKeys()320 long parseKeys() throws IOException { 321 BufferedReader in = null; 322 try { 323 in = new BufferedReader(new FileReader(mTraceFileName)); 324 } catch (FileNotFoundException ex) { 325 System.err.println(ex.getMessage()); 326 } 327 328 long offset = 0; 329 int mode = PARSE_VERSION; 330 String line = null; 331 while (true) { 332 line = in.readLine(); 333 if (line == null) { 334 throw new IOException("Key section does not have an *end marker"); 335 } 336 337 // Calculate how much we have read from the file so far. The 338 // extra byte is for the line ending not included by readLine(). 339 offset += line.length() + 1; 340 if (line.startsWith("*")) { 341 if (line.equals("*version")) { 342 mode = PARSE_VERSION; 343 continue; 344 } 345 if (line.equals("*threads")) { 346 mode = PARSE_THREADS; 347 continue; 348 } 349 if (line.equals("*methods")) { 350 mode = PARSE_METHODS; 351 continue; 352 } 353 if (line.equals("*end")) { 354 return offset; 355 } 356 } 357 switch (mode) { 358 case PARSE_VERSION: 359 mVersionNumber = Integer.decode(line); 360 mode = PARSE_OPTIONS; 361 break; 362 case PARSE_THREADS: 363 parseThread(line); 364 break; 365 case PARSE_METHODS: 366 parseMethod(line); 367 break; 368 case PARSE_OPTIONS: 369 break; 370 } 371 } 372 } 373 parseThread(String line)374 void parseThread(String line) { 375 String idStr = null; 376 String name = null; 377 Matcher matcher = mIdNamePattern.matcher(line); 378 if (matcher.find()) { 379 idStr = matcher.group(1); 380 name = matcher.group(2); 381 } 382 if (idStr == null) return; 383 if (name == null) name = "(unknown)"; 384 385 int id = Integer.decode(idStr); 386 mThreadMap.put(id, new ThreadData(id, name, mTopLevel)); 387 } 388 parseMethod(String line)389 void parseMethod(String line) { 390 String[] tokens = line.split("\t"); 391 int id = Long.decode(tokens[0]).intValue(); 392 String className = tokens[1]; 393 String methodName = null; 394 String signature = null; 395 String pathname = null; 396 int lineNumber = -1; 397 if (tokens.length == 6) { 398 methodName = tokens[2]; 399 signature = tokens[3]; 400 pathname = tokens[4]; 401 lineNumber = Integer.decode(tokens[5]); 402 pathname = constructPathname(className, pathname); 403 } else if (tokens.length > 2) { 404 if (tokens[3].startsWith("(")) { 405 methodName = tokens[2]; 406 signature = tokens[3]; 407 } else { 408 pathname = tokens[2]; 409 lineNumber = Integer.decode(tokens[3]); 410 } 411 } 412 413 mMethodMap.put(id, new MethodData(id, className, methodName, signature, 414 pathname, lineNumber)); 415 } 416 constructPathname(String className, String pathname)417 private String constructPathname(String className, String pathname) { 418 int index = className.lastIndexOf('/'); 419 if (index > 0 && index < className.length() - 1 420 && pathname.endsWith(".java")) 421 pathname = className.substring(0, index + 1) + pathname; 422 return pathname; 423 } 424 analyzeData()425 private void analyzeData() { 426 // Sort the threads into decreasing cpu time 427 Collection<ThreadData> tv = mThreadMap.values(); 428 mSortedThreads = tv.toArray(new ThreadData[tv.size()]); 429 Arrays.sort(mSortedThreads, new Comparator<ThreadData>() { 430 public int compare(ThreadData td1, ThreadData td2) { 431 if (td2.getCpuTime() > td1.getCpuTime()) 432 return 1; 433 if (td2.getCpuTime() < td1.getCpuTime()) 434 return -1; 435 return td2.getName().compareTo(td1.getName()); 436 } 437 }); 438 439 // Analyze the call tree so that we can label the "worst" children. 440 // Also set all the root pointers in each node in the call tree. 441 long sum = 0; 442 for (ThreadData t : mSortedThreads) { 443 if (t.isEmpty() == false) { 444 Call root = t.getCalltreeRoot(); 445 root.mGlobalStartTime = t.getGlobalStartTime(); 446 } 447 } 448 449 // Sort the methods into decreasing inclusive time 450 Collection<MethodData> mv = mMethodMap.values(); 451 MethodData[] methods; 452 methods = mv.toArray(new MethodData[mv.size()]); 453 Arrays.sort(methods, new Comparator<MethodData>() { 454 public int compare(MethodData md1, MethodData md2) { 455 if (md2.getElapsedInclusive() > md1.getElapsedInclusive()) 456 return 1; 457 if (md2.getElapsedInclusive() < md1.getElapsedInclusive()) 458 return -1; 459 return md1.getName().compareTo(md2.getName()); 460 } 461 }); 462 463 // Count the number of methods with non-zero inclusive time 464 int nonZero = 0; 465 for (MethodData md : methods) { 466 if (md.getElapsedInclusive() == 0) 467 break; 468 nonZero += 1; 469 } 470 471 // Copy the methods with non-zero time 472 mSortedMethods = new MethodData[nonZero]; 473 int ii = 0; 474 for (MethodData md : methods) { 475 if (md.getElapsedInclusive() == 0) 476 break; 477 md.setRank(ii); 478 mSortedMethods[ii++] = md; 479 } 480 481 // Let each method analyze its profile data 482 for (MethodData md : mSortedMethods) { 483 md.analyzeData(); 484 } 485 486 // Update all the calls to include the method rank in 487 // their name. 488 for (Call call : mCallList) { 489 call.updateName(); 490 } 491 492 if (mRegression) { 493 dumpMethodStats(); 494 } 495 } 496 497 /* 498 * This method computes a list of records that describe the the execution 499 * timeline for each thread. Each record is a pair: (row, block) where: row: 500 * is the ThreadData object block: is the call (containing the start and end 501 * times) 502 */ 503 @Override getThreadTimeRecords()504 public ArrayList<TimeLineView.Record> getThreadTimeRecords() { 505 TimeLineView.Record record; 506 ArrayList<TimeLineView.Record> timeRecs; 507 timeRecs = new ArrayList<TimeLineView.Record>(); 508 509 // For each thread, push a "toplevel" call that encompasses the 510 // entire execution of the thread. 511 for (ThreadData threadData : mSortedThreads) { 512 if (!threadData.isEmpty() && threadData.getId() != 0) { 513 Call call = new Call(threadData.getId(), mTopLevel, 514 threadData.getGlobalStartTime(), 0); 515 call.mGlobalStartTime = threadData.getGlobalStartTime(); 516 call.mGlobalEndTime = threadData.getGlobalEndTime(); 517 record = new TimeLineView.Record(threadData, call); 518 timeRecs.add(record); 519 } 520 } 521 522 for (Call call : mCallList) { 523 if (call.getMethodAction() != 0 || call.getThreadId() == 0) 524 continue; 525 ThreadData threadData = mThreadMap.get(call.getThreadId()); 526 record = new TimeLineView.Record(threadData, call); 527 timeRecs.add(record); 528 } 529 530 if (mRegression) { 531 dumpTimeRecs(timeRecs); 532 System.exit(0); 533 } 534 return timeRecs; 535 } 536 dumpCallTimes()537 private void dumpCallTimes() { 538 String action; 539 540 System.out.format("id thread global start,end method\n"); 541 for (Call call : mCallList) { 542 if (call.getMethodAction() == 0) { 543 action = "+"; 544 } else { 545 action = " "; 546 } 547 long callTime = call.mThreadStartTime; 548 System.out.format("%2d %6d %8d %8d %s %s\n", 549 call.getThreadId(), callTime, call.mGlobalStartTime, 550 call.mGlobalEndTime, action, call.getMethodData().getName()); 551 // if (call.getMethodAction() == 0 && call.getGlobalEndTime() < call.getGlobalStartTime()) { 552 // System.out.printf("endtime %d < startTime %d\n", 553 // call.getGlobalEndTime(), call.getGlobalStartTime()); 554 // } 555 } 556 } 557 dumpMethodStats()558 private void dumpMethodStats() { 559 System.out.format("\nExclusive Inclusive Calls Method\n"); 560 for (MethodData md : mSortedMethods) { 561 System.out.format("%9d %9d %9s %s\n", 562 md.getElapsedExclusive(), md.getElapsedInclusive(), 563 md.getCalls(), md.getProfileName()); 564 } 565 } 566 dumpTimeRecs(ArrayList<TimeLineView.Record> timeRecs)567 private void dumpTimeRecs(ArrayList<TimeLineView.Record> timeRecs) { 568 System.out.format("\nid thread global start,end method\n"); 569 for (TimeLineView.Record record : timeRecs) { 570 Call call = (Call) record.block; 571 long callTime = call.mThreadStartTime; 572 System.out.format("%2d %6d %8d %8d %s\n", 573 call.getThreadId(), callTime, 574 call.mGlobalStartTime, call.mGlobalEndTime, 575 call.getMethodData().getName()); 576 } 577 } 578 579 @Override getThreadLabels()580 public HashMap<Integer, String> getThreadLabels() { 581 HashMap<Integer, String> labels = new HashMap<Integer, String>(); 582 for (ThreadData t : mThreadMap.values()) { 583 labels.put(t.getId(), t.getName()); 584 } 585 return labels; 586 } 587 588 @Override getMethods()589 public MethodData[] getMethods() { 590 return mSortedMethods; 591 } 592 593 @Override getThreads()594 public ThreadData[] getThreads() { 595 return mSortedThreads; 596 } 597 598 @Override getEndTime()599 public long getEndTime() { 600 return mGlobalEndTime; 601 } 602 } 603