• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2011 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 package com.android.loganalysis.parser;
17 
18 import com.android.loganalysis.item.LogcatItem;
19 import com.android.loganalysis.item.MiscLogcatItem;
20 import com.android.loganalysis.util.ArrayUtil;
21 import com.android.loganalysis.util.LogPatternUtil;
22 import com.android.loganalysis.util.LogTailUtil;
23 
24 import java.io.BufferedReader;
25 import java.io.IOException;
26 import java.text.DateFormat;
27 import java.text.ParseException;
28 import java.text.SimpleDateFormat;
29 import java.util.ArrayList;
30 import java.util.Date;
31 import java.util.HashMap;
32 import java.util.LinkedList;
33 import java.util.List;
34 import java.util.Map;
35 import java.util.regex.Matcher;
36 import java.util.regex.Pattern;
37 
38 /**
39  * An {@link IParser} to handle logcat.  The parser can handle the time and threadtime logcat
40  * formats.
41  * <p>
42  * Since the timestamps in the logcat do not have a year, the year can be set manually when the
43  * parser is created or through {@link #setYear(String)}.  If a year is not set, the current year
44  * will be used.
45  * </p>
46  */
47 public class LogcatParser implements IParser {
48     public static final String ANR = "ANR";
49     public static final String JAVA_CRASH = "JAVA_CRASH";
50     public static final String NATIVE_CRASH = "NATIVE_CRASH";
51     public static final String HIGH_CPU_USAGE = "HIGH_CPU_USAGE";
52     public static final String HIGH_MEMORY_USAGE = "HIGH_MEMORY_USAGE";
53     public static final String RUNTIME_RESTART = "RUNTIME_RESTART";
54 
55     /**
56      * Match a single line of `logcat -v threadtime`, such as:
57      *
58      * <pre>05-26 11:02:36.886 5689 5689 D AndroidRuntime: CheckJNI is OFF.</pre>
59      */
60     private static final Pattern THREADTIME_LINE =
61             // UID was added to logcat. It could either be a number or a string.
62             Pattern.compile(
63                     // timestamp[1]
64                     "^(\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}.\\d{3})"
65                             // pid/tid and log level [2-4]
66                             + "(?:\\s+[0-9A-Za-z]+)?\\s+(\\d+)\\s+(\\d+)\\s+([A-Z])\\s+"
67                             // tag and message [5-6]
68                             + "(.+?)\\s*: (.*)$");
69 
70     /**
71      * Match a single line of `logcat -v time`, such as:
72      * 06-04 02:32:14.002 D/dalvikvm(  236): GC_CONCURRENT freed 580K, 51% free [...]
73      */
74     private static final Pattern TIME_LINE = Pattern.compile(
75             "^(\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}.\\d{3})\\s+" +  /* timestamp [1] */
76                 "(\\w)/(.+?)\\(\\s*(\\d+)\\): (.*)$");  /* level, tag, pid, msg [2-5] */
77 
78     /**
79      * Match: "*** FATAL EXCEPTION IN SYSTEM PROCESS: message"
80      */
81     private static final Pattern SYSTEM_SERVER_CRASH = Pattern.compile(
82             "\\*\\*\\* FATAL EXCEPTION IN SYSTEM PROCESS:.*");
83     /**
84      * Match "Process: com.android.package, PID: 123" or "PID: 123"
85      */
86     private static final Pattern JAVA_CRASH_PROCESS_PID = Pattern.compile(
87             "^(Process: (\\S+), )?PID: (\\d+)$");
88 
89 
90     /**
91      * Match a line thats printed when a non app java process starts.
92      */
93     private static final Pattern JAVA_PROC_START = Pattern.compile("Calling main entry (.+)");
94 
95     /**
96      * Class for storing logcat meta data for a particular grouped list of lines.
97      */
98     private class LogcatData {
99         public Integer mPid = null;
100         public Integer mTid = null;
101         public Date mTime = null;
102         public String mLevel = null;
103         public String mTag = null;
104         public String mLastPreamble = null;
105         public String mProcPreamble = null;
106         public List<String> mLines = new LinkedList<String>();
107 
LogcatData(Integer pid, Integer tid, Date time, String level, String tag, String lastPreamble, String procPreamble)108         public LogcatData(Integer pid, Integer tid, Date time, String level, String tag,
109                 String lastPreamble, String procPreamble) {
110             mPid = pid;
111             mTid = tid;
112             mTime = time;
113             mLevel = level;
114             mTag = tag;
115             mLastPreamble = lastPreamble;
116             mProcPreamble = procPreamble;
117         }
118     }
119 
120     private LogPatternUtil mPatternUtil = new LogPatternUtil();
121     private LogTailUtil mPreambleUtil = new LogTailUtil();
122 
123     private String mYear = null;
124 
125     LogcatItem mLogcat = null;
126 
127     Map<String, LogcatData> mDataMap = new HashMap<String, LogcatData>();
128     List<LogcatData> mDataList = new LinkedList<LogcatData>();
129 
130     private Date mStartTime = null;
131     private Date mStopTime = null;
132 
133     private boolean mIsParsing = true;
134 
135     private Map<Integer, String> mPids = new HashMap<Integer, String>();
136 
137     private List<CrashTag> mJavaCrashTags = new ArrayList<>();
138     private List<CrashTag> mNativeCrashTags = new ArrayList<>();
139 
140     /**
141      * Constructor for {@link LogcatParser}.
142      */
LogcatParser()143     public LogcatParser() {
144         // Add default tag for java crash
145         addJavaCrashTag("E", "AndroidRuntime", JAVA_CRASH);
146         addNativeCrashTag("I", "DEBUG");
147         addNativeCrashTag("F", "DEBUG");
148         initPatterns();
149     }
150 
151     /**
152      * Constructor for {@link LogcatParser}.
153      *
154      * @param year The year as a string.
155      */
LogcatParser(String year)156     public LogcatParser(String year) {
157         this();
158         setYear(year);
159     }
160 
161     /**
162      * Sets the year for {@link LogcatParser}.
163      *
164      * @param year The year as a string.
165      */
setYear(String year)166     public void setYear(String year) {
167         mYear = year;
168     }
169 
170     /**
171      * Parse a logcat from a {@link BufferedReader} into an {@link LogcatItem} object.
172      *
173      * @param input a {@link BufferedReader}.
174      * @return The {@link LogcatItem}.
175      * @see #parse(List)
176      */
parse(BufferedReader input)177     public LogcatItem parse(BufferedReader input) throws IOException {
178         String line;
179         while ((line = input.readLine()) != null) {
180             parseLine(line);
181         }
182         commit();
183 
184         return mLogcat;
185     }
186 
187     /**
188      * {@inheritDoc}
189      *
190      * @return The {@link LogcatItem}.
191      */
192     @Override
parse(List<String> lines)193     public LogcatItem parse(List<String> lines) {
194         for (String line : lines) {
195             parseLine(line);
196         }
197         commit();
198 
199         return mLogcat;
200     }
201 
202     /**
203      * Clear the existing {@link LogcatItem}. The next parse will create a new one.
204      */
clear()205     public void clear() {
206         mLogcat = null;
207         mDataList.clear();
208         mDataMap.clear();
209     }
210 
211     /**
212      * Parse a line of input.
213      *
214      * @param line The line to parse
215      */
parseLine(String line)216     private void parseLine(String line) {
217         if ("".equals(line.trim())) {
218             return;
219         }
220         if (mLogcat == null) {
221             mLogcat = new LogcatItem();
222         }
223         Integer pid = null;
224         Integer tid = null;
225         Date time = null;
226         String level = null;
227         String tag = null;
228         String msg = null;
229 
230         Matcher m = THREADTIME_LINE.matcher(line);
231         Matcher tm = TIME_LINE.matcher(line);
232         if (m.matches()) {
233             time = parseTime(m.group(1));
234             pid = Integer.parseInt(m.group(2));
235             tid = Integer.parseInt(m.group(3));
236             level = m.group(4);
237             tag = m.group(5);
238             msg = m.group(6);
239         } else if (tm.matches()) {
240             time = parseTime(tm.group(1));
241             level = tm.group(2);
242             tag = tm.group(3);
243             pid = Integer.parseInt(tm.group(4));
244             msg = tm.group(5);
245         }
246 
247         if (time != null) {
248             if (mStartTime == null) {
249                 mStartTime = time;
250             }
251             mStopTime = time;
252         }
253 
254         // Don't parse any lines after device begins reboot until a new log is detected.
255         if ("I".equals(level) && "ShutdownThread".equals(tag) &&
256                 Pattern.matches("Rebooting, reason: .*", msg)) {
257             mIsParsing = false;
258         }
259         if (Pattern.matches(".*--------- beginning of .*", line)) {
260             mIsParsing = true;
261         }
262 
263         if (!mIsParsing || !(m.matches() || tm.matches())) {
264             return;
265         }
266 
267 
268         // When a non app java process starts add its pid to the map
269         Matcher pidMatcher = JAVA_PROC_START.matcher(msg);
270         if (pidMatcher.matches()) {
271             String name = pidMatcher.group(1);
272             mPids.put(pid, name);
273         }
274 
275         // ANRs are separated either by different PID/TIDs or when AnrParser.START matches a line.
276         // The newest entry is kept in the dataMap for quick lookup while all entries are added to
277         // the list.
278         if ("E".equals(level) && "ActivityManager".equals(tag)) {
279             String key = encodeLine(pid, tid, level, tag);
280             LogcatData data;
281             if (!mDataMap.containsKey(key) || AnrParser.START.matcher(msg).matches()) {
282                 data = new LogcatData(pid, tid, time, level, tag, mPreambleUtil.getLastTail(),
283                         mPreambleUtil.getIdTail(pid));
284                 mDataMap.put(key, data);
285                 mDataList.add(data);
286             } else {
287                 data = mDataMap.get(key);
288             }
289             data.mLines.add(msg);
290         }
291 
292         // Native crashes are separated either by different PID/TIDs or when
293         // NativeCrashParser.FINGERPRINT matches a line.  The newest entry is kept in the dataMap
294         // for quick lookup while all entries are added to the list.
295         if (anyNativeCrashTagMatches(level, tag)) {
296             String key = encodeLine(pid, tid, level, tag);
297             LogcatData data;
298             if (!mDataMap.containsKey(key) || NativeCrashParser.FINGERPRINT.matcher(msg).matches()) {
299                 data = new LogcatData(pid, tid, time, level, tag, mPreambleUtil.getLastTail(),
300                         mPreambleUtil.getIdTail(pid));
301                 mDataMap.put(key, data);
302                 mDataList.add(data);
303             } else {
304                 data = mDataMap.get(key);
305             }
306             data.mLines.add(msg);
307         }
308 
309         // PID and TID are enough to separate Java crashes.
310         if (anyJavaCrashTagMatches(level, tag)) {
311             String key = encodeLine(pid, tid, level, tag);
312             LogcatData data;
313             if (!mDataMap.containsKey(key)) {
314                 data = new LogcatData(pid, tid, time, level, tag, mPreambleUtil.getLastTail(),
315                         mPreambleUtil.getIdTail(pid));
316                 mDataMap.put(key, data);
317                 mDataList.add(data);
318             } else {
319                 data = mDataMap.get(key);
320             }
321             data.mLines.add(msg);
322         }
323 
324         // Check the message here but add it in commit()
325         if (mPatternUtil.checkMessage(msg, new ExtrasPattern(level, tag)) != null) {
326             LogcatData data = new LogcatData(pid, tid, time, level, tag,
327                     mPreambleUtil.getLastTail(), mPreambleUtil.getIdTail(pid));
328             data.mLines.add(msg);
329             mDataList.add(data);
330         }
331 
332         // After parsing the line, add it the the buffer for the preambles.
333         mPreambleUtil.addLine(pid, line);
334     }
335 
336     /**
337      * Signal that the input has finished.
338      */
commit()339     private void commit() {
340         if (mLogcat == null) {
341             return;
342         }
343         for (LogcatData data : mDataList) {
344             MiscLogcatItem item = null;
345             if ("E".equals(data.mLevel) && "ActivityManager".equals(data.mTag)) {
346                 item = new AnrParser().parse(data.mLines);
347             } else if (anyJavaCrashTagMatches(data.mLevel, data.mTag)) {
348                 // Get the process name/PID from the Java crash, then pass the rest of the lines to
349                 // the parser.
350                 Integer pid = null;
351                 String app = null;
352                 for (int i = 0; i < data.mLines.size(); i++) {
353                     String line = data.mLines.get(i);
354                     Matcher m = JAVA_CRASH_PROCESS_PID.matcher(line);
355                     if (m.matches()) {
356                         app = m.group(2);
357                         pid = Integer.valueOf(m.group(3));
358                         data.mLines = data.mLines.subList(i + 1, data.mLines.size());
359                         break;
360                     }
361                     m = SYSTEM_SERVER_CRASH.matcher(line);
362                     if (m.matches()) {
363                         app = mPids.get(data.mPid);
364                         if (app == null) {
365                             app = "system_server";
366                         }
367                         data.mLines = data.mLines.subList(i + 1, data.mLines.size());
368                         break;
369                     }
370                 }
371                 item = new JavaCrashParser().parse(data.mLines);
372                 if (item != null) {
373                     item.setApp(app);
374                     item.setPid(pid);
375                     item.setCategory(getJavaCrashCategory(data.mLevel, data.mTag));
376                 }
377             } else if (anyNativeCrashTagMatches(data.mLevel, data.mTag)) {
378                 // CLog.v("Parsing native crash: %s", data.mLines);
379                 item = new NativeCrashParser().parse(data.mLines);
380             } else {
381                 String msg = ArrayUtil.join("\n", data.mLines);
382                 String category = mPatternUtil.checkMessage(msg, new ExtrasPattern(
383                         data.mLevel, data.mTag));
384                 if (category != null) {
385                     MiscLogcatItem logcatItem = new MiscLogcatItem();
386                     logcatItem.setCategory(category);
387                     logcatItem.setStack(msg);
388                     item = logcatItem;
389                 }
390             }
391             if (item != null) {
392                 item.setEventTime(data.mTime);
393                 if (item.getPid() == null) {
394                     item.setPid(data.mPid);
395                     item.setTid(data.mTid);
396                 }
397                 item.setLastPreamble(data.mLastPreamble);
398                 item.setProcessPreamble(data.mProcPreamble);
399                 item.setTag(data.mTag);
400                 mLogcat.addEvent(item);
401             }
402         }
403 
404         mLogcat.setStartTime(mStartTime);
405         mLogcat.setStopTime(mStopTime);
406     }
407 
408     /**
409      * Create an identifier that "should" be unique for a given logcat. In practice, we do use it as
410      * a unique identifier.
411      */
encodeLine(Integer pid, Integer tid, String level, String tag)412     private static String encodeLine(Integer pid, Integer tid, String level, String tag) {
413         if (tid == null) {
414             return String.format("%d|%s|%s", pid, level, tag);
415         }
416         return String.format("%d|%d|%s|%s", pid, tid, level, tag);
417     }
418 
419     /**
420      * Parse the timestamp and return a {@link Date}.  If year is not set, the current year will be
421      * used.
422      *
423      * @param timeStr The timestamp in the format {@code MM-dd HH:mm:ss.SSS}.
424      * @return The {@link Date}.
425      */
parseTime(String timeStr)426     private Date parseTime(String timeStr) {
427         // If year is null, just use the current year.
428         if (mYear == null) {
429             DateFormat yearFormatter = new SimpleDateFormat("yyyy");
430             mYear = yearFormatter.format(new Date());
431         }
432 
433         DateFormat formatter = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
434         try {
435             return formatter.parse(String.format("%s-%s", mYear, timeStr));
436         } catch (ParseException e) {
437             // CLog.e("Could not parse time string %s", timeStr);
438             return null;
439         }
440     }
441 
initPatterns()442     private void initPatterns() {
443         // High CPU usage
444         mPatternUtil.addPattern(Pattern.compile(".* timed out \\(is the CPU pegged\\?\\).*"),
445                 HIGH_CPU_USAGE);
446 
447         // High memory usage
448         mPatternUtil.addPattern(Pattern.compile(
449                 "GetBufferLock timed out for thread \\d+ buffer .*"), HIGH_MEMORY_USAGE);
450 
451         // Runtime restarts
452         mPatternUtil.addPattern(Pattern.compile("\\*\\*\\* WATCHDOG KILLING SYSTEM PROCESS.*"),
453                 RUNTIME_RESTART);
454     }
455 
456     /**
457      * Adds a custom, more complex pattern to LogcatParser for parsing out of logcat events.
458      * Any matched events are then assigned to the category name provided, and can be grabbed
459      * via LogcatParser's .getMiscEvents("yourCustomCategoryName") method.
460      * Considers null messages, levels, or tags to be wildcards.
461      *
462      * @param pattern The regex representing the pattern to match for, or null for wildcard.
463      * @param level The name of the level to match for, or null for wildcard.
464      * @param tag The name of the tag to match for, or null for wildcard.
465      * @param category Assign any matching logcat events to this category name, for later retrieval
466      */
addPattern(Pattern pattern, String level, String tag, String category)467     public void addPattern(Pattern pattern, String level, String tag, String category) {
468         /* count null message as wildcard */
469         if (pattern == null) {
470             pattern = Pattern.compile(".*");
471         }
472         mPatternUtil.addPattern(pattern, new ExtrasPattern(level, tag), category);
473     }
474 
475     /**
476      * Used internally for bundling up extra pattern criteria for more advanced pattern matching.
477      */
478     private class ExtrasPattern {
479         public String mLevel;
480         public String mTag;
481 
ExtrasPattern(String level, String tag)482         public ExtrasPattern(String level, String tag) {
483             mLevel = level;
484             mTag = tag;
485         }
486 
487         /**
488          * Override Object.equals to match based on the level & tag patterns,
489          * while also counting null level & tag patterns as wildcards.
490          *
491          * @param otherObj the object we're matching the level & tag patterns to.
492          * @return true if otherObj's extras match, false otherwise
493          */
494         @Override
equals(Object otherObj)495         public boolean equals(Object otherObj) {
496             if (otherObj instanceof ExtrasPattern) {
497                 // Treat objects as equal only if the obj's level and tag match.
498                 // Treat null as a wildcard.
499                 ExtrasPattern other = (ExtrasPattern) otherObj;
500                 if ((mLevel == null || other.mLevel == null || mLevel.equals(other.mLevel)) &&
501                         (mTag == null || other.mTag == null || mTag.equals(other.mTag))) {
502                     return true;
503                 }
504             }
505             return false;
506         }
507 
508         /** {@inheritdoc} */
509         @Override
hashCode()510         public int hashCode() {
511             // Since both mLevel and mTag can be wild cards, we can't actually use them to generate
512             // a hashcode without potentially violating the hashcode contract. That doesn't leave
513             // us with anything to actually use to generate the hashcode, so just return a random
514             // static int.
515             return 145800969;
516         }
517     }
518 
519     /**
520      * Allows Java crashes to be parsed from multiple log levels and tags. Normally the crashes
521      * are error level messages from AndroidRuntime, but they could also be from other sources.
522      * Use this method to parse java crashes from those other sources.
523      *
524      * @param level log level on which to look for java crashes
525      * @param tag log tag where to look for java crashes
526      */
addJavaCrashTag(String level, String tag, String category)527     public void addJavaCrashTag(String level, String tag, String category) {
528         mJavaCrashTags.add(new CrashTag(level, tag, category));
529     }
530 
531     /**
532      * Allows native crashes to be parsed from multiple log levels and tags.  The default levels
533      * are "I DEBUG" and "F DEBUG".
534      *
535      * @param level log level on which to look for native crashes
536      * @param tag log tag where to look for native crashes
537      */
addNativeCrashTag(String level, String tag)538     private void addNativeCrashTag(String level, String tag) {
539         mNativeCrashTags.add(new CrashTag(level, tag, NATIVE_CRASH));
540     }
541 
542     /**
543      * Determines if any of the Java crash tags is matching a logcat line.
544      *
545      * @param level log level of the logcat line
546      * @param tag tag of the logcat line
547      * @return True if any Java crash tag matches the current level and tag. False otherwise.
548      */
anyJavaCrashTagMatches(String level, String tag)549     private boolean anyJavaCrashTagMatches(String level, String tag) {
550         return findCrashTag(mJavaCrashTags, level, tag) != null;
551     }
552 
553     /**
554      * Determines if any of the native crash tags is matching a logcat line.
555      *
556      * @param level log level of the logcat line
557      * @param tag tag of the logcat line
558      * @return True if any native crash tag matches the current level and tag. False otherwise.
559      */
anyNativeCrashTagMatches(String level, String tag)560     private boolean anyNativeCrashTagMatches(String level, String tag) {
561         return findCrashTag(mNativeCrashTags, level, tag) != null;
562     }
563 
564     /**
565      * Finds the {@link CrashTag} matching given level and tag.
566      *
567      * @param level level to find
568      * @param tag tag to find
569      * @return the matching {@link CrashTag} or null if no matches exist.
570      */
findCrashTag(List<CrashTag> crashTags, String level, String tag)571     private CrashTag findCrashTag(List<CrashTag> crashTags, String level, String tag) {
572         for (CrashTag t : crashTags) {
573             if (t.matches(level, tag)) {
574                 return t;
575             }
576         }
577         return null;
578     }
579 
580     /**
581      * Returns category for a given {@link CrashTag}.
582      *
583      * @param level level of the {@link CrashTag}
584      * @param tag tag of the {@link CrashTag}
585      * @return category of the {@link CrashTag}, matching search criteria. If nothing was found
586      * returns {@code JAVA_CRASH}.
587      */
getJavaCrashCategory(String level, String tag)588     private String getJavaCrashCategory(String level, String tag) {
589         CrashTag crashTag = findCrashTag(mJavaCrashTags, level, tag);
590         if (crashTag == null) {
591             return JAVA_CRASH;
592         }
593         return crashTag.getCategory();
594     }
595 
596     /**
597      * Class to encapsulate the tags that indicate which crashes should be parsed.
598      */
599     private class CrashTag {
600         private String mLevel;
601         private String mTag;
602         private String mCategory;
603 
CrashTag(String level, String tag, String category)604         public CrashTag(String level, String tag, String category) {
605             mLevel = level;
606             mTag = tag;
607             mCategory = category;
608         }
609 
matches(String level, String tag)610         public boolean matches(String level, String tag) {
611             return mLevel.equals(level) && mTag.equals(tag);
612         }
613 
getCategory()614         public String getCategory() {
615             return mCategory;
616         }
617     }
618 }
619