Implement detection and triage of non-fatal assertions through logfilter

This commit is contained in:
Christian Holler 2012-05-09 16:16:26 +02:00
Родитель 9ad3833433
Коммит 9d8cb31234
4 изменённых файлов: 190 добавлений и 54 удалений

Просмотреть файл

@ -23,6 +23,7 @@ import signal
import sys
import traceback
import random
import uuid
from ConfigParser import SafeConfigParser
from mozdevice import DeviceManagerADB
@ -30,6 +31,7 @@ from mozdevice import DeviceManagerADB
from adbfuzzconfig import ADBFuzzConfig
from triage import Triager
from minidump import Minidump
from logfilter import LogFilter
def usage():
print ""
@ -84,6 +86,7 @@ class ADBFuzz:
self.HTTPProcess = None
self.logProcesses = []
self.logThreads = []
self.remoteInitialized = None
self.triager = Triager(self.config)
@ -207,7 +210,7 @@ class ADBFuzz:
logSize = 0
hangDetected = False
forceRestart = False
while(self.isFennecRunning()):
while(self.isFennecRunning() and not self.checkLoggingThreads()):
time.sleep(self.config.runTimeout)
if not os.path.exists(self.logFile):
@ -231,36 +234,57 @@ class ADBFuzz:
print "Hang detected or running too long, restarting..."
else:
try:
# Fennec died
# Fennec died or a logger found something
checkCrashDump = True
crashUUID = None
minidump = None
# If Fennec is still running, stop it now
if self.isFennecRunning():
checkCrashDump = False
self.stopFennec()
# Terminate our logging processes first
self.stopLoggers()
dumps = self.getMinidumps()
if (len(dumps) > 1):
raise Exception("Multiple dumps detected!")
if checkCrashDump:
dumps = self.getMinidumps()
if (len(dumps) > 1):
raise Exception("Multiple dumps detected!")
if (len(dumps) < 1):
raise Exception("No crash dump detected!")
if not self.fetchMinidump(dumps[0]):
raise Exception("Failed to fetch minidump with UUID " + dumps[0])
crashUUID = dumps[0]
# Copy logfiles
shutil.copy2(self.syslogFile, dumps[0] + ".syslog")
shutil.copy2(self.logFile, dumps[0] + ".log")
minidump = Minidump(dumps[0] + ".dmp", self.config.libDir)
else:
# We need to generate an arbitrary ID here
crashUUID = str(uuid.uuid4())
if (len(dumps) < 1):
raise Exception("No crash dump detected!")
# Copy logfiles
shutil.copy2(self.syslogFile, crashUUID + ".syslog")
shutil.copy2(self.logFile, crashUUID + ".log")
if not self.fetchMinidump(dumps[0]):
raise Exception("Failed to fetch minidump with UUID " + dumps[0])
print "Crash detected. Reproduction logfile stored at: " + crashUUID + ".log"
if checkCrashDump:
crashTrace = minidump.getCrashTrace()
crashType = minidump.getCrashType()
print "Crash type: " + crashType
print "Crash backtrace:"
print ""
print crashTrace
else:
print "Crash type: Abnormal behavior (e.g. Assertion violation)"
# Copy logfiles
shutil.copy2(self.syslogFile, dumps[0] + ".syslog")
shutil.copy2(self.logFile, dumps[0] + ".log")
minidump = Minidump(dumps[0] + ".dmp", self.config.libDir)
print "Crash detected. Reproduction logfile stored at: " + dumps[0] + ".log"
crashTrace = minidump.getCrashTrace()
crashType = minidump.getCrashType()
print "Crash type: " + crashType
print "Crash backtrace:"
print ""
print crashTrace
self.triager.process(minidump, dumps[0] + ".syslog", dumps[0] + ".log")
self.triager.process(crashUUID, minidump, crashUUID + ".syslog", crashUUID + ".log")
except Exception, e:
print "Error during crash processing: "
print traceback.format_exc()
@ -290,7 +314,7 @@ class ADBFuzz:
startTime = time.time()
while(self.isFennecRunning()):
while(self.isFennecRunning() and not self.checkLoggingThreads()):
time.sleep(1)
if ((time.time() - startTime) > self.config.runTimeout):
self.stopFennec()
@ -298,6 +322,11 @@ class ADBFuzz:
self.stopLoggers()
print "[TIMEOUT]"
return False
abortedByLogThread = False
if self.isFennecRunning():
abortedByLogThread = True
self.stopFennec()
self.HTTPProcess.terminate()
self.stopLoggers()
@ -307,8 +336,11 @@ class ADBFuzz:
if (len(dumps) > 0):
print "[Crash reproduced successfully]"
return True
elif abortedByLogThread:
print "[Abort reproduced successfully]"
return True
else:
# Fennec exited, but no crash
# Fennec exited, but no crash/abort
print "[Exit without Crash]"
return False
@ -367,6 +399,20 @@ class ADBFuzz:
# Terminate our logging processes
while (len(self.logProcesses) > 0):
self.logProcesses.pop().terminate()
while (len(self.logThreads) > 0):
logThread = self.logThreads.pop()
logThread.terminate()
logThread.join()
def checkLoggingThreads(self):
for logThread in self.logThreads:
# Check if the thread aborted but did not hit EOF.
# That means we hit something interesting.
if not logThread.isAlive() and not logThread.eof:
return True
return False
def startNewDeviceLog(self, toStdout=False):
# Clear the log first
@ -375,16 +421,17 @@ class ADBFuzz:
logCmd = ["adb", "logcat", "-s", "Gecko:v", "GeckoDump:v", "GeckoConsole:v", "MOZ_Assert:v"]
if toStdout:
logProcess = subprocess.Popen(logCmd)
logFile = None
else:
# Logfile
self.syslogFile = 'device.log'
logFile = self.syslogFile
# Start logging
logFile = open(self.syslogFile, 'w')
logProcess = subprocess.Popen(logCmd, stdout=logFile)
self.logProcesses.append(logProcess)
# Start logging thread
logThread = LogFilter(self.config, self.triager, logCmd, logFile)
logThread.start()
self.logThreads.append(logThread)
def startNewWebSocketLog(self):
self.logFile = 'websock.log'

