vmcatcher_cache

#!/usr/bin/env python
import sys
if sys.version_info < (2, 4):
    print "Your python interpreter is too old. Please consider upgrading."
    sys.exit(1)

if sys.version_info < (2, 5):
    import site
    import os.path
    from distutils.sysconfig import get_python_lib
    found = False
    module_dir = get_python_lib()
    for name in os.listdir(module_dir):
        lowername = name.lower()
        if lowername[0:10] == 'sqlalchemy' and 'egg' in lowername:
            sqlalchemy_dir = os.path.join(module_dir, name)
            if os.path.isdir(sqlalchemy_dir):
                site.addsitedir(sqlalchemy_dir)
                found = True
                break
    if not found:
        print "Could not find SQLAlchemy installed."
        sys.exit(1)

from sqlalchemy import create_engine
from sqlalchemy.orm import sessionmaker

import vmcatcher.databaseDefinition as model
import os.path
import logging
import optparse
from vmcatcher.__version__ import version
import vmcatcher
import urllib2
import urllib
import hashlib
import datetime
from hepixvmitrust.vmitrustlib import VMimageListDecoder as VMimageListDecoder
from hepixvmitrust.vmitrustlib import time_format_definition as time_format_definition
from hepixvmitrust.vmitrustlib import file_extract_metadata as file_extract_metadata
import os, statvfs
import shutil
import commands
import uuid
from M2Crypto import  BIO, SMIME, X509
try:
    import simplejson as json
except:
    import json

import urlparse
import subprocess
import time


def uglyUriParser(uri):
    parsedUri = urlparse.urlsplit(uri)
    if isinstance(parsedUri, tuple):
        # We are probably python 2.4
        networklocation = parsedUri[1].split(':')
        hostname = networklocation[0]
        port = ""
        if len (networklocation) > 1:
            port = networklocation[1]
        return { "scheme" : parsedUri[0],
            "path" : parsedUri[2],
            "hostname" : hostname,
            "port" : port,
        }
    if isinstance(parsedUri,urlparse.SplitResult):
        # We are probably python 2.6
        return { "scheme" : parsedUri.scheme,
            "path" : parsedUri.path,
            "hostname" : parsedUri.hostname,
            "port" : parsedUri.port,
        }


class BaseDir(object):
    def __init__(self, directory):
        self.directory = directory
        self.indexFile = "cache.index"
        self.index = {}
        self.indexLoad()
        # self.files = { 'uuid' : { 'sha512' : 'hash', 'message' : 'signed message' , 'date' : }
        self.indexUnknownClear()
        self.log = logging.getLogger("BaseDir")
 
        
    def getFiles(self):
        output = set()
        directoryList = os.listdir(self.directory)
        for item in directoryList:
            if item == self.indexFile:
                continue
            filepath = os.path.join(self.directory,item)
            if os.path.isfile(filepath):
                output.add(item)
        return output

    def indexLoad(self):
        indexFilePath = os.path.join(self.directory,self.indexFile)
        if os.path.isfile(indexFilePath):
            fp = open(indexFilePath,'r')
            lines = fp.read()
            tmp = json.loads(lines)
            if type(tmp) is dict:
                self.index = tmp
        return True

    def indexSave(self):
        self.indexUnknownClear()
        indexFilePath = os.path.join(self.directory,self.indexFile)
        fp = open(indexFilePath,'w')
        fp.write(json.dumps(self.index,sort_keys=True, indent=4))
        fp.flush()
        fp.close()
        return True

    def indexUnknownClear(self):
        allfiles = self.getFiles()
        for filename in allfiles:
            unknown = True
            for uuid in self.index.keys():
                if 'filename' in self.index[uuid].keys():
                    if self.index[uuid]['filename'] == filename:
                        unknown = False
            if unknown:
                filepath = os.path.join(self.directory,filename)
                os.remove(filepath)
    def indexAdd(self,metadata):
        requiredkeys = set(['uuid','sha512','uri','size'])
        metadataKeys = set(metadata.keys())
        if not requiredkeys.issubset(metadataKeys):
            return False
        uuid = metadata['uuid']
        if not uuid in self.index.keys():
            self.index[uuid] = dict(metadata)
            return True
        self.index[uuid].update(metadata)
        return True
    def moveFrom(self,aDir,uuid):
        if not isinstance(aDir,BaseDir):
            self.log.error("not a BaseDir object code error")
            return False
        if not uuid in aDir.index.keys():
            self.log.error("uuid '%s' is not in directory %s" % (aDir, self.directory))
            return False
        origin = os.path.join(aDir.directory,aDir.index[uuid]['filename'])
        destination = os.path.join(self.directory,uuid)
        shutil.move(origin, destination)
        self.index[uuid] = aDir.index[uuid]
        self.index[uuid]['filename'] = uuid
        del aDir.index[uuid]
        return True

