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