ProcessPools.py

'''
This file contains the Manager Classes which handle the parts of Update process:
extracting from cab files, updating the database and searching for symbols
'''
#***************************************
# Imports
#***************************************
import queue

import os

from time import time

import threading

import subprocess

import traceback as tb

import logging, logging.handlers

import re

from concurrent.futures import ProcessPoolExecutor

from pathlib import Path

from shutil import rmtree

import globs

import BamLogger

from db import wsuse_db

from support.utils import validatecab, ispe, validatezip, \
    getfilehashes, ispebuiltwithdebug, pebinarytype, getpepdbfilename, \
    getpeage, getpearch, getpesigwoage, ispedbgstripped, rmfile

from dependencies.pefile import pefile



#****************************************************
# Local Variables
#****************************************************
_mgrlogger = logging.getLogger("BAM.Pools")

def mgr_logconfig(queue):
    global _mgrlogger

    qh = logging.handlers.QueueHandler(queue)
    _mgrlogger.addHandler(qh)
    _mgrlogger.setLevel(logging.INFO)

def wkr_logconfig(queue, logger):
    parent = logger
    qh = logging.handlers.QueueHandler(queue)
    fh = logging.Formatter("[%(process)d][Thread %(thread)d] %(message)s")
    qh.setFormatter(fh)
    parent.addHandler(qh)
    parent.setLevel(logging.INFO)