class DownloadDir(BaseDir):
    def __init__(self, dir_download):
        BaseDir.__init__(self,dir_download)
        self.log = logging.getLogger("DownloadDir")

    def download(self,uuid):
        if not uuid in self.index.keys():
            self.log.error("Image '%s' is not known" % (uuid))
            return False
        DownLoadTrys = 0
        if u'DownLoadTrys' in self.index[uuid].keys():
            if 'msgHash' in self.index[uuid]['DownLoadTrys'].keys():
                if self.index[uuid]['DownLoadTrys']['msgHash'] == self.index[uuid]['msgHash']:
                    DownLoadTrys = int(self.index[uuid]['DownLoadTrys']['count'])
        if DownLoadTrys >= 5:
            self.log.warning("Image '%s' has failed to download '%s' times, giving up until new image list." % (uuid,DownLoadTrys))
            return False
        self.index[uuid]['DownLoadTrys'] = { 'count' : DownLoadTrys + 1 , 'msgHash' : self.index[uuid]['msgHash'] }
        self.index[uuid]['filename'] = uuid
        self.indexSave()
        if self.index[uuid]['size'] != None:
            stats = os.statvfs(self.directory)
            diskspace = (stats[statvfs.F_BSIZE] * stats[statvfs.F_BAVAIL])
            imagesize = self.index[uuid]['size']
            if imagesize > diskspace:
                self.log.error("Image '%s' is too large at '%s' bytes, available disk space is '%s' bytes." % (uuid,imagesize,diskspace))
                return False
        self.log.info("Downloading '%s'." % (uuid))
        filepath = os.path.join(self.directory,self.index[uuid]['filename'])
        uriParsed = uglyUriParser(self.index[uuid]['uri'])
        unknownTransport = True
        if uriParsed['scheme'] == u'http':
            cmd = "wget -q -O %s %s" % (filepath,self.index[uuid]['uri'])
            rc,output = commands.getstatusoutput(cmd)
            if rc != 0:
                self.log.error("Command '%s' failed with return code '%s' for image '%s'" % (cmd,rc,uuid))
                if len(output) > 0:
                    self.log.info("Output '%s'" % (output))
                os.remove(filepath)
                return False
            unknownTransport = False
        if uriParsed['scheme'] == u'https':
            cmd = "wget -q -O %s %s --no-check-certificate" % (filepath,self.index[uuid]['uri'])
            rc,output = commands.getstatusoutput(cmd)
            if rc != 0:
                self.log.error("Command '%s' failed with return code '%s' for image '%s'" % (cmd,rc,uuid))
                if len(output) > 0:
                    self.log.info("Output '%s'" % (output))
                os.remove(filepath)
                return False
            unknownTransport = False
        if uriParsed['scheme'] == u'file':
            shutil.copyfile(uriParsed['path'],filepath)
            unknownTransport = False
        if unknownTransport:
            self.log.error("Unknown transport '%s' for URI for '%s'" % (uriParsed['scheme'],uuid))
            return False
        file_metadata = file_extract_metadata(filepath)
        if file_metadata == None:
            self.log.error("Failed to get metadata for image '%s' at path '%s'." % (uuid,filepath))
            return False
        if file_metadata[u'sl:checksum:sha512'] != self.index[uuid]['sha512']:
            os.remove(filepath)
            self.log.error("Downloaded image '%s' has unexpected sha512." % (uuid))
            self.log.info("Expected sha512 '%s'" % (self.index[uuid]['sha512']))
            self.log.info("Downloaded sha512 '%s'" % (file_metadata[u'sl:checksum:sha512']))
            return False
        if self.index[uuid]['size'] != None:
            if int(file_metadata[u'hv:size']) != int(self.index[uuid]['size']):
                os.remove(filepath)
                self.log.error("Image '%s' is incorrect size." % (uuid))
                return False
        return True

