• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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