#****************************************************
# Classes
#****************************************************
class ExtractMgr(threading.Thread):
    '''
    pdir - directory to cab files to be extracted
    dest - directory to place extracted results
    poolsize - number of processes to spawn and keep track of
    cleaner - CleanMgr to pass results to
    db - DBMgr for which to refer database write jobs to
    '''
    def __init__(self, pdir, dest, poolsize, cleaner, db, local, globqueue):
        super(ExtractMgr, self).__init__()
        self.pdir = pdir
        self.dest = dest
        self.poolsize = poolsize
        self.cleaner = cleaner
        self.dbc = db
        # jobs - a list of cab files that have not been distributed to worker processes
        self.jobs = []
        # workRemaining - the amount of work that is not complete, which is not strictly the
        # same as the length of the jobs list, since work remaining includes jobs taken off
        # of the list to be worked on by processes
        self.workremaining = 0
        # jobsincoming - an event to signal to the ProcessPoolExecutor that more jobs have
        # been added to the jobs list
        self.jobsincoming = threading.Event()
        self.localaction = local
        self.globqueue = globqueue
        self.extmgrlogger = logging.getLogger("BAM.Pools.ExMgr")
        

    def addq(self, taskpath):
        '''
        adds item to job list from which the manager will task workers with
        '''
        self.jobs.append(taskpath)
        self.jobsincoming.set()
        self.workremaining += 1

    def passresult(self, future):
        '''
        takes future generated by executor process and passes result to
        cleaner
        '''
        # if exception generated by extracttask, notify here. If not, get result and send to
        # cleaner
        fexception = future.exception()
        if fexception is not None:
            self.extmgrlogger.log(logging.ERROR, "[EXMGR] {-} exception occurred: " + str(fexception) + \
                "\n\ttraceback: " + tb.format_exc())
        else:
            job = future.result()
            if job is not None:
                # if the directory contains ncabdir, then we
                # know that it is already a nestedCab, so remove
                # it from deliverables, otherwise, send to DBMgr
                ncabdir = self.pdir + "\\nestedCabs"
                if ncabdir in job[0][0]:
                    self.extmgrlogger.log(logging.DEBUG, "[EXMGR] found nested cab, not adding to database")
                else:
                    self.dbc.addtask("update", job[0], job[1], job[2], None)

                if self.cleaner is not None:
                    self.cleaner.receivejobset(job[0][0])
                    self.extmgrlogger.log(logging.DEBUG, "[EXMGR] sent to cleaner: " + str(job[0][0]))
                else:
                    self.extmgrlogger.log(logging.DEBUG, "[EXMGR] no jobs passed to cleaner")
            else:
                self.extmgrlogger.log(logging.DEBUG, "[EXMGR] job did not contain patched binaries or additional updates")

        # if there are no more nested cabs, set the jobs incoming event to allow thread to
        # complete execution
        self.workremaining -= 1
        self.extmgrlogger.log(logging.DEBUG, "[EXMGR] work remaining: " + str(self.workremaining))
        if self.workremaining == 0:
            self.jobsincoming.set()

    def requeuetask(self, future):
        '''
        if extraction yielded additional cabs, add those tasks back into job list
        '''
        job = future.result()
        if job is not None:
            if job[0][1]:
                for task in job[0][1]:
                    self.addq(task)

    def run(self):
        '''
        ExtractMgr finds all cab files in target directory and adds to jobslist.
        Then assigns jobslist items to worker processes which handle extraction/DB update.
        Finally receives results back from workers, requeues nested cabs if any,
        and passes results to cleaner.
        '''
        start = time()
        self.extmgrlogger.log(logging.INFO, "[EXMGR] starting ExMgr")
        # search for and add cab files to task queue
        for root, dummy, files, in os.walk(self.pdir):
            for file in files:
                filel = file.lower()
                if filel.endswith(".cab") or filel.endswith(".msu") \
                    or filel.endswith(".exe"):
                    self.addq(os.path.join(root, file))

        # don't wait for results to pile up, task workers and send off to cleaner
        # and dbc as they come in.
        global _mgrlogger
        with ProcessPoolExecutor(max_workers=self.poolsize, initializer=wkr_logconfig, initargs=(self.globqueue, _mgrlogger)) as executor:
            while self.workremaining > 0:
                if not self.jobs:
                    self.extmgrlogger.log(logging.DEBUG, "[EXMGR] waiting for more extraction jobs. Current jobs:"    \
                            + str(self.workremaining))
                    self.jobsincoming.wait()
                while self.jobs:
                    self.extmgrlogger.log(logging.DEBUG, "[EXMGR] assigning extraction job")
                    if self.localaction:
                        future = executor.submit(self.dbupdate, self.jobs.pop(), \
                                                 self.dest)
                    else:
                        future = executor.submit(self.extracttask, self.jobs.pop(), \
                                                 self.pdir, self.dest)
                    self.extmgrlogger.log(logging.DEBUG, "[EXMGR] jobs left: " + str(len(self.jobs)) + " " + \
                           "workremaining " + str(self.workremaining))
                    future.add_done_callback(self.requeuetask)
                    future.add_done_callback(self.passresult)

                self.jobsincoming.clear()
            # ensure that executor and all futures shut down properly
            executor.shutdown(wait=True)

        self.extmgrlogger.log(logging.INFO, "[EXMGR] **************part 1 done**********************")
        print("[EXMGR] **************part 1 done**********************")

        if self.cleaner is not None:
            self.cleaner.donesig()
        self.extmgrlogger.log(logging.DEBUG, "[EXMGR] done signal sent to cleaner")
        self.dbc.donesig()

        end = time()
        elapsed = end-start
        print("elapsed time for part 1: " + str(elapsed))


    @staticmethod
    def verifyentry(src, sha256, sha1, logger):
        '''
        verify DB entry
        '''
        logmsg = "[EXMGR] Verifying entry for " + src
        logger.log(logging.DEBUG, logmsg)

        filepath = None

        try:
            filepath = str(Path(src).resolve())
        except OSError as error:
            logmsg = "[EXMGR] Issue getting full path for " + src + ": " + str(error) + ". Using unresolved path."
            logger.log(logging.ERROR, logmsg)
            filepath = src

        if wsuse_db.dbentryexist(globs.DBCONN.cursor(),     \
                                globs.UPDATEFILESDBNAME, sha256, sha1):
            logmsg = "[EXMGR] {-} item " + filepath + " already exists in db, skipping"
            logger.log(logging.WARNING, logmsg)
            return True
        return False

    @staticmethod
    def performcablisting(src, logger):
        '''
        Call expand.exe to get a listing of files within a CAB/MSU
        '''
        result = None
        logmsg = "[EXMGR] Listing " + str(src) + " CAB contents"
        logger.log(logging.DEBUG, logmsg)

        filepath = os.environ['systemdrive'] + "\\Windows\\system32\\expand.exe"

        if not os.path.isfile(filepath):
            logmsg = "[EXMGR] {-} expand.exe was not found. Given path: " + filepath
            logger.log(logging.ERROR, logmsg)
            return None

        args = filepath + " -D \"" + str(src) + "\""

        try:
            with subprocess.Popen(args, shell=False, stdout=subprocess.PIPE) as pexp:
                result, dummy = pexp.communicate()
        except subprocess.CalledProcessError as error:
            logmsg = "[EXMGR] {-} Listing contents of " + src + \
                   " failed with " + str(error.returncode) + " " +  \
                   str(error.stderr)
            logger.log(logging.ERROR, logmsg)
            result = None
        except FileNotFoundError as error:
            logmsg = ("[EXMGR] {-} expand.exe not found")
            logger.log(logging.ERROR, logmsg)
            result = None

        return result

    @staticmethod
    def performcabextract(extstr, src, newdir, logger):
        '''
        Call expand.exe to extract files (if any)
        https://support.microsoft.com/en-us/help/928636/you-cannot-extract-the-contents-of-a-microsoft-update-standalone-packa
        https://blogs.msdn.microsoft.com/astebner/2008/03/11/knowledge-base-article-describing-how-to-extract-msu-files-and-automate-installing-them/
        '''
        result = None
        args = os.environ['systemdrive'] + "\\Windows\\system32\\expand -R \"" + str(src) + "\" -F:" + str(extstr) + " \"" + str(newdir) + "\""
        try:
            with subprocess.Popen(args, shell=False, stdout=subprocess.PIPE) as pexp:
                rawstdout, dummy = pexp.communicate()
                result = rawstdout.decode("ascii")
            logmsg = "[EXMGR] extracted " + extstr + " at " + newdir
            logger.log(logging.DEBUG, logmsg)
        except subprocess.CalledProcessError as error:
            logmsg = "[EXMGR] {-} extracting " + extstr + " from " + src +    \
                    " failed with " + str(error.returncode) + " " +  \
                    error.output.decode('ascii') + ".\n\n" + \
                    "{-} cmd (" + str(error.cmd) + ") stderr (" + \
                    str(error.stderr) + ")"
            logger.log(logging.ERROR, logmsg)
            result = None
        except FileNotFoundError as error:
            logmsg = ("[EXMGR] {-} expand.exe not found")
            logger.log(logging.ERROR, logmsg)
            result = None

        return result

    @staticmethod
    def perform7zextract(src, newpath, logger):
        '''
        Call 7z.exe to extract files (if any)
        '''
        result = None
        logmsg = "[EXMGR] Performing 7z on " + newpath
        logger.log(logging.DEBUG, logmsg)
        filepath = os.environ["PROGRAMW6432"] + "\\7-Zip\\7z.exe"
        
        if not os.path.isfile(filepath):
            logmsg = "[EXMGR] {-} 7z.exe was not found. Given path: " + filepath
            logger.log(logging.ERROR, logmsg)
            return None

        args =  filepath + " x -aoa -o\"" + str(newpath) + "\" -y -r \"" +str(src) + "\" *.dll *.sys *.exe"

        try:
            with subprocess.Popen(args, shell=False, stdout=subprocess.PIPE) as p7z:
                result, dummy = p7z.communicate()
        except subprocess.CalledProcessError as error:
            logmsg = "[EXMGR] {-} extracting, using 7z, from " + src + \
                     " failed with " + str(error.returncode) + " " +  \
                     error.output.decode('ascii')
            logger.log(logging.ERROR, logmsg)
            result = None
        except FileNotFoundError as error:
            logmsg = ("[PBSK] {-} 7z.exe not found")
            logger.log(logging.ERROR, logmsg)
            result = None
        
        return result

    @classmethod
    def dbupdate(cls, src, pdestdir):
        '''
        when given a directory of updates (CABs/MSUs/ZIPs)
        and no extraction, only set up update files to be added to dbc.
        Destination is where patched files are.
        '''
        extlogger = logging.getLogger("BAM.Pools.ExWkr")
        
        logmsg = "[EXMGR][DBUP] starting on " + str(src)
        extlogger.log(logging.DEBUG, logmsg)

        # initialize deliverables
        deliverables = None
        newpath = ''

        # indicates that this cab is one of the new update version that MS started using for v1809 and forward
        # can't handle this type of update yet, so skip it.
        if "PSFX" in src or "psfx" in src:
            return deliverables

        hashes = getfilehashes(src)

        if hashes is None:
            return hashes

        if not (validatecab(str(src)) or ispe(str(src)) or validatezip(str(src))):
            logmsg = "[EXMGR][DBUP] invalid cab/pe/zip"
            extlogger.log(logging.ERROR, logmsg)
            return deliverables

        newname = src.split("\\")[-1].lstrip()
        newpath = pdestdir + "\\" + newname

        if ".exe" in newname:
            newpath = newpath.split(".exe")[0]
        elif ".cab" in newname:
            newpath = newpath.split(".cab")[0]
        elif ".zip" in newname:
            newpath = newpath.split(".zip")[0]

        deliverables = ((newpath, []), hashes[0], hashes[1])
        # No need to locate nested CABs/MSUs as long the parent update file
        # is found. Revisit if needed

        logmsg = "[EXMGR][DBUP] Extraction (DB update only) task completed for " + src
        extlogger.log(logging.DEBUG, logmsg)

        # Send the job to the next manager (DB will be updated eventually)
        return deliverables

    @classmethod
    def extracttask(cls, src, pdir, dst):
        '''
        task for workers to extract contents of .cab file and return
        directory of result to for use by cleaner
        '''
        extlogger = logging.getLogger("BAM.Pools.ExWkr")

        hashes = getfilehashes(src)

        if hashes is None:
            return hashes

        entryexists = False
        if cls.verifyentry(src, hashes[0], hashes[1], extlogger):
            entryexists = True

        logmsg = "[EXMGR] started on " + str(src) + " extracting files to " + str(dst)
        extlogger.log(logging.DEBUG, logmsg)

        # initialize deliverables
        deliverables = None

        # indicates that this cab is one of the new update version that MS started using for v1809 and forward
        # can't handle this type of update yet, so skip it.
        if "PSFX" in src or "psfx" in src:
            return deliverables

        newname = src.split("\\")[-1].lstrip()

        # If the files being worked on is a PE file
        # see if it can be opened with 7z.exe and that
        # it has PE files. Otherwise, skip to other
        # update files.
        if ispe(src):
            logmsg = "[EXMGR] extracting PE file (" + src + ")..."
            extlogger.log(logging.DEBUG, logmsg)

            newdir = (dst + "\\" + newname).split(".exe")[0]
            try:
                os.mkdir(newdir)
            except FileExistsError:
                pass
            except OSError as oserror:
                logmsg = "[EXMGR] OSError creating new directory... skipping extraction for (" + \
                    src + "). Error: " + str(oserror)
                extlogger.log(logging.ERROR, logmsg)
                return deliverables

            if not entryexists and cls.perform7zextract(src, newdir, extlogger) is None:
                return deliverables

            deliverables = ((newdir, []), hashes[0], hashes[1])

            # if nothing was extracted, remove the directory to clean up
            try:
                os.rmdir(newdir)
            except OSError:
                pass
        else:
            if not validatecab(str(src)):
                logmsg = "[EXMGR] {-} invalid file: " + src
                extlogger.log(logging.ERROR, logmsg)
                return None

            # make new directory to hold extracted files
            newdir = ""
            # if this is true, this must be a nested cab file
            if dst in src:
                newdir = str(os.path.dirname(src))
            # otherwise the cab is brand new and should create a newdir in dst
            else:
                if ".cab" in newname:
                    newdir = (dst + "\\" + newname).split(".cab")[0]
                elif ".msu" in newname:
                    newdir = (dst + "\\" + newname).split(".msu")[0]

            try:
                os.mkdir(newdir)
            except FileExistsError:
                pass
            except OSError as oserror:
                logmsg = "[EXMGR] OSError creating new directory... skipping extraction for (" + \
                    src + "). Error: " + str(oserror)
                extlogger.log(logging.ERROR, logmsg)
                return deliverables                

            if not entryexists:
                # extract .dll, .exe and .sys first
                cls.performcabextract("*.dll", src, newdir, extlogger)
                cls.performcabextract("*.exe", src, newdir, extlogger)
                cls.performcabextract("*.sys", src, newdir, extlogger)

            deliverables = ((newdir, []), hashes[0], hashes[1])

            # search through rest of .cab for nested cabs or msus to extract
            # again
            if not entryexists:
                listing = cls.performcablisting(src, extlogger)

                if listing is None:
                    return deliverables

                stroutput = listing.decode("ascii").split("\r\n")

                # indicates that this cab is one of the new update version that MS started using for v1809 and forward
                # can't handle this type of update yet, so skip it.
                if "psfx" in stroutput[3] or "PSFX" in stroutput[4]:
                    return deliverables

                for line in stroutput:
                    if line.endswith(".cab") or line.endswith(".msu"):

                        # expand that line only to start another thread on it
                        potentialfile = line.split(":")[-1].lstrip()

                        # make a new directory to store the nested cab
                        # nested cabs with the same name may exists, keep contents
                        # under the newly created extracted directory for update
                        parentdir = src.split("\\")[-1][0:-4]
                        ncabdir = str(dst) + "\\" + str(parentdir) + "\\" + str(potentialfile)[0:-4]

                        if not os.path.exists(ncabdir):
                            try:
                                os.mkdir(ncabdir)
                                ncabdir = Path(ncabdir).resolve()

                            except OSError as error:
                                logmsg = "[EXMGR] {-} unable to make nested cab directory: " + str(error)
                                extlogger.log(logging.ERROR, logmsg)
                                break

                        logmsg = "[EXMGR] beginning extraction of nestedcab: " + str(src)
                        extlogger.log(logging.DEBUG, logmsg)
                        extractstdout = cls.performcabextract(potentialfile, src, str(ncabdir), extlogger)

                        if extractstdout is not None:
                            # Case where there exists nested cabs with a .manifest file
                            newpath = None
                            for root, dummy, cabs in os.walk(ncabdir):
                                for cab in cabs:
                                    if str(cab) == potentialfile:
                                        newpath = Path(os.path.join(root, cab)).resolve()
                                        break

                            if newpath is None:
                                continue

                            # if file is not a cab/msu, remove it since that's all we're interested
                            # in at this point
                            if not validatecab(str(newpath)):
                                logmsg = "[EXMGR] {-} extracttask: " + str(newpath) + " extracted from " + str(src) +  " is not a validate cab"
                                extlogger.log(logging.ERROR, logmsg)

                                logmsg = "[EXMGR] extracttask: Removing " + str(newpath)
                                extlogger.log(logging.ERROR, logmsg)

                                rmfile(newpath)

                                continue

                            logmsg = "[EXMGR] Creating " + str(newpath) + " for new thread..."
                            extlogger.log(logging.DEBUG, logmsg)

                            # return new location of extracted cab for addition to job queue
                            deliverables[0][1].append(str(newpath))

        logmsg = "[EXMGR] Extraction task completed for " + src
        extlogger.log(logging.DEBUG, logmsg)
        return deliverables