class CacheDir(BaseDir):
    def __init__(self, dir_cache):
        BaseDir.__init__(self,dir_cache)
        self.log = logging.getLogger("CacheDir")
    def getExpired(self,validDict):
        # Takes a dictionary of uuid : sha512 mappings.
        # Returns the file path of all files not matching
        pass

class ExpireDir(BaseDir):
    def __init__(self, dir_cache):
        BaseDir.__init__(self,dir_cache)
        self.log = logging.getLogger("ExpireDir")

    def moveFrom(self,aDir,uuid):
        if not isinstance(aDir,BaseDir):
            self.log.error("not a BaseDir object code error")
            return False
        if not uuid in aDir.index.keys():
            self.log.error("uuid '%s' is not in directory %s" % aDir)
            return False
        idStr = "%s.%s" % (uuid, datetime.datetime.now().strftime("%Y-%m-%d_%H-%M-%S"))
        origin = os.path.join(aDir.directory,aDir.index[uuid]['filename'])
        if not os.path.isfile(origin):
            self.log.error("uuid '%s' referances file '%s' but file does not exist." % (uuid,origin))
            del aDir.index[uuid]
            return False
        destination = os.path.join(self.directory,idStr)
        shutil.move(origin, destination)
        self.index[idStr] = aDir.index[uuid]
        self.index[idStr]['filename'] = idStr
        del aDir.index[uuid]
        return True