75
logfilter.py Normal file
Просмотреть файл

@ -0,0 +1,75 @@
# ***** BEGIN LICENSE BLOCK *****
# Version: MPL 2.0
#
# This Source Code Form is subject to the terms of the Mozilla Public
# License, v. 2.0. If a copy of the MPL was not distributed with this
# file, You can obtain one at http://mozilla.org/MPL/2.0/.
#
# The Original Code is ADBFuzz.
#
# The Initial Developer of the Original Code is Christian Holler (decoder).
#
# Contributors:
# Christian Holler <decoder@mozilla.com> (Original Developer)
#
# ***** END LICENSE BLOCK *****
import threading
import subprocess
class LogFilter(threading.Thread):
def __init__(self, config, triager, logCmd, logFile):
self.config = config
self.triager = triager
self.logCmd = logCmd
self.logFile = logFile
self.eof = False
# Thread initialization stuff
self.stdout = None
self.stderr = None
threading.Thread.__init__(self)
# We need this to know when to terminate
self._stop = threading.Event()
def run(self):
if self.logFile == None:
logFileFd = None
else:
logFileFd = open(self.logFile, 'w')
logProcess = subprocess.Popen(self.logCmd, shell=False, stdout=subprocess.PIPE, stderr=None)
# Loop until we get aborted, hit EOF or find something interesting
while not self._stop.isSet():
line = logProcess.stdout.readline()
if (len(line) == 0):
self.eof = True
break
if logFileFd == None:
# Output to stdout
print line
else:
# Store to file first
logFileFd.write(line)
# Now check if it has something interesting (e.g. assertion)
line = line.strip()
if self.triager.checkLine(line):
break
logProcess.terminate()
if logFileFd != None:
logFileFd.close()
return
def terminate(self):
self._stop.set()
if __name__ == "__main__":
raise Exception("This module cannot run standalone, but is used by ADBFuzz")

14
mail.py
Просмотреть файл