class CleanMgr(threading.Thread):
    '''
    after extraction is complete sorts through collected files and removes those that
    are already in the database. Finally passes remaining files to SymMgr for Symbol
    collection.
    poolsize - number of worker processes to spawn
    symmgr - SymbolMgr to pass results to
    db - DBMgr for which to refer database write jobs to
    '''
    def __init__(self, poolsize, symmgr, db, globqueue):
        super(CleanMgr, self).__init__()
        self.poolsize = poolsize
        self.symmgr = symmgr
        self.dbc = db
        self.globqueue = globqueue
        # jobs - holds the paths to the directories containing binaries to sort and
        # clean up
        self.jobs = []
        # jobsready is an event to indicate that ExtractMgr has job items ready
        self.jobsready = threading.Event()
        # alldone is a signal to indicate that ExtractMgr has completed and will not send
        # any more jobs over
        self.alldone = False
        self.clnmgrlogger = logging.getLogger("BAM.Pools.ClnMgr")

    def receivejobset(self, cleaningjobs):
        '''
            receive jobs from ExtractMgr, add those jobs to jobs List, and set
        the jobsready Event to indicate there are jobs waiting to be
        processed
        '''
        self.jobs.append(cleaningjobs)
        self.jobsready.set()

    def donesig(self):
        '''
        Used to notify that there are no more jobs coming in from ExtractMgr
        so the last batch of work should proceed
        '''
        self.alldone = True
        self.jobsready.set()

    def passresult(self, future):
        '''
        takes a future generated by the executor and passes result over to
        SymbolMgr for processing. Since result is guaranteed to be new to DB
        at this point, also submits result to DBMgr to update DB
        '''
        fexception = future.exception()
        if fexception is not None:
            self.clnmgrlogger.log(logging.ERROR, "[CLNMGR] {-} exception occurred: " + str(fexception) + \
            "\n\ttraceback: " + tb.format_exc())
        else:
            result = future.result()
            if result is not None:
                if result[3]["builtwithdbginfo"] and self.symmgr is not None:
                    # only need to use verify if PE was builtwithdbginfo here because 
                    # that condition takes precedence over the stripped condition and 
                    # if the item is stripped, a check must be made by symchk anyway 
                    # to find the .dbg file.
                    # Reference:
                    # https://docs.microsoft.com/en-us/windows-hardware/drivers
                    # /debugger/symchk-command-line-options
                    # in the DBG file options.
                    jobitem = (str(result[0][0]), result[1], result[2])
                    self.symmgr.receivejobset(jobitem)
                    self.clnmgrlogger.log(logging.DEBUG, "[CLNMGR] items passed to symmgr: " + str(result[0][0]))

                self.dbc.addtask("binary", result[0], result[1], result[2], result[3])

    def run(self):
        '''
        spawns, manages, and tasks workers to perform cleaning functionalities
        '''
        self.clnmgrlogger.log(logging.DEBUG, "[CLNMGR] ClnMgr starting")
        start_time = time()
        # setup workers and Executor
        global _mgrlogger
        with ProcessPoolExecutor(max_workers=self.poolsize, initializer=wkr_logconfig, initargs=(self.globqueue, _mgrlogger)) as executor:
            while not self.alldone:
                if not self.jobs:
                    self.clnmgrlogger.log(logging.DEBUG, "[CLNMGR] waiting for more cleaning jobs")
                    self.jobsready.wait()

                # take item from jobs and assign it to a worker
                while self.jobs:
                    jobdir = self.jobs.pop(0)
                    for root, dummy, files in os.walk(jobdir):
                        for file in files:
                            filepath = Path(os.path.join(root, file)).resolve()
                            self.clnmgrlogger.log(logging.DEBUG, "[CLNMGR] assigning cleaning job for " + str(filepath))
                            
                            updateid = re.search("([A-F0-9]{40})", str(filepath)).group(1)

                            future = executor.submit(self.cleantask, str(filepath), updateid)
                            future.add_done_callback(self.passresult)

                self.jobsready.clear()

                self.clnmgrlogger.log(logging.DEBUG, "[CLNMGR] items left in cleanmgr queue: " + str(len(self.jobs)))
            # ensure that executor and all futures shut down properly
            executor.shutdown(wait=True)

        self.clnmgrlogger.log(logging.INFO, "[CLNMGR] *************part 2 done*****************")
        print("[CLNMGR] **************part 2 done**********************")

        if self.symmgr is not None:
            self.symmgr.donesig()
        self.clnmgrlogger.log(logging.DEBUG, "[CLNMGR] done signal sent to symmgr")
        self.dbc.donesig()

        endtime = time()
        elapsedtime = endtime-start_time
        print("elapsed time for part 2: " + str(elapsedtime))

    @classmethod
    def cleantask(cls, jobfile, updateid):
        '''
        task to clean up folder before submitting jobs for symbol search
        if item is removed in cleaning, None is returned, else return item
        '''
        clnlogger = logging.getLogger("BAM.Pools.ClnWkr")
        
        results = None

        logmsg = "[CLNMGR] Starting on " + str(jobfile)
        clnlogger.log(logging.DEBUG, logmsg)

        if ispe(jobfile):
            # check db to see if job already exists:
            hashes = getfilehashes(jobfile)

            if hashes is None:
                return hashes

            if wsuse_db.dbentryexistwithsymbols(globs.DBCONN.cursor(),     \
                                globs.PATCHEDFILESDBNAME, hashes[0], hashes[1]):
                # if PE is already in db with symbols obtained,
                # do not retask job to symbol manager, return None instead
                return results
            else:
                pass
                logmsg = "[CLNMGR] continuing forward with " + str(jobfile)
                clnlogger.log(logging.DEBUG, logmsg)

            # getting to this point means item is not in db, may need to come up
            # with case where db needs to update item though
            infolist = {
                    'OriginalFilename': '', 'FileDescription': '', 'ProductName': '',
                    'Comments': '', 'CompanyName': '', 'FileVersion': '',
                    'ProductVersion': '', 'IsDebug': '', 'IsPatched': '',
                    'IsPreReleased': '', 'IsPrivateBuild': '', 'IsSpecialBuild': '',
                    'Language': '', 'PrivateBuild': '', 'SpecialBuild': ''
                    }

            try:
                unpefile = pefile.PE(jobfile, fast_load=True)
            except pefile.PEFormatError as peerror:
                logmsg = "[WSUS_DB] skipping " + str(jobfile) + " due to exception: " + peerror.value
                clnlogger.log(logging.ERROR, logmsg)
                return results

            infolist['fileext'], infolist['stype'] = pebinarytype(unpefile)
            infolist['arch'] = getpearch(unpefile)
            infolist['age'] = getpeage(unpefile)
            infolist['strippedpe'] = ispedbgstripped(unpefile)
            infolist['builtwithdbginfo'] = ispebuiltwithdebug(unpefile)            

            direntires=[ pefile.DIRECTORY_ENTRY['IMAGE_DIRECTORY_ENTRY_DEBUG'],    \
                pefile.DIRECTORY_ENTRY['IMAGE_DIRECTORY_ENTRY_RESOURCE'] ]
            unpefile.parse_data_directories(directories=direntires)
            infolist['pdbfilename'] = getpepdbfilename(unpefile)
            infolist['signature'] = getpesigwoage(unpefile)

            # a PE only have 1 VERSIONINFO, but multiple language strings
            # More information on different properites can be found at
            # https://msdn.microsoft.com/en-us/library/windows/desktop/aa381058
            # https://msdn.microsoft.com/en-us/library/windows/desktop/aa381049
            if getattr(unpefile, "VS_VERSIONINFO", None) is not None and \
                getattr(unpefile, "FileInfo", None) is not None:
                    for fileinfoentries in unpefile.FileInfo:
                        for fileinfoentry in fileinfoentries:
                            if getattr(fileinfoentry, "StringTable", None) is not None:
                                for strtable in fileinfoentry.StringTable:
                                    # Currently only handling unicode en-us
                                    if strtable.LangID[:4] == b'0409' or \
                                            (strtable.LangID[:4] == b'0000' and
                                            (strtable.LangID[4:] == b'04b0' or
                                            strtable.LangID[4:] == b'04B0')):
                                        infolist["Language"] \
                                            = strtable.LangID.decode("utf-8")
                                        for field, value in strtable.entries.items():
                                            dfield = field.decode('utf-8')
                                            dvalue = value.decode('utf-8')
                                            if dfield == "OriginalFilename":
                                                infolist["OriginalFilename"] \
                                                    = dvalue
                                            if dfield == "FileDescription":
                                                infolist["FileDescription"] \
                                                    = dvalue
                                            if dfield == "ProductName":
                                                infolist["ProductName"] \
                                                    = dvalue
                                            if dfield == "Comments":
                                                infolist["Comments"] \
                                                    = dvalue
                                            if dfield == "CompanyName":
                                                infolist["CompanyName"] \
                                                    = dvalue
                                            if dfield == "FileVersion":
                                                infolist["FileVersion"] \
                                                    = dvalue
                                            if dfield == "ProductVersion":
                                                infolist["ProductVersion"] \
                                                    = dvalue
                                            if dfield == "IsDebug":
                                                infolist["IsDebug"] \
                                                    = dvalue
                                            if dfield == "IsPatched":
                                                infolist["IsPatched"] \
                                                    = dvalue
                                            if dfield == "IsPreReleased":
                                                infolist["IsPreReleased"] \
                                                    = dvalue
                                            if dfield == "IsPrivateBuild":
                                                infolist["IsPrivateBuild"] \
                                                    = dvalue
                                            if dfield == "IsSpecialBuild":
                                                infolist["IsSpecialBuild"] \
                                                    = dvalue
                                            if dfield == "PrivateBuild":
                                                infolist["PrivateBuild"] \
                                                    = dvalue
                                            if dfield == "SpecialBuild":
                                                infolist["SpecialBuild"] \
                                                    = dvalue
            # Get the OS this PE is designed towards.
            # Microsoft PE files distributed via Microsoft's Updates typically
            # use the ProductVersion file properties to indicate the OS a specific
            # PE file is built towards.
            # If this is a Microsoft binary, the Product version is typically
            # the OS version it was built towards, but other products this is not
            # necessarily true
            if infolist['ProductName'].find("Operating System") != -1:
                infolist['osver'] = "NT" + infolist['ProductVersion']
            else:
                infolist['osver'] = "UNKNOWN"

            unpefile.close()

            results = ((str(jobfile), updateid), hashes[0], hashes[1], infolist)
        else:
            # if jobfile is not a PE, then check if it's a cab. If not a cab, remove it.
            if not validatecab(str(jobfile)):
                logmsg = "[CLNMGR] cleantask: Removing " + str(jobfile)
                clnlogger.log(logging.DEBUG, logmsg)

                rmfile(jobfile)

                logmsg = "[CLNMGR] " + str(jobfile) + " removed, not PE or cab file"
                clnlogger.log(logging.DEBUG, logmsg)
            else:
                pass
                logmsg = "[CLNMGR] " + str(jobfile) + " is nested cab, skipping"
                clnlogger.log(logging.DEBUG, logmsg)
            return results

        logmsg = "[CLNMGR] completed one cleantask for " + str(jobfile)
        clnlogger.log(logging.DEBUG, logmsg)

        return results