class EventObj(object):
    def __init__(self,eventExecutionString):
        self.eventExecutionString = eventExecutionString
        self.env = os.environ
        self.env['VMCATCHER_EVENT_UUID_SESSION'] = str(uuid.uuid1())
        self.log = logging.getLogger("Events")
    def launch(self,env):
        if self.eventExecutionString == None:
            return 0,"",""
        process = subprocess.Popen([self.eventExecutionString], shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE,env=env)
        processRc = None
        handleprocess = True
        counter = 0
        stdout = ''
        stderr = ''
        timeout = 10
        while handleprocess:
            counter += 1
            cout,cerr = process.communicate()
            stdout += cout
            stderr += cerr
            process.poll()
            processRc = process.returncode
            if processRc != None:
                break
            if counter == timeout:
                os.kill(process.pid, signal.SIGQUIT)
            if counter > timeout:
                os.kill(process.pid, signal.SIGKILL)
                processRc = -9
                break
            time.sleep(1)
        return (processRc,stdout,stderr)
    
    def eventProcess(self,EventStr,metadata):
        # Note keys 'sha512', 'uuid','size' are depricated.
        mappingdict = {'sha512' : 'VMCATCHER_EVENT_SL_CHECKSUM_SHA512',
            'uuid' : 'VMCATCHER_EVENT_DC_IDENTIFIER',
            'size' : 'VMCATCHER_EVENT_HV_SIZE',
            'sha512' : 'VMCATCHER_EVENT_SL_CHECKSUM_SHA512',
            # End of depricated options
            'filename' : 'VMCATCHER_EVENT_FILENAME',
            'dc:identifier' : 'VMCATCHER_EVENT_DC_IDENTIFIER',
            'hv:uri' : 'VMCATCHER_EVENT_HV_URI',
            'hv:size' : 'VMCATCHER_EVENT_HV_SIZE',
            'dc:description' : 'VMCATCHER_EVENT_DC_DESCRIPTION',
            'hv:imagelist.dc:identifier' : 'VMCATCHER_EVENT_IL_DC_IDENTIFIER',
            'dc:title' : 'VMCATCHER_EVENT_DC_TITLE',
            'hv:hypervisor' : 'VMCATCHER_EVENT_HV_HYPERVISOR',
            "hv:image.hv:format" : 'VMCATCHER_EVENT_HV_FORMAT',
            'hv:version' : 'VMCATCHER_EVENT_HV_VERSION',
            'sl:arch' : 'VMCATCHER_EVENT_SL_ARCH',
            'sl:comments' : 'VMCATCHER_EVENT_SL_COMMENTS',
            'sl:os' : 'VMCATCHER_EVENT_SL_OS',
            'sl:osversion' : 'VMCATCHER_EVENT_SL_OSVERSION',
            'sl:checksum:sha512' : 'VMCATCHER_EVENT_SL_CHECKSUM_SHA512'}
        newEnv = self.env
        newEnv['VMCATCHER_EVENT_TYPE'] = EventStr
        for key in mappingdict.keys():
            if key in metadata.keys():
                newEnv[str(mappingdict[key])] = str(metadata[key])
        
        rc,stdout,stderr = self.launch(newEnv)
        if rc == 0:
            self.log.debug("event '%s' executed '%s'" % (newEnv['VMCATCHER_EVENT_TYPE'],self.eventExecutionString))
            self.log.debug("stdout=%s" % (stdout))
            self.log.debug("stderr=%s" % (stderr))
        else:
            self.log.error("Event '%s' executed '%s' with exit code '%s'." % (newEnv['VMCATCHER_EVENT_TYPE'],self.eventExecutionString,rc))
            self.log.info("stdout=%s" % (stdout))
            self.log.info("stderr=%s" % (stderr))
        return
    def eventAvailablePrefix(self,metadata):
        self.eventProcess("AvailablePrefix",metadata)
    def eventAvailablePrefix(self,metadata):
        self.eventProcess("AvailablePrefix",metadata)
    def eventAvailablePostfix(self,metadata):
        self.eventProcess("AvailablePostfix",metadata)
    def eventExpirePrefix(self, metadata):
        self.eventProcess("ExpirePrefix",metadata)
    def eventExpirePosfix(self, metadata):
        self.eventProcess("ExpirePosfix",metadata)
    def eventProcessPrefix(self, metadata):
        self.eventProcess("ProcessPrefix",metadata)
    def eventProcessPostfix(self, metadata):
        self.eventProcess("ProcessPostfix",metadata)
        
