From 128cc007d23bcb1b0f48bfaa1b5a846c7744bd31 Mon Sep 17 00:00:00 2001 From: Marco Mariani <marco.mariani@nexedi.com> Date: Fri, 26 Apr 2013 15:46:16 +0200 Subject: [PATCH] logger refactoring of slapgrid --- slapos/grid/SlapObject.py | 54 +++++++----- slapos/grid/slapgrid.py | 173 ++++++++++++++++++------------------- slapos/grid/svcbackend.py | 8 +- slapos/grid/utils.py | 52 +++++------ slapos/tests/slapgrid.py | 15 ++-- slapos/tests/slapobject.py | 12 ++- 6 files changed, 163 insertions(+), 151 deletions(-) diff --git a/slapos/grid/SlapObject.py b/slapos/grid/SlapObject.py index 7d8a34308..0931b9961 100644 --- a/slapos/grid/SlapObject.py +++ b/slapos/grid/SlapObject.py @@ -28,7 +28,6 @@ # ############################################################################## -import logging import os import pkg_resources import pwd @@ -58,7 +57,7 @@ REQUIRED_COMPUTER_PARTITION_PERMISSION = 0o750 class Software(object): """This class is responsible for installing a software release""" - def __init__(self, url, software_root, buildout, + def __init__(self, url, software_root, buildout, logger, signature_private_key_file=None, signature_certificate_list=None, upload_cache_url=None, upload_dir_url=None, shacache_cert_file=None, shacache_key_file=None, shadir_cert_file=None, shadir_key_file=None, @@ -75,7 +74,7 @@ class Software(object): self.software_path = os.path.join(self.software_root, self.software_url_hash) self.buildout = buildout - self.logger = logging.getLogger('BuildoutManager') + self.logger = logger self.signature_private_key_file = signature_private_key_file self.signature_certificate_list = signature_certificate_list self.upload_cache_url = upload_cache_url @@ -139,7 +138,8 @@ class Software(object): it. If it fails, we notify the server. """ root_stat_info = os.stat(self.software_root) - os.environ = getCleanEnvironment(pwd.getpwuid(root_stat_info.st_uid).pw_dir) + os.environ = getCleanEnvironment(logger=self.logger, + home_path=pwd.getpwuid(root_stat_info.st_uid).pw_dir) if not os.path.isdir(self.software_path): os.mkdir(self.software_path) extends_cache = tempfile.mkdtemp() @@ -177,10 +177,13 @@ class Software(object): self.createProfileIfMissing(buildout_cfg, self.url) buildout_parameter_list.extend(['-c', buildout_cfg]) - utils.bootstrapBuildout(self.software_path, self.buildout, - additional_buildout_parametr_list=buildout_parameter_list) - utils.launchBuildout(self.software_path, - os.path.join(self.software_path, 'bin', 'buildout'), + utils.bootstrapBuildout(path=self.software_path, + buildout=self.buildout, + logger=self.logger, + additional_buildout_parametr_list=buildout_parameter_list) + utils.launchBuildout(path=self.software_path, + buildout_binary=os.path.join(self.software_path, 'bin', 'buildout'), + logger=self.logger, additional_buildout_parametr_list=buildout_parameter_list) finally: shutil.rmtree(extends_cache) @@ -256,10 +259,12 @@ class Partition(object): server_url, software_release_url, buildout, + logger, certificate_repository_path=None, ): """Initialisation of class parameters""" self.buildout = buildout + self.logger = logger self.software_path = software_path self.instance_path = instance_path self.run_path = os.path.join(self.instance_path, 'etc', 'run') @@ -268,7 +273,6 @@ class Partition(object): supervisord_partition_configuration_path self.supervisord_socket = supervisord_socket self.computer_partition = computer_partition - self.logger = logging.getLogger('Partition') self.computer_id = computer_id self.partition_id = partition_id self.server_url = server_url @@ -356,8 +360,8 @@ class Partition(object): 'permissions are: 0%o, wanted are 0%o' % (self.instance_path, permission, REQUIRED_COMPUTER_PARTITION_PERMISSION)) - os.environ = getCleanEnvironment(pwd.getpwuid( - instance_stat_info.st_uid).pw_dir) + os.environ = getCleanEnvironment(logger=self.logger, + home_path=pwd.getpwuid(instance_stat_info.st_uid).pw_dir) # Generates buildout part from template template_location = os.path.join(self.software_path, 'instance.cfg') # Backward compatibility: "instance.cfg" file was named "template.cfg". @@ -417,11 +421,13 @@ class Partition(object): self.logger.debug('Invoking %r in %r' % (' '.join(invocation_list), self.instance_path)) process_handler = SlapPopen(invocation_list, - preexec_fn=lambda: dropPrivileges(uid, gid), + preexec_fn=lambda: dropPrivileges(uid, gid, logger=self.logger), cwd=self.instance_path, - env=getCleanEnvironment(pwd.getpwuid(uid).pw_dir), + env=getCleanEnvironment(logger=self.logger, + home_path=pwd.getpwuid(uid).pw_dir), stdout=subprocess.PIPE, - stderr=subprocess.STDOUT) + stderr=subprocess.STDOUT, + logger=self.logger) if process_handler.returncode is None or process_handler.returncode != 0: message = 'Failed to bootstrap buildout in %r.' % (self.instance_path) self.logger.error(message) @@ -430,11 +436,17 @@ class Partition(object): if not os.path.exists(buildout_binary): # use own buildout generation - utils.bootstrapBuildout(self.instance_path, self.buildout, - ['buildout:bin-directory=%s' % os.path.join(self.instance_path, 'sbin')]) + utils.bootstrapBuildout(path=self.instance_path, + buildout=self.buildout, + logger=self.logger, + additional_buildout_parameter_list= + ['buildout:bin-directory=%s' % + os.path.join(self.instance_path, 'sbin')]) buildout_binary = os.path.join(self.instance_path, 'sbin', 'buildout') # Launches buildout - utils.launchBuildout(self.instance_path, buildout_binary) + utils.launchBuildout(path=self.instance_path, + buildout_binary=buildout_binary, + logger=self.logger) # Generates supervisord configuration file from template self.logger.info("Generating supervisord config file from template...") # check if CP/etc/run exists and it is a directory @@ -510,11 +522,13 @@ class Partition(object): uid, gid = self.getUserGroupId() self.logger.debug('Invoking %r' % destroy_executable_location) process_handler = SlapPopen([destroy_executable_location], - preexec_fn=lambda: dropPrivileges(uid, gid), + preexec_fn=lambda: dropPrivileges(uid, gid, logger=self.logger), cwd=self.instance_path, - env=getCleanEnvironment(pwd.getpwuid(uid).pw_dir), + env=getCleanEnvironment(logger=self.logger, + home_path=pwd.getpwuid(uid).pw_dir), stdout=subprocess.PIPE, - stderr=subprocess.STDOUT) + stderr=subprocess.STDOUT, + logger=self.logger) if process_handler.returncode is None or process_handler.returncode != 0: message = 'Failed to destroy Computer Partition in %r.' % \ self.instance_path diff --git a/slapos/grid/slapgrid.py b/slapos/grid/slapgrid.py index eec768d86..61cdf2cf7 100644 --- a/slapos/grid/slapgrid.py +++ b/slapos/grid/slapgrid.py @@ -226,11 +226,11 @@ def setup_logger(options): '%(asctime)s %(name)-18s: %(levelname)-8s %(message)s')) logging.getLogger('').addHandler(console) - # XXX return and use logger object + logger = logging.getLogger(__name__) + return logger - -def random_delay(options): +def random_delay(options, logger): """ Sleep for a random time to avoid SlapOS Master being DDOSed by an army of SlapOS Nodes configured with cron. @@ -242,8 +242,8 @@ def random_delay(options): maximal_delay = int(options.get('maximal_delay', '0')) if maximal_delay: duration = random.randint(1, maximal_delay) - logging.info('Sleeping for %s seconds. To disable this feature, ' \ - 'check --now parameter in slapgrid help.' % duration) + logger.info('Sleeping for %s seconds. To disable this feature, ' \ + 'check --now parameter in slapgrid help.' % duration) time.sleep(duration) @@ -254,7 +254,7 @@ def parseArgumentTupleAndReturnSlapgridObject(*argument_tuple): """ options = parse_arguments_merge_config(*argument_tuple) - setup_logger(options) + logger = setup_logger(options) check_missing_parameters(options) check_missing_files(options) @@ -287,15 +287,15 @@ def parseArgumentTupleAndReturnSlapgridObject(*argument_tuple): url.strip() for url in options.get( "upload-to-binary-cache-url-blacklist", "").split('\n') if url] - random_delay(options) + random_delay(options, logger=logger) - slapgrid_object = create_slapgrid_object(options) + slapgrid_object = create_slapgrid_object(options, logger=logger) return slapgrid_object, options.get('pidfile') -def create_slapgrid_object(options): +def create_slapgrid_object(options, logger): signature_certificate_list = None if 'signature-certificate-list' in options: cert_marker = '-----BEGIN CERTIFICATE-----' @@ -312,10 +312,12 @@ def create_slapgrid_object(options): computer_id=op['computer_id'], supervisord_socket=op['supervisord_socket'], supervisord_configuration_path=op['supervisord_configuration_path'], + buildout=op.get('buildout'), + logger=logger, + force_periodicity = op.get('force_periodicity', False), + maximum_periodicity = op.get('maximum_periodicity', 86400), key_file=op.get('key_file'), cert_file=op.get('cert_file'), - master_ca_file=op.get('master_ca_file'), - certificate_repository_path=op.get('certificate_repository_path'), signature_private_key_file=op.get('signature_private_key_file'), signature_certificate_list=signature_certificate_list, download_binary_cache_url=op.get('download-binary-cache-url'), @@ -328,7 +330,8 @@ def create_slapgrid_object(options): download_binary_dir_url=op.get('download-binary-dir-url'), upload_binary_dir_url=op.get('upload-binary-dir-url'), upload_dir_url=op.get('upload-dir-url'), - buildout=op.get('buildout'), + master_ca_file=op.get('master_ca_file'), + certificate_repository_path=op.get('certificate_repository_path'), promise_timeout=op['promise_timeout'], shacache_cert_file=op.get('shacache-cert-file'), shacache_key_file=op.get('shacache-key-file'), @@ -338,15 +341,13 @@ def create_slapgrid_object(options): # Try to fetch from deprecated argument software_release_filter_list=op.get('only-sr', op.get('only_sr')), # Try to fetch from deprecated argument - computer_partition_filter_list=op.get('only-cp', op.get('only_cp')), - force_periodicity = op.get('force_periodicity', False), - maximum_periodicity = op.get('maximum_periodicity', 86400)) + computer_partition_filter_list=op.get('only-cp', op.get('only_cp'))) def realRun(argument_tuple, method): slapgrid_object, pidfile = parseArgumentTupleAndReturnSlapgridObject(*argument_tuple) if pidfile: - setRunning(pidfile) + setRunning(logger=slapgrid_object.logger, pid_file=pidfile) try: failed = False failed_promise = False @@ -397,6 +398,7 @@ class Slapgrid(object): supervisord_socket, supervisord_configuration_path, buildout, + logger, force_periodicity=False, maximum_periodicity=86400, key_file=None, @@ -450,8 +452,7 @@ class Slapgrid(object): self.shacache_key_file = shacache_key_file self.shadir_cert_file = shadir_cert_file self.shadir_key_file = shadir_key_file - # Configures logger - self.logger = logging.getLogger('Slapgrid') + self.logger = logger # Creates objects from slap module self.slap = slapos.slap.slap() self.slap.initializeConnection(self.master_url, key_file=self.key_file, @@ -529,8 +530,7 @@ class Slapgrid(object): """Will process each Software Release. """ self.checkEnvironmentAndCreateStructure() - logger = logging.getLogger('SoftwareReleases') - logger.info("Processing software releases...") + self.logger.info('Processing software releases...') # Boolean to know if every instance has correctly been deployed clean_run = True for software_release in self.computer.getSoftwareReleaseList(): @@ -542,6 +542,7 @@ class Slapgrid(object): software = Software(url=software_release_uri, software_root=self.software_root, buildout=self.buildout, + logger=self.logger, signature_private_key_file=self.signature_private_key_file, signature_certificate_list=self.signature_certificate_list, download_binary_cache_url=self.download_binary_cache_url, @@ -573,9 +574,9 @@ class Slapgrid(object): fout.write(time.asctime()) elif state == 'destroyed': if os.path.exists(software_path): - logger.info('Destroying %r...' % software_release_uri) + self.logger.info('Destroying %r...' % software_release_uri) software.destroy() - logger.info('Destroyed %r.' % software_release_uri) + self.logger.info('Destroyed %r.' % software_release_uri) # Send log before exiting except (SystemExit, KeyboardInterrupt): software_release.error(traceback.format_exc()) @@ -589,13 +590,13 @@ class Slapgrid(object): except (SystemExit, KeyboardInterrupt): raise except Exception: - logger.error('Problem while reporting error, continuing:\n%s' % - traceback.format_exc()) + self.logger.error('Problem while reporting error, continuing:\n%s' % + traceback.format_exc()) # For everything else: log it, send it, continue. except Exception: exc = traceback.format_exc() - logger.error(exc) + self.logger.error(exc) software_release.error(exc) clean_run = False else: @@ -609,7 +610,7 @@ class Slapgrid(object): software_release.destroyed() except (NotFoundError, ServerError): print traceback.format_exc() - logger.info("Finished software releases.") + self.logger.info('Finished software releases.') # Return success value if not clean_run: @@ -650,7 +651,7 @@ class Slapgrid(object): self.logger.info("Checking promise %r.", promise) process_handler = subprocess.Popen(command, - preexec_fn=lambda: dropPrivileges(uid, gid), + preexec_fn=lambda: dropPrivileges(uid, gid, logger=self.logger), cwd=cwd, env=None if sys.platform == 'cygwin' else {}, stdout=subprocess.PIPE, @@ -680,8 +681,6 @@ class Slapgrid(object): """ Process a Computer Partition, depending on its state """ - logger = logging.getLogger('ComputerPartitionProcessing') - computer_partition_id = computer_partition.getId() # Sanity checks before processing @@ -695,7 +694,7 @@ class Slapgrid(object): (computer_partition_id not in self.computer_partition_filter_list): return - logger.info('Processing Computer Partition %s...' % computer_partition_id) + self.logger.info('Processing Computer Partition %s...' % computer_partition_id) instance_path = os.path.join(self.instance_root, computer_partition_id) @@ -733,7 +732,7 @@ class Slapgrid(object): periodicity = int(open(periodicity_path).read()) except ValueError: os.remove(periodicity_path) - logger.error(traceback.format_exc()) + self.logger.error(traceback.format_exc()) # Check if timestamp from server is more recent than local one. # If not: it's not worth processing this partition (nothing has @@ -759,7 +758,7 @@ class Slapgrid(object): os.remove(timestamp_path) except ValueError: os.remove(timestamp_path) - logger.error(traceback.format_exc()) + self.logger.error(traceback.format_exc()) local_partition = Partition( software_path=software_path, @@ -774,7 +773,8 @@ class Slapgrid(object): server_url=self.master_url, software_release_url=software_url, certificate_repository_path=self.certificate_repository_path, - buildout=self.buildout) + buildout=self.buildout, + logger=self.logger) computer_partition_state = computer_partition.getState() if computer_partition_state == COMPUTER_PARTITION_STARTED_STATE: @@ -820,7 +820,6 @@ class Slapgrid(object): """ Try to filter valid partitions to be processed from free partitions. """ - logger = logging.getLogger('ComputerPartitionProcessing') filtered_computer_partition_list = [] for computer_partition in computer_partition_list: try: @@ -861,19 +860,19 @@ class Slapgrid(object): except (SystemExit, KeyboardInterrupt): raise except Exception: - logger.error('Problem during reporting error, continuing:\n%s' % - traceback.format_exc()) + self.logger.error('Problem during reporting error, continuing:\n%s' % + traceback.format_exc()) # For everything else: log it, send it, continue. except Exception as exc: - logger.error(traceback.format_exc()) + self.logger.error(traceback.format_exc()) try: computer_partition.error(exc) except (SystemExit, KeyboardInterrupt): raise except Exception: - logger.error('Problem during reporting error, continuing:\n%s' % - traceback.format_exc()) + self.logger.error('Problem during reporting error, continuing:\n%s' % + traceback.format_exc()) return filtered_computer_partition_list @@ -881,8 +880,7 @@ class Slapgrid(object): """ Will start supervisord and process each Computer Partition. """ - logger = logging.getLogger('ComputerPartitionProcessing') - logger.info('Processing computer partitions...') + self.logger.info('Processing computer partitions...') # Prepares environment self.checkEnvironmentAndCreateStructure() self._launchSupervisord() @@ -912,13 +910,13 @@ class Slapgrid(object): except Slapgrid.PromiseError as exc: clean_run_promise = False try: - logger.error(exc) + self.logger.error(exc) computer_partition.error(exc) except (SystemExit, KeyboardInterrupt): raise except Exception: - logger.error('Problem during reporting error, continuing:\n%s' % - traceback.format_exc()) + self.logger.error('Problem during reporting error, continuing:\n%s' % + traceback.format_exc()) # Buildout failed: send log but don't print it to output (already done) except BuildoutFailedError as exc: @@ -928,22 +926,22 @@ class Slapgrid(object): except (SystemExit, KeyboardInterrupt): raise except Exception: - logger.error('Problem during reporting error, continuing:\n%s' % - traceback.format_exc()) + self.logger.error('Problem during reporting error, continuing:\n%s' % + traceback.format_exc()) # For everything else: log it, send it, continue. except Exception as exc: clean_run = False - logger.error(traceback.format_exc()) + self.logger.error(traceback.format_exc()) try: computer_partition.error(exc) except (SystemExit, KeyboardInterrupt): raise except Exception: - logger.error('Problem during reporting error, continuing:\n%s' % - traceback.format_exc()) + self.logger.error('Problem during reporting error, continuing:\n%s' % + traceback.format_exc()) - logger.info("Finished computer partitions.") + self.logger.info('Finished computer partitions.') # Return success value if not clean_run: @@ -955,9 +953,6 @@ class Slapgrid(object): def validateXML(self, to_be_validated, xsd_model): """Validates a given xml file""" - - logger = logging.getLogger('XMLValidating') - #We retrieve the xsd model xsd_model = StringIO.StringIO(xsd_model) xmlschema_doc = etree.parse(xsd_model) @@ -966,9 +961,9 @@ class Slapgrid(object): try: document = etree.fromstring(to_be_validated) except (etree.XMLSyntaxError, etree.DocumentInvalid) as exc: - logger.info('Failed to parse this XML report : %s\n%s' % \ + self.logger.info('Failed to parse this XML report : %s\n%s' % \ (to_be_validated, _formatXMLError(exc))) - logger.error(_formatXMLError(exc)) + self.logger.error(_formatXMLError(exc)) return False if xmlschema.validate(document): @@ -1030,8 +1025,7 @@ class Slapgrid(object): slap_computer_usage = self.slap.registerComputer(self.computer_id) computer_partition_usage_list = [] - logger = logging.getLogger('UsageReporting') - logger.info("Aggregating and sending usage reports...") + self.logger.info('Aggregating and sending usage reports...') #We retrieve XSD models try: @@ -1099,24 +1093,25 @@ class Slapgrid(object): uid = stat_info.st_uid gid = stat_info.st_gid process_handler = SlapPopen(invocation_list, - preexec_fn=lambda: dropPrivileges(uid, gid), + preexec_fn=lambda: dropPrivileges(uid, gid, logger=self.logger), cwd=os.path.join(instance_path, 'etc', 'report'), env=None, stdout=subprocess.PIPE, - stderr=subprocess.STDOUT) + stderr=subprocess.STDOUT, + logger=self.logger) if process_handler.returncode is None: process_handler.kill() if process_handler.returncode != 0: clean_run = False failed_script_list.append("Script %r failed." % script) - logger.warning("Failed to run %r" % invocation_list) + self.logger.warning('Failed to run %r' % invocation_list) if len(failed_script_list): computer_partition.error('\n'.join(failed_script_list)) # Whatever happens, don't stop processing other instances except Exception: - logger.info('Cannot run usage script(s) for %r: %s' % ( - computer_partition.getId(), - traceback.format_exc())) + self.logger.info('Cannot run usage script(s) for %r: %s' % ( + computer_partition.getId(), + traceback.format_exc())) #Now we loop through the different computer partitions to report report_usage_issue_cp_list = [] @@ -1132,7 +1127,7 @@ class Slapgrid(object): filename_list = os.listdir(dir_reports) else: filename_list = [] - #logger.debug('name List %s' % filename_list) + #self.logger.debug('name List %s' % filename_list) for filename in filename_list: @@ -1142,9 +1137,9 @@ class Slapgrid(object): #We check the validity of xml content of each reports if not self.validateXML(usage, partition_consumption_model): - logger.info('WARNING: The XML file %s generated by slapreport is ' - 'not valid - This report is left as is at %s where you can ' - 'inspect what went wrong ' % (filename, dir_reports)) + self.logger.info('WARNING: The XML file %s generated by slapreport is ' + 'not valid - This report is left as is at %s where you can ' + 'inspect what went wrong ' % (filename, dir_reports)) # Warn the SlapOS Master that a partition generates corrupted xml # report else: @@ -1154,7 +1149,7 @@ class Slapgrid(object): computer_partition_usage_list.append(computer_partition_usage) filename_delete_list.append(filename) else: - logger.debug("Usage report %r not found, ignored" % file_path) + self.logger.debug('Usage report %r not found, ignored' % file_path) #After sending the aggregated file we remove all the valid xml reports for filename in filename_delete_list: @@ -1162,14 +1157,14 @@ class Slapgrid(object): # Whatever happens, don't stop processing other instances except Exception: - logger.info('Cannot run usage script(s) for %r: %s' % ( - computer_partition.getId(), - traceback.format_exc())) + self.logger.info('Cannot run usage script(s) for %r: %s' % ( + computer_partition.getId(), + traceback.format_exc())) for computer_partition_usage in computer_partition_usage_list: - logger.info('computer_partition_usage_list: %s - %s' % ( - computer_partition_usage.usage, - computer_partition_usage.getId())) + self.logger.info('computer_partition_usage_list: %s - %s' % ( + computer_partition_usage.usage, + computer_partition_usage.getId())) #If there is, at least, one report if computer_partition_usage_list != []: @@ -1177,20 +1172,20 @@ class Slapgrid(object): #We generate the final XML report with asXML method computer_consumption = self.asXML(computer_partition_usage_list) - logger.info('Final xml report: %s' % computer_consumption) + self.logger.info('Final xml report: %s' % computer_consumption) #We test the XML report before sending it if self.validateXML(computer_consumption, computer_consumption_model): - logger.info('XML file generated by asXML is valid') + self.logger.info('XML file generated by asXML is valid') slap_computer_usage.reportUsage(computer_consumption) else: - logger.info('XML file generated by asXML is not valid !') + self.logger.info('XML file generated by asXML is not valid !') raise ValueError('XML file generated by asXML is not valid !') except Exception: issue = "Cannot report usage for %r: %s" % ( computer_partition.getId(), traceback.format_exc()) - logger.info(issue) + self.logger.info(issue) computer_partition.error(issue) report_usage_issue_cp_list.append(computer_partition_id) @@ -1220,7 +1215,7 @@ class Slapgrid(object): software_release_url=software_url, certificate_repository_path=self.certificate_repository_path, buildout=self.buildout, - ) + logger=self.logger) local_partition.stop() try: computer_partition.stopped() @@ -1230,8 +1225,8 @@ class Slapgrid(object): except Exception: pass if computer_partition.getId() in report_usage_issue_cp_list: - logger.info('Ignoring destruction of %r, as no report usage was sent' % - computer_partition.getId()) + self.logger.info('Ignoring destruction of %r, as no report usage was sent' % + computer_partition.getId()) continue local_partition.destroy() except (SystemExit, KeyboardInterrupt): @@ -1241,19 +1236,19 @@ class Slapgrid(object): clean_run = False exc = traceback.format_exc() computer_partition.error(exc) - logger.error(exc) + self.logger.error(exc) try: computer_partition.destroyed() except NotFoundError: - logger.debug('Ignored slap error while trying to inform about ' - 'destroying not fully configured Computer Partition %r' % - computer_partition.getId()) + self.logger.debug('Ignored slap error while trying to inform about ' + 'destroying not fully configured Computer Partition %r' % + computer_partition.getId()) except ServerError as server_error: - logger.debug('Ignored server error while trying to inform about ' - 'destroying Computer Partition %r. Error is:\n%r' % - (computer_partition.getId(), server_error.args[0])) + self.logger.debug('Ignored server error while trying to inform about ' + 'destroying Computer Partition %r. Error is:\n%r' % + (computer_partition.getId(), server_error.args[0])) - logger.info("Finished usage reports.") + self.logger.info('Finished usage reports.') # Return success value if not clean_run: diff --git a/slapos/grid/svcbackend.py b/slapos/grid/svcbackend.py index a6407651e..4c66e1e6a 100644 --- a/slapos/grid/svcbackend.py +++ b/slapos/grid/svcbackend.py @@ -46,13 +46,8 @@ def getSupervisorRPC(socket): supervisor_transport) return getattr(server_proxy, 'supervisor') -class dummylogger(object): - def info(self, *args): - print args - debug = info def launchSupervisord(socket, configuration_file, logger): - #logger = dummylogger() if os.path.exists(socket): trynum = 1 while trynum < 6: @@ -92,7 +87,8 @@ def launchSupervisord(socket, configuration_file, logger): env={}, executable=sys.executable, stdout=subprocess.PIPE, - stderr=subprocess.STDOUT) + stderr=subprocess.STDOUT, + logger=logger) result = supervisord_popen.communicate()[0] if supervisord_popen.returncode: diff --git a/slapos/grid/utils.py b/slapos/grid/utils.py index d141dc425..d19069906 100644 --- a/slapos/grid/utils.py +++ b/slapos/grid/utils.py @@ -30,7 +30,6 @@ import grp import hashlib -import logging import os import pkg_resources import pwd @@ -95,6 +94,7 @@ class SlapPopen(subprocess.Popen): log. """ def __init__(self, *args, **kwargs): + logger = kwargs.pop('logger') kwargs.update(stdin=subprocess.PIPE) if sys.platform == 'cygwin' and kwargs.get('env') == {}: kwargs['env'] = None @@ -103,7 +103,6 @@ class SlapPopen(subprocess.Popen): self.stdin.close() self.stdin = None - logger = logging.getLogger('SlapProcessManager') # XXX-Cedric: this algorithm looks overkill for simple logging. output_lines = [] while True: @@ -119,8 +118,7 @@ def md5digest(url): return hashlib.md5(url).hexdigest() -def getCleanEnvironment(home_path='/tmp'): - logger = logging.getLogger('CleanEnvironment') +def getCleanEnvironment(logger, home_path='/tmp'): changed_env = {} removed_env = [] env = os.environ.copy() @@ -137,12 +135,11 @@ def getCleanEnvironment(home_path='/tmp'): return env -def setRunning(pid_file): +def setRunning(logger, pidfile): """Creates a pidfile. If a pidfile already exists, we exit""" - logger = logging.getLogger('Slapgrid') - if os.path.exists(pid_file): + if os.path.exists(pidfile): try: - pid = int(open(pid_file, 'r').readline()) + pid = int(open(pidfile, 'r').readline()) except ValueError: pid = None # XXX This could use psutil library. @@ -150,29 +147,28 @@ def setRunning(pid_file): logger.info('New slapos process started, but another slapos ' 'process is aleady running with pid %s, exiting.' % pid) sys.exit(10) - logger.info('Existing pid file %r was stale, overwritten' % pid_file) + logger.info('Existing pid file %r was stale, overwritten' % pidfile) # Start new process - write_pid(pid_file) + write_pid(logger, pidfile) -def setFinished(pid_file): +def setFinished(pidfile): try: - os.remove(pid_file) + os.remove(pidfile) except OSError: pass -def write_pid(pid_file): - logger = logging.getLogger('Slapgrid') +def write_pid(logger, pidfile): try: - with open(pid_file, 'w') as fout: + with open(pidfile, 'w') as fout: fout.write('%s' % os.getpid()) except (IOError, OSError): - logger.critical('slapgrid could not write pidfile %s' % pid_file) + logger.critical('slapgrid could not write pidfile %s' % pidfile) raise -def dropPrivileges(uid, gid): +def dropPrivileges(uid, gid, logger): """Drop privileges to uid, gid if current uid is 0 Do tests to check if dropping was successful and that no system call is able @@ -180,7 +176,6 @@ def dropPrivileges(uid, gid): Does nothing in case if uid and gid are not 0 """ - logger = logging.getLogger('dropPrivileges') # XXX-Cedric: remove format / just do a print, otherwise formatting is done # twice current_uid, current_gid = os.getuid(), os.getgid() @@ -232,11 +227,10 @@ def dropPrivileges(uid, gid): logger.debug('Succesfully dropped privileges to uid=%r gid=%r' % (uid, gid)) -def bootstrapBuildout(path, buildout=None, - additional_buildout_parametr_list=None): +def bootstrapBuildout(path, logger, buildout=None, + additional_buildout_parametr_list=None): if additional_buildout_parametr_list is None: additional_buildout_parametr_list = [] - logger = logging.getLogger('BuildoutManager') # Reads uid/gid of path, launches buildout with thoses privileges stat_info = os.stat(path) uid = stat_info.st_uid @@ -270,10 +264,11 @@ def bootstrapBuildout(path, buildout=None, logger.debug('Invoking: %r in directory %r' % (' '.join(invocation_list), path)) process_handler = SlapPopen(invocation_list, - preexec_fn=lambda: dropPrivileges(uid, gid), + preexec_fn=lambda: dropPrivileges(uid, gid, logger=logger), cwd=path, stdout=subprocess.PIPE, - stderr=subprocess.STDOUT) + stderr=subprocess.STDOUT, + logger=logger) if process_handler.returncode is None or process_handler.returncode != 0: message = 'Failed to run buildout profile in directory %r' % (path) logger.error(message) @@ -285,10 +280,9 @@ def bootstrapBuildout(path, buildout=None, logger.debug('Restore umask from %03o to %03o' % (old_umask, umask)) -def launchBuildout(path, buildout_binary, +def launchBuildout(path, buildout_binary, logger, additional_buildout_parametr_list=None): """ Launches buildout.""" - logger = logging.getLogger('BuildoutManager') if additional_buildout_parametr_list is None: additional_buildout_parametr_list = [] # Reads uid/gid of path, launches buildout with thoses privileges @@ -311,11 +305,13 @@ def launchBuildout(path, buildout_binary, logger.debug('Invoking: %r in directory %r' % (' '.join(invocation_list), path)) process_handler = SlapPopen(invocation_list, - preexec_fn=lambda: dropPrivileges(uid, gid), + preexec_fn=lambda: dropPrivileges(uid, gid, logger=logger), cwd=path, - env=getCleanEnvironment(pwd.getpwuid(uid).pw_dir), + env=getCleanEnvironment(logger=logger, + home_path=pwd.getpwuid(uid).pw_dir), stdout=subprocess.PIPE, - stderr=subprocess.STDOUT) + stderr=subprocess.STDOUT, + logger=logger) if process_handler.returncode is None or process_handler.returncode != 0: message = 'Failed to run buildout profile in directory %r' % (path) logger.error(message) diff --git a/slapos/tests/slapgrid.py b/slapos/tests/slapgrid.py index 8818b30b6..a81bd9e8d 100644 --- a/slapos/tests/slapgrid.py +++ b/slapos/tests/slapgrid.py @@ -117,10 +117,15 @@ class BasicMixin: 'supervisord') self.usage_report_periodicity = 1 self.buildout = None - self.grid = slapgrid.Slapgrid(self.software_root, self.instance_root, - self.master_url, self.computer_id, self.supervisord_socket, - self.supervisord_configuration_path, - self.buildout, develop=develop) + self.grid = slapgrid.Slapgrid(self.software_root, + self.instance_root, + self.master_url, + self.computer_id, + self.supervisord_socket, + self.supervisord_configuration_path, + self.buildout, + develop=develop, + logger=logging.getLogger()) # monkey patch buildout bootstrap def dummy(*args, **kw): pass @@ -1826,7 +1831,7 @@ exit 127""" % {'worked_file': worked_file}) slapos.grid.slapgrid.SLAPGRID_PROMISE_FAIL) self.assertTrue(os.path.isfile(worked_file)) - self.assertEqual(instance.error_log, 'Error') + self.assertEqual(instance.error_log.split('\n')[-1], 'Error') self.assertTrue(instance.error) self.assertIsNone(instance.state) diff --git a/slapos/tests/slapobject.py b/slapos/tests/slapobject.py index 7b0f701cc..3ac58f9d9 100644 --- a/slapos/tests/slapobject.py +++ b/slapos/tests/slapobject.py @@ -25,12 +25,14 @@ # ############################################################################## +import logging +import os +import unittest + from slapos.grid import SlapObject from slapos.grid import utils from slapos.grid import networkcache from slapos.tests.slapgrid import BasicMixin -import os -import unittest class FakeCallAndRead: @@ -93,6 +95,7 @@ class TestSoftwareSlapObject(BasicMixin, unittest.TestCase): url='http://example.com/software.cfg', software_root=self.software_root, buildout=self.buildout, + logger=logging.getLogger(), signature_private_key_file='/signature/private/key_file', upload_cache_url='http://example.com/uploadcache', upload_dir_url='http://example.com/uploaddir', @@ -129,7 +132,8 @@ class TestSoftwareSlapObject(BasicMixin, unittest.TestCase): software = SlapObject.Software( url='http://example.com/software.cfg', software_root=self.software_root, - buildout=self.buildout) + buildout=self.buildout, + logger=logging.getLogger()) software.install() @@ -161,6 +165,7 @@ class TestSoftwareSlapObject(BasicMixin, unittest.TestCase): url='http://example.com/software.cfg', software_root=self.software_root, buildout=self.buildout, + logger=logging.getLogger(), signature_private_key_file='/signature/private/key_file', upload_cache_url='http://example.com/uploadcache', upload_dir_url='http://example.com/uploaddir', @@ -192,6 +197,7 @@ class TestSoftwareSlapObject(BasicMixin, unittest.TestCase): url='http://example.com/software.cfg', software_root=self.software_root, buildout=self.buildout, + logger=logging.getLogger(), signature_private_key_file='/signature/private/key_file', upload_cache_url='http://example.com/uploadcache', upload_dir_url='http://example.com/uploaddir', -- 2.30.9