class SymMgr(threading.Thread):
    '''
    poolsize - number of worker processes to spawn
    symserver - Symbol Server with which to refer to when using symchk
    symdest - destination folder for symbols if downloading new symbols
    dbc - DBMgr for which to refer database write jobs to
    '''
    def __init__(self, poolsize, symserver, symdest, db, symlocal=False, globqueue=None):
        super(SymMgr, self).__init__()
        self.poolsize = poolsize
        self.symserver = symserver
        self.symdest = symdest
        self.dbc = db
        self.symlocal = symlocal
        self.globqueue = globqueue
        # jobs - contains the list of files to search for symbols for
        self.jobs = []
        # jobsready - an Event that indicates to SymMgr when jobs are ready
        # for it to process
        self.jobsready = threading.Event()
        # alldone - a signal that indicates to SymMgr when CleanMgr has completed
        # and will not send any more requests
        self.alldone = False
        self.symmgrlogger = logging.getLogger("BAM.Pools.SymMgr")

    def donesig(self):
        '''
        Used to notify that there are no more jobs coming in from CleanMgr
        so the last batch of work should proceed
        '''
        self.alldone = True
        self.jobsready.set()

    def receivejobset(self, job):
        '''
        receive jobs from CleanMgr, add those jobs to jobs List, and set
        the jobsready Event to indicate there are jobs waiting to be
        processed
        '''
        if job is not None:
            self.jobs.append(job)
            self.jobsready.set()

    def makedbrequest(self, future):
        '''
        once Symbols found, submit task to DBMgr to update database with found symbols
        '''
        fexception = future.exception()
        if fexception is not None:
            self.symmgrlogger.log(logging.DEBUG, "[SYMMGR] {-} exception occurred: " + str(fexception) + "\ntraceback: " + \
                tb.format_exc())
        else:
            results = future.result()
            if results is not None:
                self.dbc.addtask("symbol", results[0], results[1], results[2], results[3])
            else:
                self.symmgrlogger.log(logging.DEBUG, "[SYMMGR] no symbols found")

    def run(self):
        '''
        spawns, manages, and tasks workers to perform cleaning functionalities
        '''
        start_time = time()
        # setup workers and Executor
        global _mgrlogger
        with ProcessPoolExecutor(max_workers=self.poolsize, initializer=wkr_logconfig, initargs=(self.globqueue, _mgrlogger)) as executor:
            while not self.alldone:
                if not self.jobs:
                    self.symmgrlogger.log(logging.DEBUG, "[SYMMGR] waiting for more symbols jobs")
                    self.jobsready.wait()

                # take item from jobs and assign to workers
                while self.jobs:
                    self.symmgrlogger.log(logging.DEBUG, "[SYMMGR] assigning symbol job")
                    future = executor.submit(self.symtask, self.jobs.pop(), self.symserver, \
                        self.symdest, self.symlocal)
                    future.add_done_callback(self.makedbrequest)

                self.jobsready.clear()

                self.symmgrlogger.log(logging.DEBUG, "[SYMMGR] items left in symmgr queue: " + str(len(self.jobs)))
            # ensure that executor and all futures shut down properly
            executor.shutdown(wait=True)

        self.symmgrlogger.log(logging.INFO, "[SYMMGR] *************part 3 done*****************")
        print("[SYMMGR] **************part 3 done**********************")

        self.dbc.donesig()

        endtime = time()
        elapsedtime = endtime-start_time
        print("elapsed time for part 3: " + str(elapsedtime))

    @classmethod
    def symtask(cls, jobitem, symserver, symdest, symlocal):
        '''
        perform symbol search for symbols of jobfile. If there are no symbols or symbols found
        are already in db, discard results. Else, return found symbols
        '''
        symlogger = logging.getLogger("BAM.Pools.SymWkr")
        jobfile = jobitem[0]
        hashes = (jobfile[1], jobfile[2])

        result = None
        logmsg = "[SYMMGR].. Getting SYM for (" + str(jobfile) + ")"
        symlogger.log(logging.DEBUG, logmsg)
        servers = ""

        if symlocal:
            servers = " \""+ symdest + "\""
        else:
            servers = "u \"srv*" + symdest + "*" + symserver +"\""

        args = (".\\tools\\x64\\symchk.exe /v \"" + str(jobfile) + "\" /s" + servers + " /od")

        try:
            with subprocess.Popen(args, shell=False, stdout=subprocess.PIPE, stderr=subprocess.PIPE) \
                    as psymchk:
                # communicate used as symchk's output is for one file and
                # is not "large or unlimited"
                pstdout, pstderr = psymchk.communicate()
                stdoutsplit = str(pstdout.decode("ascii")).split("\r\n")
                stderrsplit = str(pstderr.decode("ascii")).split("\r\n")

                logmsg = "[SYMMGR] Attempt to obtain symbols for " + str(jobfile) + " complete"
                symlogger.log(logging.DEBUG, logmsg)

                infolist = {}
                try:
                    unpefile = pefile.PE(jobfile)
                except pefile.PEFormatError as peerror:
                    logmsg = "[WSUS_DB] Caught: PE error " + str(peerror) + ". File: " + jobfile
                    symlogger.log(logging.ERROR, logmsg)
                    return result

                infolist['signature'] = getpesigwoage(unpefile)
                infolist['arch'] = getpearch(unpefile)

                unpefile.close()

                stderrsplit.append(symserver)
                result = ((str(jobfile), stderrsplit, stdoutsplit), hashes[0], hashes[1], infolist)
        except subprocess.CalledProcessError as error:
            logmsg = "[SYMMGR] {-} symchk failed with error: " + str(error) + ". File: " + jobfile
            symlogger.log(logging.ERROR, logmsg)
            result = None
        except FileNotFoundError as error:
            logmsg = ("[SYMMGR] {-} symchk.exe not found")
            symlogger.log(logging.ERROR, logmsg)
            result = None

        logmsg = "[SYMMGR] completed symtask for " + str(jobfile)
        symlogger.log(logging.DEBUG, logmsg)
        return result