class CacheMan(object):
    def __init__(self,database,dblog ,dir_cache, dir_partial, dir_expired):
        self.log = logging.getLogger("CacheMan")
        self.engine = create_engine(database, echo=dblog)
        model.init(self.engine)
        self.SessionFactory = sessionmaker(bind=self.engine)
        self.Session = self.SessionFactory()
        self.cacheDir = CacheDir(dir_cache)
        self.DownloadDir = DownloadDir(dir_partial)
        self.ExpireDir = ExpireDir(dir_expired)
        self.callbackEventExpirePrefix = None
        self.callbackEventExpirePostfix = None
        self.callbackEventAvailablePrefix = None
        self.callbackEventAvailablePostfix = None

    def checkSumCache(self):
        self.cacheDir.indexUnknownClear()
        uuid2del = set()
        for uuid in self.cacheDir.index.keys():
            filename = self.cacheDir.index[uuid]['filename']
            filepath = os.path.join(self.cacheDir.directory,filename)
            file_metadata = file_extract_metadata(filepath)
            if file_metadata == None:
                uuid2del.add(uuid)
                continue
            MatchingUuid = None
            if int(file_metadata[u'hv:size']) != int(self.cacheDir.index[uuid]['size']):
                self.log.error("Image '%s' size incorrect." % (uuid))
                uuid2del.add(uuid)
                continue
            if file_metadata[u'sl:checksum:sha512'] != self.cacheDir.index[uuid]['sha512']:
                self.log.error("Image '%s' sha512 incorrect." % (uuid))
                uuid2del.add(uuid)
                continue
        # Now we remove files that have been corrupted
        for uuid in uuid2del:
            if 'filename' in self.cacheDir.index[uuid]:
                filepath = os.path.join(self.cacheDir.directory,self.cacheDir.index[uuid]['filename'])
                if os.path.isfile(filepath):
                    os.remove(filepath)
                self.log.error("Image '%s' was corrupted deleting." % (uuid))
            del self.cacheDir.index[uuid]
        return True
    def expire(self):
        rc = True
        self.cacheDir.indexUnknownClear()
        uuids2expire = {}
        for key in self.cacheDir.index.keys():
            uuid = self.cacheDir.index[key]['uuid']
            CachedSha512 = self.cacheDir.index[key]['sha512']
            QueryResults = self.Session.query(model.Subscription,model.ImageDefinition,model.ImageListInstance,model.ImageInstance).\
                filter(model.ImageInstance.sha512 == CachedSha512).\
                filter(model.ImageDefinition.cache == 1).\
                filter(model.ImageDefinition.identifier == uuid).\
                filter(model.ImageDefinition.latest == model.ImageInstance.id).\
                filter(model.ImageDefinition.id == model.ImageInstance.fkIdentifier).\
                filter(model.Subscription.authorised == True).\
                filter(model.Subscription.imagelist_latest == model.ImageListInstance.id).\
                filter(model.ImageDefinition.subscription == model.Subscription.id).\
                filter(model.ImageListInstance.expired == None).\
                filter(model.ImageListInstance.id == model.ImageInstance.fkimagelistinstance)
            if QueryResults.count() != 1:
                uuids2expire[uuid] = self.cacheDir.index[key]
                continue
            dbSub, sbImageDef, DbImageListInst, DbImageInst = QueryResults.one()
            # If the image hash has changed expire old image
            if self.cacheDir.index[key][u'sha512'] != DbImageInst.sha512:
                uuids2expire[uuid] = self.cacheDir.index[key]
                continue
            # Is the size has changed expire old image
            if self.cacheDir.index[key][u'size'] != DbImageInst.size:
                uuids2expire[uuid] = self.cacheDir.index[key]
                continue
            # If the Image list instance has changed then update 
            # Image list instance metadata from DB.
            if DbImageListInst.data_hash != self.cacheDir.index[uuid]['msgHash']:
                self.cacheDir.index[key]['message'] = DbImageListInst.data
                self.cacheDir.index[key]['msgHash'] = DbImageListInst.data_hash
        for uuid in uuids2expire.keys():
            if self.callbackEventExpirePrefix != None:
                self.callbackEventExpirePrefix(uuids2expire[uuid])
            if self.ExpireDir.moveFrom(self.cacheDir,uuid):
                self.log.info("Expired image '%s'" % (uuid))
            else:
                self.log.error("Failed to move file %s to expired directory" % (uuid))
                rc = False
            self.cacheDir.indexSave()
            self.ExpireDir.indexSave()
            if self.callbackEventExpirePostfix != None:
                self.callbackEventExpirePostfix(uuids2expire[uuid])
        return rc
    def download(self):
        downloadsneeded = {}
        QueryResults = self.Session.query(model.Subscription,model.ImageDefinition,model.ImageListInstance,model.ImageInstance).\
                filter(model.ImageDefinition.cache == 1).\
                filter(model.ImageDefinition.latest == model.ImageInstance.id).\
                filter(model.ImageDefinition.id == model.ImageInstance.fkIdentifier).\
                filter(model.ImageListInstance.expired == None).\
                filter(model.Subscription.authorised == True).\
                filter(model.Subscription.imagelist_latest == model.ImageListInstance.id).\
                filter(model.ImageDefinition.subscription == model.Subscription.id).\
                filter(model.ImageListInstance.id == model.ImageInstance.fkimagelistinstance)
        for line in QueryResults:
            sub = line[0]
            imageDef = line[1]
            imageListInst = line[2]
            ImageInst = line[3]
            uuid = imageDef.identifier
            
            details = {'hv:uri' : str(ImageInst.uri),
                    'sl:checksum:sha512' : str(ImageInst.sha512),
                    'hv:size': int(ImageInst.size),
                    'dc:identifier' : uuid,
                    'message' : str(imageListInst.data),
                    'hv:imagelist.dc:identifier' : str(sub.identifier),
                    'msgHash' : str(imageListInst.data_hash),
                    'dc:title' : str(ImageInst.title),
                    'dc:description' : str(ImageInst.description),
                    'hv:hypervisor' : str(ImageInst.hypervisor),
                    'sl:arch' : str(ImageInst.arch),
                    'sl:comments' : str(ImageInst.comments),
                    'sl:os' : str(ImageInst.os),
                    'sl:osversion' : str(ImageInst.osversion),
                    # And now the legacy values
                    'uri' : str(ImageInst.uri),
                    'sha512' : str(ImageInst.sha512),
                    'size': int(ImageInst.size),
                    'uuid' : uuid,
                    }
            
            
            # read message
            
            buf = BIO.MemoryBuffer(str(imageListInst.data))
            sk = X509.X509_Stack()
            p7, data = SMIME.smime_load_pkcs7_bio(buf)
            data_str = data.read()

            try:
                jsonData = json.loads(str(data_str))
            except ValueError:
                self.log.error("proiblem reading JSON")
                continue
            if jsonData == None:
                self.log.error("Downlaoded jsonData was not valid image.")
                continue
            vmilist = VMimageListDecoder(jsonData)
            if vmilist == None:
                self.log.error("Downlaoded metadata from '%s' was not valid image list Object." % (subscriptionKey))
            matchingImage = None
            for image in vmilist.images:
                if "dc:identifier" in image.metadata.keys():
                    if uuid == image.metadata["dc:identifier"]:
                        matchingImage = image
            if matchingImage != None:
                for metafield in matchingImage.metadata.keys():
                    newfield = "hv:image.%s" % (metafield)
                    details[newfield] = matchingImage.metadata[metafield]
            
            if not uuid in self.cacheDir.index.keys():
                downloadsneeded[uuid] = details
                continue
            if self.cacheDir.index[uuid]['sha512'] != str(ImageInst.sha512):
                downloadsneeded[uuid] = details
                continue
        for key in downloadsneeded.keys():
            if not self.DownloadDir.indexAdd(downloadsneeded[key]):
                self.log.error("Failed to add metadata request to download file '%s'." % (key))
                continue
            if not self.DownloadDir.download(key):
                self.log.error("Failed to download file '%s'." % (key))
                self.DownloadDir.indexSave()
                continue
            if self.callbackEventAvailablePrefix != None:
                metadata = {}
                metadata.update(dict(downloadsneeded[key]))
                metadata.update(dict(self.DownloadDir.index[key]))
                #for pkey in  metadata.keys():
                #    print "%s---%s" % (pkey, metadata[pkey])
                self.callbackEventAvailablePrefix(metadata)
            if not self.cacheDir.moveFrom(self.DownloadDir,key):
                self.log.error("Failed to Move file '%s' into the enbdorsed directory." % (key))
                continue
            self.DownloadDir.indexSave()
            self.cacheDir.indexSave()
            self.log.info("moved file %s" % (key))
            if self.callbackEventAvailablePostfix != None:
                metadata = {}
                #metadata.update(dict(ddownloadsneeded[key]))
                metadata.update(dict(self.cacheDir.index[key]))
                self.callbackEventAvailablePostfix(metadata)
        return True


    def load(self):
        self.cacheDir.indexLoad()
        self.DownloadDir.indexLoad()
        self.ExpireDir.indexLoad()
    def save(self):
        self.cacheDir.indexSave()
        self.DownloadDir.indexSave()
        self.ExpireDir.indexSave()

