def loadDb(self, store: ApplicationStore = None, checkInitialised: bool = False): """Load the PreloadLogger database. Go through the directory and create all the relevant app instances and events. Can be made to insert all found apps into an ApplicationStore, or to exit if some Application instances are not properly initialised. """ count = 0 # Counter of fetched files, for stats actors = set() # Apps that logged anything at all empties = 0 # Matching files without content (logger crash) invalids = 0 # Files with corrupted content (logger crash) nosyscalls = [] # Logs with zero syscalls logged (not a bug) nosyscallactors = set() # Apps that logged zero syscalls instanceCount = 0 # Count of distinct app instances in the dataset hasErrors = False # Whether some uninitialised apps were found invalidApps = set() # List of desktop IDs that could not be init'd eventCount = 0 # List all log files that match the PreloadLogger syntax for file in os.listdir(self.path): # Ignore files that don't match if not PreloadLoggerLoader.pattern.match(file): continue count += 1 # Process log files that match the PreloadLogger name pattern try: f = open(self.path + "/" + file, 'rb') except (IOError) as e: print("Error: could not open file %s: %s" % (file, str(e)), file=sys.stderr) else: with f: if os.fstat(f.fileno()).st_size == 0: print("Info: file '%s' is empty. Skipping." % file) continue # Parse the first line to get the identity of the app, # but sometimes the header ends up on the second line # in some logs... So, parse until we find a match, and # remember the line index of the header idx = 0 headerLocation = 0 result = None for binary in f: try: line = binary.decode('utf-8') except (UnicodeDecodeError) as e: print("Error: %s has a non utf-8 line: %s " % (file, str(e)), file=sys.stderr) idx += 1 continue result = PreloadLoggerLoader.header.match(line) if result: headerLocation = idx break idx += 1 # Files with a missing or corrupted header are invalid if result is None: print("%s is missing a header" % file, file=sys.stderr) invalids += 1 continue # Parse the header line, make sure it has the right length. g = result.groups() if (len(g) != 3): print("%s has wrong group count: " % file, result.group(), file=sys.stderr) invalids += 1 continue # Filter interpreters, and rewrite them to get the identity # of the app they launched instead. items = space.split(g[2]) interpreterid = None # Python if (pyre.match(g[0])): interpreterid = g[0] g = self.parsePython(g, items) # print("PYTHON APP: %s" % g[2]) # Bash if (bashre.match(g[0])): interpreterid = g[0] g = self.parseBash(g, items) # print("BASH APP: %s" % g[2]) # Java if (javare.match(g[0])): interpreterid = g[0] g = self.parseJava(g, items) # print("JAVA APP: %s" % g[2]) # Perl if (perlre.match(g[0])): interpreterid = g[0] g = self.parsePerl(g, items) # print("PERL APP: %s" % g[2]) # Mono if (monore.match(g[0])): interpreterid = g[0] g = self.parseMono(g, items) # print("MONO APP: %s" % g[2]) # PHP if (phpre.match(g[0])): interpreterid = g[0] g = self.parsePHP(g, items) # print("PHP APP: %s" % g[2]) # Get first and last event to calculate the timestamps. tstart = float("inf") tend = 0 skipCache = None lineIdx = 0 f.seek(0, 0) for binary in f: # Ignore the header. if lineIdx == headerLocation: lineIdx += 1 skipCache = None continue # Decode line. try: line = binary.decode('utf-8') except (UnicodeDecodeError) as e: print("Error: %s has a non utf-8 line: %s " % (file, str(e)), file=sys.stderr) lineIdx += 1 skipCache = None continue # Previous line did not end and was skipped, merge it. if skipCache: line = skipCache + line skipCache = None # Line continues... if line.endswith('\\\n'): skipCache = line lineIdx += 1 continue line = line.rstrip("\n").lstrip(" ") # Line is a parameter to the last system call logged if line.startswith(' '): lineIdx += 1 continue # Check that line is a syntactically valid system call result = PreloadLoggerLoader.syscall.match(line) if result is None: if debugEnabled(): print("%s has a corrupted line (match): %s" % (file, line), file=sys.stderr) lineIdx += 1 continue # Update the timestamp (convert to ZG millisec format) h = result.groups() tstart = int(h[0]) * 1000 break # TODO, first non-header line + tail code. lastLine = tail(f) result = None if lastLine: result = PreloadLoggerLoader.syscall.match(lastLine) if result is None: if debugEnabled(): print("%s's last line is corrupted: %s" % (file, lastLine), file=sys.stderr) else: # Update the timestamp (convert to ZG millisec format) h = result.groups() tend = int(h[0]) * 1000 # Check if the timestamps have been set if tend == 0: nosyscalls.append(g) nosyscallactors.add(g[0]) continue # Sometimes, short logs have event ordering problems... We # can try to ignore these problems as all events are indi- # vidually timestamped anyway. if tstart > tend: tend, start = tstart, tend # TODO: process deletions and remove corresponding files # Make the application try: app = Application(desktopid=g[0], pid=int(g[1]), tstart=tstart, tend=tend, interpreterid=interpreterid) app.setCommandLine(g[2]) except (ValueError) as e: print("MISSING: %s" % g[0], file=sys.stderr) hasErrors = True invalidApps.add(g[0]) continue # Ignore study artefacts! if app.isStudyApp(): continue # Add command-line event event = Event(actor=app, time=tstart, cmdlineStr=g[2]) app.addEvent(event) # Add system call events skipCache = None lineIdx = 0 currentCall = None prevTimestamp = 0 timeDelta = 0 f.seek(0, 0) for binary in f: # Ignore the header. if lineIdx == headerLocation: lineIdx += 1 skipCache = None continue # Decode line. try: line = binary.decode('utf-8') except (UnicodeDecodeError) as e: print("Error: %s has a non utf-8 line: %s " % (file, str(e)), file=sys.stderr) lineIdx += 1 skipCache = None continue # Previous line did not end and was skipped, merge it. if skipCache: line = skipCache + line skipCache = None # Line continues... if line.endswith('\\\n'): skipCache = line lineIdx += 1 continue line = line[:-1] # Remove ending "\n" # Line is a parameter to the last system call logged if line.startswith(' '): if currentCall: currentCall = (currentCall[0], currentCall[1] + '\n' + line) elif debugEnabled(): print("%s has a corrupted line (no call): %s" % (file, line), file=sys.stderr) lineIdx += 1 continue # Check that line is a syntactically valid system call result = PreloadLoggerLoader.syscall.match(line) if result is None: if debugEnabled(): print("%s has a corrupted line (match): %s" % (file, line), file=sys.stderr) lineIdx += 1 continue # Update the timestamp (convert to ZG millisec format) h = result.groups() timestamp = int(h[0]) * 1000 # Append the system call to our syscall list. Note that # we do something odd with the timestamp: because PL # only logs at second precision, a lot of system calls # have the same timestamp, which causes the EventStore # to sort them in the wrong order. So, every time we # have a timestamp identical to the previous one, we # increase a counter that sorts them. This works under # the assumption that there are at most 1000 events per # second. if timestamp == prevTimestamp: timeDelta += 1 else: timeDelta = 0 # Process the last system call into an Event, and clear # up the syscalls list to keep RAM free! if currentCall: event = Event(actor=app, time=currentCall[0], syscallStr=currentCall[1]) app.addEvent(event) eventCount += 1 # Create the new syscalls list. currentCall = (timestamp + timeDelta, h[1]) prevTimestamp = timestamp lineIdx += 1 # Add the found process id to our list of actors, using the # app identity that was resolved by the Application ctor actors.add(app.desktopid) if checkInitialised and not app.isInitialised(): print("MISSING: %s" % g[0], file=sys.stderr) hasErrors = True # Insert into the ApplicationStore if one is available if store is not None: store.insert(app) instanceCount += 1 if checkInitialised and hasErrors: if invalidApps: print("Invalid apps:", file=sys.stderr) for a in sorted(invalidApps): print("\t%s" % a, file=sys.stderr) sys.exit(-1) # print("Apps that logged valid files:") # for act in sorted(actors): # print(act) # print("\nApps that logged files without a single system call:") # for act in sorted(nosyscallactors): # print(act) self.appCount = len(actors) self.instCount = count - empties - invalids - len(nosyscalls) self.eventCount = eventCount self.validEventRatio = 100 - 100 * (invalids + empties + len(nosyscalls)) / (count) print("Finished loading DB.\n%d files seen, %d valid from %d apps, " "%d empty files, " "%d logs with 0 syscalls from %d apps, " "%d invalid.\nIn " "total, %.02f%% files processed." % (count, self.instCount, self.appCount, empties, len(nosyscalls), len(nosyscallactors), invalids, self.validEventRatio)) print("Instance count: %d" % instanceCount)
def loadDb(self, store: ApplicationStore = None): """Browse the SQLite db and create all the relevant app instances.""" # Load up our events from the Zeitgeist database self.cur = self.con.cursor() self.cur.execute('SELECT * \ FROM event_view \ WHERE id IN (SELECT DISTINCT id \ FROM event_view \ WHERE subj_uri LIKE "activity://%")') # Merge all event subjects based on their event id, and find their pids eventsMerged = dict() data = self.cur.fetchone() while data: pid = 0 if "pid://" in data[EV_SUBJ_URI]: m = re.search('(?<=pid://)\d+', data[EV_SUBJ_URI]) pid = int(m.group(0)) if m else 0 ev = eventsMerged.get(data[EV_ID]) if not ev: ev = SqlEvent(id=data[EV_ID], pid=pid, timestamp=data[EV_TIMESTAMP], interpretation=self.getInterpretation( data[EV_INTERPRETATION]), manifestation=self.getManifestation( data[EV_MANIFESTATION]), origin_uri=data[EV_EVENT_ORIGIN_URI], actor_uri=data[EV_ACTOR_URI]) elif pid and ev.pid: assert ev.pid == pid, ("Error: multiple events record a pid " " event %d, and they disagree on the " "pid to record (%d != %d)." % ( data[EV_ID], ev.pid, pid)) elif pid and not ev.pid: ev.pid = pid subj = SqlEventSubject(uri=data[EV_SUBJ_URI], interpretation=self.getInterpretation( data[EV_SUBJ_INTERPRETATION]), manifestation=self.getManifestation( data[EV_SUBJ_MANIFESTATION]), origin_uri=data[EV_SUBJ_ORIGIN_URI], mimetype=self.getMimeType( data[EV_SUBJ_MIMETYPE]), text=data[EV_SUBJ_TEXT], storage_uri=data[EV_SUBJ_STORAGE], current_uri=data[EV_SUBJ_CURRENT_URI]) ev.addSubject(subj) eventsMerged[data[EV_ID]] = ev data = self.cur.fetchone() # Now, sort the events per app PID so we can build apps nopids = [] # Matching events without a PID eventsPerPid = dict() # Storage for our events count = len(eventsMerged) # Counter of fetched events, for stats instanceCount = 0 # Count of distinct app instances in the dataset actors = set() for event in eventsMerged.items(): pid = event[1].pid if not pid: nopids.append(event[1]) else: try: eventsPerPid[pid].append(event[1]) except KeyError as e: eventsPerPid[pid] = [event[1]] del eventsMerged # no longer needed # For each PID, we'll now identify the successive Application instances for (pkey, pevent) in eventsPerPid.items(): pevent = sorted(pevent, key=lambda x: x.timestamp) currentId = '' # currently matched Desktop Id currentApp = None # currently matched Application apps = [] # temp storage for found Applications for ev in pevent: (evId, __) = Application.getDesktopIdFromDesktopUri( ev.actor_uri) if evId != currentId: if debugEnabled(): print ("New application:", evId, currentId, ev) currentId = evId currentApp = Application(desktopid=evId, pid=int(pkey), tstart=ev.timestamp, tend=ev.timestamp) actors.add(currentApp.desktopid) apps.append(currentApp) else: currentApp.setTimeOfStart(min(ev.timestamp, currentApp.getTimeOfStart())) currentApp.setTimeOfEnd(max(ev.timestamp, currentApp.getTimeOfEnd())) # Ignore study artefacts! if not currentApp.isStudyApp(): event = Event(actor=currentApp, time=ev.timestamp, zgEvent=ev) currentApp.addEvent(event) # Insert into the ApplicationStore if one was given to us instanceCount += len(apps) if store is not None: for app in apps: # Ignore study artefacts! if not app.isStudyApp(): store.insert(app) else: instanceCount -= 1 # We discount this app instance self.appCount = len(actors) self.instCount = instanceCount self.eventCount = count self.validEventRatio = 100-100*len(nopids) / count print("Finished loading DB.\n%d events seen, %d normal, %d without a " "PID.\nIn total, %.02f%% events accepted." % ( count, count-len(nopids), len(nopids), self.validEventRatio)) print("Instance count: %d" % self.instCount)