class DBMgr(threading.Thread):
    '''
    handles all write transactions to db. other managers needing to write to db will
    submit request to DBmgr which will accept and perform transaction to prevent race
    conditions.
    dbConn - sqlite3 connection to database
    '''
    def __init__(self, exdest,dbconn=None):
        super(DBMgr, self).__init__()
        self.dbconn = dbconn
        # jobqueue - queue to hold database write tasks
        self.jobqueue = queue.Queue()
        # jobsig - event that indicates when there are jobs that are waiting to be processed
        self.jobsig = threading.Event()
        # donecount - used to indicate when there are no more jobs being submit to the DBMgr
        # by any of the other 3 Mgrs. When count is 3, indicates that there are no more jobs
        self.donecount = 0
        self.dbrecordscnt = 0
        self.exdest = exdest
        self.dblogger = logging.getLogger("BAM.Pools.DbMgr")

    def addtask(self, optype, jobtuple, sha256, sha1, infolist):
        '''
        takes results generated from other Mgrs and creates a task which is placed
        in the Queue
        '''
        task = (optype, jobtuple, sha256, sha1, infolist)
        self.jobqueue.put(task)
        self.dblogger.log(logging.DEBUG, "[DBMGR] " + optype + " task added to queue. Queue at " + \
               str(self.jobqueue.qsize()) + " tasks.")
        self.jobsig.set()

    def writeupdate(self, file, sha256, sha1):
        '''
        performs writes to DB for Update files
        should use function in wsuse_db
        '''
        self.dblogger.log(logging.DEBUG, "[DBMGR] writing update for (" + str(file) + ")")
        wsuse_db.writeupdate(file, sha256, sha1, conn=self.dbconn)

    def writebinary(self, file, updateid, sha256, sha1, infolist):
        '''
        performs write updates to db for Binary files
        should use function in wsuse_db
        '''
        self.dblogger.log(logging.DEBUG, "[DBMGR] writing binary for (" + str(file) + ")")
        wsuse_db.writebinary(file, updateid, sha256, sha1, infolist, conn=self.dbconn)

    def writesym(self, file, symchkerr, symchkout, sha256, sha1, infolist):
        '''
        performs write updates to db for Symbol Files
        should use function in wsuse_db
        '''
        self.dblogger.log(logging.DEBUG, "[DBMGR] writing symbol for (" + str(file) + ")")

        wsuse_db.writesymbol(file, symchkerr, symchkout, sha256, sha1, infolist, self.exdest, conn=self.dbconn)

    def donesig(self):
        '''
        When all other Mgrs are done working, set jobsig so DBMgr can handle
        rest of items in queue and complete
        '''
        self.donecount += 1
        if self.donecount >= 3:
            self.jobsig.set()

    def run(self):
        '''
        handles requests from other Mgrs to write to DB
        '''
        self.dblogger.log(logging.DEBUG, "[DBMGR] DBMgr starting")
        start_time = time()

        while self.donecount < 3:
            if self.jobqueue.empty():
                self.dblogger.log(logging.DEBUG, "[DBMGR] waiting for more database jobs")
                self.jobsig.wait()

            # once signal received, take tasks off queue and process
            while not self.jobqueue.empty():

                # For every 5k queries, end transaction, commit, then restart
                # transaction
                self.dblogger.log(logging.DEBUG, "[DBMGR][DBUP] " + str(self.dbrecordscnt) + " records ready...")

                if self.dbrecordscnt == 0:
                    # this case is only ran once
                    print("[DBUP] Restarting limit count")
                    wsuse_db.starttransaction(self.dbconn)
                elif self.dbrecordscnt >= 5000:
                    print("[DBUP] limit to commit hit")
                    wsuse_db.endtransaction(self.dbconn)
                    self.dbrecordscnt = 0

                task = self.jobqueue.get()
                self.dblogger.log(logging.DEBUG, "[DBMGR] assigning database job: " + str(task[0]))

                if task[0] == "update":
                    self.dbrecordscnt += 1
                    self.writeupdate(task[1][0], task[2], task[3])
                elif task[0] == "binary":
                    self.dbrecordscnt += 1
                    self.writebinary(task[1][0], task[1][1], task[2], task[3], task[4])
                elif task[0] == "symbol":
                    self.dbrecordscnt += 1
                    self.writesym(task[1][0], task[1][1], task[1][2], task[2], task[3], task[4])
                else:
                    self.dblogger.log(logging.DEBUG, "[DBMGR] task unrecognized")

                self.dblogger.log(logging.DEBUG, "[DBMGR] task done, queue at " + str(self.jobqueue.qsize()) + " tasks")

                if self.jobsig.is_set():
                    self.jobsig.clear()

        wsuse_db.endtransaction(self.dbconn, True)
        endtime = time()
        elapsedtime = endtime-start_time
        print("elapsed time for part 4: " + str(elapsedtime))
        self.dblogger.log(logging.INFO, "[DBMGR] ****************everything done********************")
        print("[DMMGR] **************everything done**********************")