def main():
    """Runs program and handles command line options"""
    p = optparse.OptionParser(version = "%prog " + version)
    p.add_option('-d', '--database', action ='store', help='Database conection string')
    p.add_option('-x', '--execute', action ='store',help='Event application to launch.', metavar='EVENT')
    p.add_option('-C', '--cache-dir', action ='store',help='Set the cache directory.',metavar='DIR_CACHE')
    p.add_option('-p', '--partial-dir', action ='store',help='Set the cache download directory.',metavar='DIR_PARTIAL')
    p.add_option('-e', '--expired-dir', action ='store',help='Set the cache expired directory.',metavar='DIR_EXPIRE')
    p.add_option('-D', '--download', action ='store_true',help='Download subscribed images to cache directory.')
    p.add_option('-s', '--sha512', action ='store_true',help='Check cache directory images Sha512.')
    p.add_option('-E', '--expire', action ='store_true',help='Remove expired images from cache directory.')
    p.add_option('-v', '--verbose', action ='count',help='Change global log level, increasing log output.', metavar='LOGFILE')
    p.add_option('-q', '--quiet', action ='count',help='Change global log level, decreasing log output.', metavar='LOGFILE')
    p.add_option('--log-config', action ='store',help='Logfile configuration file, (overrides command line).', metavar='LOGFILE')
    p.add_option('--log-sql-info', action ='store_true',help='Echo all SQL commands.', metavar='LOGFILE')
    
    options, arguments = p.parse_args()

    dir_cache = None
    dir_partial = None
    dir_expired = None
    actions = set()
    databaseConnectionString = None
    eventExecutionString = None
    logFile = None
    debugSqlEcho = False
    if 'VMCATCHER_RDBMS' in os.environ:
        databaseConnectionString = os.environ['VMCATCHER_RDBMS']
    if 'VMCATCHER_LOG_CONF' in os.environ:
        logFile = os.environ['VMCATCHER_LOG_CONF']
    if 'VMCATCHER_CACHE_DIR_CACHE' in os.environ:
        dir_cache = os.environ['VMCATCHER_CACHE_DIR_CACHE']
    if 'VMCATCHER_CACHE_DIR_DOWNLOAD' in os.environ:
        dir_partial = os.environ['VMCATCHER_CACHE_DIR_DOWNLOAD']
    if 'VMCATCHER_CACHE_DIR_EXPIRE' in os.environ:
        dir_expired = os.environ['VMCATCHER_CACHE_DIR_EXPIRE']
    if 'VMCATCHER_CACHE_EVENT' in os.environ:
        eventExecutionString = os.environ['VMCATCHER_CACHE_EVENT']
    
    if 'VMCATCHER_CACHE_ACTION_DOWNLOAD' in os.environ:
        if os.environ['VMCATCHER_CACHE_ACTION_DOWNLOAD'] == "1":
            actions.add("download")
    if 'VMCATCHER_CACHE_ACTION_CHECK' in os.environ:
        if os.environ['VMCATCHER_CACHE_ACTION_CHECK'] == "1":
            actions.add("sha512")
    if 'VMCATCHER_CACHE_ACTION_EXPIRE' in os.environ:
        if os.environ['VMCATCHER_CACHE_ACTION_EXPIRE'] == "1":
            actions.add("expire")
        
    # Set up log file
    LoggingLevel = logging.WARNING
    LoggingLevelCounter = 2
    if options.verbose:
        LoggingLevelCounter = LoggingLevelCounter - options.verbose
        if options.verbose == 1:
            LoggingLevel = logging.INFO
        if options.verbose == 2:
            LoggingLevel = logging.DEBUG
    if options.quiet:
        LoggingLevelCounter = LoggingLevelCounter + options.quiet
    if LoggingLevelCounter <= 0:
        LoggingLevel = logging.DEBUG
    if LoggingLevelCounter == 1:
        LoggingLevel = logging.INFO
    if LoggingLevelCounter == 2:
        LoggingLevel = logging.WARNING
    if LoggingLevelCounter == 3:
        LoggingLevel = logging.ERROR
    if LoggingLevelCounter == 4:
        LoggingLevel = logging.FATAL
    if LoggingLevelCounter >= 5:
        LoggingLevel = logging.CRITICAL
    
    if options.log_config:
        logFile = options.log_config
    if logFile != None:
        if os.path.isfile(str(options.log_config)):
            logging.config.fileConfig(options.log_config)
        else:
            logging.basicConfig(level=LoggingLevel)
            log = logging.getLogger("main")
            log.error("Logfile configuration file '%s' was not found." % (options.log_config))
            sys.exit(1)
    else:
        
        logging.basicConfig(level=LoggingLevel)
    log = logging.getLogger("main")
    # Now logging is set up process other options
    if options.log_sql_info:
        debugSqlEcho = True
    if options.cache_dir:
        dir_cache = options.cache_dir
    if options.partial_dir:
        dir_partial = options.partial_dir
    if options.expired_dir:
        dir_expired = options.expired_dir
    if options.expire:
        actions.add("expire")
    if options.sha512:
        actions.add("sha512")
    if options.download:
        actions.add("download")
    if options.database:
        databaseConnectionString = options.database
    if options.execute:
        eventExecutionString = options.execute
    # 1 So we have some command line validation

    if databaseConnectionString == None:
        databaseConnectionString = 'sqlite:///vmcatcher.db'
        log.info("Defaulting DB connection to '%s'" % (databaseConnectionString))
    if len(actions) == 0:
        actions.add("download")
        actions.add("expire")
        log.info("Defaulting actions as 'expire', and 'download'.")
    if ("download" in actions) and (not "expire" in actions):
        log.info("Defaulting action 'expire', as 'download' is requested.")
        actions.add("expire")

    if dir_cache == None:
        dir_cache = "cache"
        log.info("Defaulting cache-dir to '%s'." % (dir_cache))

    if dir_partial == None:
        dir_partial = os.path.join(dir_cache,"partial")
        log.info("Defaulting partial-dir to '%s'." % (dir_partial))
    if dir_expired == None:
        dir_expired = os.path.join(dir_cache,"expired")
        log.info("Defaulting expired-dir to '%s'." % (dir_expired))
    directories_good = True
    if not os.path.isdir(dir_cache):
        log.error("Cache directory '%s' does not exist." % (dir_cache))
        directories_good = False
    if not os.path.isdir(dir_partial):
        log.error("Download directory '%s' does not exist." % (dir_partial))
        directories_good = False
    if not os.path.isdir(dir_expired):
        log.error("Expired directory '%s' does not exist." % (dir_expired))
        directories_good = False
    if not directories_good:
        sys.exit(1)


    ThisCacheManager = CacheMan(databaseConnectionString,debugSqlEcho,dir_cache, dir_partial, dir_expired)
    EventInstance = None
    EventInstance = EventObj(eventExecutionString)
    EventInstance.env['VMCATCHER_CACHE_DIR_CACHE'] = dir_cache
    EventInstance.env['VMCATCHER_CACHE_DIR_DOWNLOAD'] = dir_partial
    EventInstance.env['VMCATCHER_CACHE_DIR_EXPIRE'] = dir_expired

    ThisCacheManager.callbackEventAvailablePrefix = EventInstance.eventAvailablePrefix
    ThisCacheManager.callbackEventAvailablePostfix = EventInstance.eventAvailablePostfix
    ThisCacheManager.callbackEventExpirePrefix = EventInstance.eventExpirePrefix
    ThisCacheManager.callbackEventExpirePostfix = EventInstance.eventExpirePosfix
    ThisCacheManager.load()
    EventInstance.eventProcessPrefix({})
    if "expire" in actions:
        if not ThisCacheManager.expire():
            log.error("Failed to expire old images")
            sys.exit(1)
    if "sha512" in actions:
        if not ThisCacheManager.checkSumCache():
            log.error("Failed to checksum old images")
            sys.exit(1)
    if "download" in actions:
        if not ThisCacheManager.download():
            log.error("Failed to download new images")
            sys.exit(1)
    ThisCacheManager.save()
    EventInstance.eventProcessPostfix({})
if __name__ == "__main__":
    main()