@ -20,19 +20,21 @@ class Mailer:
def __init__(self, config):
self.config = config
def notify(self, miniDump, issueDesc):
def notify(self, issueUUID, issueDesc, miniDump):
msg = ("From: %s\r\nTo: %s\r\n" % (self.config.mailFrom, self.config.mailTo))
msg = msg + "Subject: [ADBFuzz] Issue report: " + issueDesc + "\r\n\r\n"
msg = msg + "Crash dump: " + miniDump.getFilename() + "\r\n"
msg = msg + "Crash UUID: " + issueUUID + "\r\n"
msg = msg + "Instance identifier: " + self.config.id + "\r\n"
msg = msg + "\r\n"
msg = msg + "Crash trace:" + "\r\n"
crashTrace = miniDump.getSymbolizedCrashTrace()
if miniDump != None:
msg = msg + "Crash trace:" + "\r\n"
for (frameNum, frameAddr, frameFile) in crashTrace:
msg = msg + " " + frameNum + " " + frameAddr + " " + frameFile + "\r\n"
crashTrace = miniDump.getSymbolizedCrashTrace()
for (frameNum, frameAddr, frameFile) in crashTrace:
msg = msg + " " + frameNum + " " + frameAddr + " " + frameFile + "\r\n"
server = smtplib.SMTP(self.config.SMTPHost)
server.set_debuglevel(1)

Просмотреть файл

@ -34,8 +34,10 @@ class Triager:
self.assertDetector = AssertionDetector(self.config.knownPath)
self.crashDetector = CrashDetector(self.config.knownPath)
self.androidLogLinefilter = lambda x: re.sub('^[^:]+: ', '', x)
def process(self, miniDump, systemLog, websockLog):
def process(self, issueUUID, miniDump, systemLog, websockLog):
print "Triaging crash..."
# Read Android system log
@ -45,7 +47,7 @@ class Triager:
aborted = self.assertDetector.hasFatalAssertion(
systemLogFile,
verbose=True,
lineFilter=lambda x: re.sub('^[^:]+: ', '', x)
lineFilter=self.androidLogLinefilter
)
# Reopen file
@ -58,27 +60,32 @@ class Triager:
systemLogFile,
verbose=True,
ignoreKnownAssertions=True,
lineFilter=lambda x: re.sub('^[^:]+: ', '', x)
lineFilter=self.androidLogLinefilter
)
hasNewAssertion = len(assertions) > 0
systemLogFile.close()
# Obtain symbolized crash trace to check crash signature
trace = miniDump.getSymbolizedCrashTrace()
isNewCrash = True
if miniDump == None and not hasNewAssertion:
print "Error: No minidump available but also no assertions detected!"
return
isNewCrash = (miniDump != None)
crashFunction = "Unknown"
issueDesc = "Unknown"
if (len(trace) > 0):
crashFunction = trace[0][1]
issueDesc = "Crashed at " + crashFunction
isNewCrash = not self.crashDetector.isKnownCrashSignature(crashFunction)
# Also check first frame (some functions are blacklisted here)
if (isNewCrash and len(trace) > 1):
isNewCrash = not self.crashDetector.isKnownCrashSignature(trace[1][1])
if miniDump != None:
# Obtain symbolized crash trace to check crash signature
trace = miniDump.getSymbolizedCrashTrace()
if (len(trace) > 0):
crashFunction = trace[0][1]
issueDesc = "Crashed at " + crashFunction
isNewCrash = not self.crashDetector.isKnownCrashSignature(crashFunction)
# Also check first frame (some functions are blacklisted here)
if (isNewCrash and len(trace) > 1):
isNewCrash = not self.crashDetector.isKnownCrashSignature(trace[1][1])
# Use the last assertion as issue description
if hasNewAssertion:
@ -89,15 +96,20 @@ class Triager:
if hasNewAssertion or (not aborted and isNewCrash):
print "Found new issue, check " + websockLog + " to reproduce"
if self.config.useMail:
self.mailer.notify(miniDump, issueDesc)
self.mailer.notify(issueUUID, issueDesc, miniDump)
else:
# Delete files if not in debug mode
if not self.config.debug:
miniDump.cleanup()
if miniDump != None:
miniDump.cleanup()
os.remove(systemLog)
os.remove(websockLog)
return
def checkLine(self, line):
return self.assertDetector.scanLineAssertions(self.androidLogLinefilter(line))
if __name__ == "__main__":
raise Exception("This module cannot run standalone, but is used by ADBFuzz")