Skip to content

erp5
erp5
Commit 7fe1f931 authored by Julien Muchembled's avatar Julien Muchembled Committed by Klaus Wölfel
Browse files
Options

testnode: simplify logging 

Conflicts:
	erp5/util/testnode/ProcessManager.py
parent 78a3eb8e
Expand all Hide whitespace changes
Inline Side-by-side
Showing with 302 additions and 321 deletions
erp5/tests/testERP5TestNode.py
View file @ 7fe1f931
This diff is collapsed.
erp5/util/testnode/ProcessManager.py
View file @ 7fe1f931
...@@ -32,6 +32,7 @@ import threading ...@@ -32,6 +32,7 @@ import threading
import signal import signal
import sys import sys
import time import time
from . import logger
MAX_TIMEOUT = 3600 * 4 MAX_TIMEOUT = 3600 * 4
...@@ -67,28 +68,28 @@ def format_command(*args, **kw): ...@@ -67,28 +68,28 @@ def format_command(*args, **kw):
cmdline.append(v) cmdline.append(v)
return ' '.join(cmdline) return ' '.join(cmdline)
def subprocess_capture(p, log, log_prefix, get_output=True): def subprocess_capture(p, log_prefix, get_output=True):
def readerthread(input, output, buffer): log = logger.info
if log_prefix:
log_prefix += ': '
def readerthread(input, buffer):
while True: while True:
data = input.readline() data = input.readline()
if not data: if not data:
break break
if get_output: if get_output:
buffer.append(data) buffer.append(data)
if log_prefix: log(log_prefix + data.rstrip('\n'))
data = "%s : " % log_prefix + data
data = data.rstrip('\n')
output(data)
if p.stdout: if p.stdout:
stdout = [] stdout = []
stdout_thread = threading.Thread(target=readerthread, stdout_thread = threading.Thread(target=readerthread,
args=(p.stdout, log, stdout)) args=(p.stdout, stdout))
stdout_thread.daemon = True stdout_thread.daemon = True
stdout_thread.start() stdout_thread.start()
if p.stderr: if p.stderr:
stderr = [] stderr = []
stderr_thread = threading.Thread(target=readerthread, stderr_thread = threading.Thread(target=readerthread,
args=(p.stderr, log, stderr)) args=(p.stderr, stderr))
stderr_thread.daemon = True stderr_thread.daemon = True
stderr_thread.start() stderr_thread.start()
p.wait() p.wait()
...@@ -99,7 +100,7 @@ def subprocess_capture(p, log, log_prefix, get_output=True): ...@@ -99,7 +100,7 @@ def subprocess_capture(p, log, log_prefix, get_output=True):
return (p.stdout and ''.join(stdout), return (p.stdout and ''.join(stdout),
p.stderr and ''.join(stderr)) p.stderr and ''.join(stderr))
def killCommand(pid, log): def killCommand(pid):
""" """
To prevent processes from reacting to the KILL of other processes, To prevent processes from reacting to the KILL of other processes,
we STOP them all first, and we repeat until the list of children does not we STOP them all first, and we repeat until the list of children does not
...@@ -118,21 +119,20 @@ def killCommand(pid, log): ...@@ -118,21 +119,20 @@ def killCommand(pid, log):
try: try:
child.suspend() child.suspend()
except psutil.Error, e: except psutil.Error, e:
log("killCommand/suspend: %s", e) logger.debug("killCommand/suspend: %s", e)
time.sleep(1) time.sleep(1)
new_list = set(process.children(recursive=True)).difference(process_list) new_list = set(process.children(recursive=True)).difference(process_list)
for process in process_list: for process in process_list:
try: try:
process.kill() process.kill()
except psutil.Error, e: except psutil.Error, e:
log("killCommand/kill: %s", e) logger.debug("killCommand/kill: %s", e)
class ProcessManager(object): class ProcessManager(object):
stdin = file(os.devnull) stdin = file(os.devnull)
def __init__(self, log, max_timeout=MAX_TIMEOUT): def __init__(self, max_timeout=MAX_TIMEOUT):
self.log = log
self.process_pid_set = set() self.process_pid_set = set()
signal.signal(signal.SIGTERM, self.sigterm_handler) signal.signal(signal.SIGTERM, self.sigterm_handler)
self.under_cancellation = False self.under_cancellation = False
...@@ -142,19 +142,17 @@ class ProcessManager(object): ...@@ -142,19 +142,17 @@ class ProcessManager(object):
self.timer_set = set() self.timer_set = set()
def spawn(self, *args, **kw): def spawn(self, *args, **kw):
def timeoutExpired(p, log): def timeoutExpired(p):
if p.poll() is None: if p.poll() is None:
log('PROCESS TOO LONG OR DEAD, GOING TO BE TERMINATED') logger.warning('PROCESS TOO LONG OR DEAD, GOING TO BE TERMINATED')
killCommand(p.pid, log) killCommand(p.pid)
raise SubprocessError('Dead or too long process killed')
if self.under_cancellation: if self.under_cancellation:
raise CancellationError("Test Result was cancelled") raise CancellationError("Test Result was cancelled")
get_output = kw.pop('get_output', True) get_output = kw.pop('get_output', True)
log_prefix = kw.pop('log_prefix', '') log_prefix = kw.pop('log_prefix', '')
new_session = kw.pop('new_session', True) new_session = kw.pop('new_session', True)
log = kw.pop('log', None)
if log is None:
log = self.log
subprocess_kw = {} subprocess_kw = {}
cwd = kw.pop('cwd', None) cwd = kw.pop('cwd', None)
if cwd: if cwd:
...@@ -164,17 +162,16 @@ class ProcessManager(object): ...@@ -164,17 +162,16 @@ class ProcessManager(object):
raise_error_if_fail = kw.pop('raise_error_if_fail', True) raise_error_if_fail = kw.pop('raise_error_if_fail', True)
env = kw and dict(os.environ, **kw) or None env = kw and dict(os.environ, **kw) or None
command = format_command(*args, **kw) command = format_command(*args, **kw)
log('subprocess_kw : %r' % (subprocess_kw,)) logger.info('subprocess_kw : %r', subprocess_kw)
log('$ ' + command) logger.info('$ %s', command)
sys.stdout.flush() sys.stdout.flush()
p = subprocess.Popen(args, stdin=self.stdin, stdout=subprocess.PIPE, p = subprocess.Popen(args, stdin=self.stdin, stdout=subprocess.PIPE,
stderr=subprocess.PIPE, env=env, **subprocess_kw) stderr=subprocess.PIPE, env=env, **subprocess_kw)
self.process_pid_set.add(p.pid) self.process_pid_set.add(p.pid)
timer = threading.Timer(self.max_timeout, timeoutExpired, args=(p, log)) timer = threading.Timer(self.max_timeout, timeoutExpired, args=(p,))
self.timer_set.add(timer) self.timer_set.add(timer)
timer.start() timer.start()
stdout, stderr = subprocess_capture(p, log, log_prefix, stdout, stderr = subprocess_capture(p, log_prefix, get_output=get_output)
get_output=get_output)
timer.cancel() timer.cancel()
self.timer_set.discard(timer) self.timer_set.discard(timer)
result = dict(status_code=p.returncode, command=command, result = dict(status_code=p.returncode, command=command,
...@@ -211,32 +208,39 @@ class ProcessManager(object): ...@@ -211,32 +208,39 @@ class ProcessManager(object):
continue continue
except (psutil.AccessDenied, psutil.NoSuchProcess): except (psutil.AccessDenied, psutil.NoSuchProcess):
continue continue
self.log('ProcesssManager, killall on %s having pid %s', logger.debug('ProcesssManager, killall on %s having pid %s',
name, process.pid) name, process.pid)
to_kill_list.append(process.pid) to_kill_list.append(process.pid)
for pid in to_kill_list: for pid in to_kill_list:
killCommand(pid, self.log) killCommand(pid)
def killPreviousRun(self, cancellation=False): def killPreviousRun(self, cancellation=False):
self.log('ProcessManager killPreviousRun, going to kill %r', logger.debug('ProcessManager killPreviousRun, going to kill %r',
self.process_pid_set) self.process_pid_set)
if cancellation: if cancellation:
self.under_cancellation = True self.under_cancellation = True
for timer in self.timer_set: for timer in self.timer_set:
timer.cancel() timer.cancel()
for pgpid in self.process_pid_set: for pgpid in self.process_pid_set:
killCommand(pgpid, self.log) killCommand(pgpid)
try: try:
if os.path.exists(self.supervisord_pid_file): pid_file = self.supervisord_pid_file
with open(self.supervisord_pid_file) as f: except AttributeError:
supervisor_pid = int(f.read().strip()) pass
self.log('ProcessManager killPreviousRun, going to kill supervisor with pid %r', else:
supervisor_pid) del self.supervisord_pid_file
os.kill(supervisor_pid, signal.SIGTERM) try:
except Exception: if os.path.exists(pid_file):
self.log('ProcessManager killPreviousRun, exception when killing supervisor') with open(pid_file) as f:
pid = int(f.read().strip())
logger.debug('ProcessManager killPreviousRun,'
' going to kill supervisor with pid %r', pid)
os.kill(pid, signal.SIGTERM)
except Exception:
logger.exception(
'ProcessManager killPreviousRun, exception when killing supervisor')
self.process_pid_set.clear() self.process_pid_set.clear()
def sigterm_handler(self, signal, frame): def sigterm_handler(self, signal, frame):
self.log('SIGTERM_HANDLER') logger.debug('SIGTERM_HANDLER')
sys.exit(1) sys.exit(1)
erp5/util/testnode/ScalabilityTestRunner.py
View file @ 7fe1f931
This diff is collapsed.
erp5/util/testnode/SlapOSControler.py
View file @ 7fe1f931
...@@ -30,9 +30,9 @@ import slapos.slap ...@@ -30,9 +30,9 @@ import slapos.slap
import subprocess import subprocess
import time import time
import xml_marshaller import xml_marshaller
import sys
import argparse import argparse
from slapos import client from slapos import client
from . import logger
from .Utils import createFolder from .Utils import createFolder
MAX_PARTITIONS = 10 MAX_PARTITIONS = 10
...@@ -40,12 +40,11 @@ MAX_SR_RETRIES = 3 ...@@ -40,12 +40,11 @@ MAX_SR_RETRIES = 3
class SlapOSControler(object): class SlapOSControler(object):
def __init__(self, working_directory, config, log): def __init__(self, working_directory, config):
self.config = config self.config = config
self.software_root = os.path.join(working_directory, 'soft') self.software_root = os.path.join(working_directory, 'soft')
self.instance_root = os.path.join(working_directory, 'inst') self.instance_root = os.path.join(working_directory, 'inst')
self.slapos_config = os.path.join(working_directory, 'slapos.cfg') self.slapos_config = os.path.join(working_directory, 'slapos.cfg')
self.log = log
self.proxy_database = os.path.join(working_directory, 'proxy.db') self.proxy_database = os.path.join(working_directory, 'proxy.db')
self.instance_config = {} self.instance_config = {}
...@@ -80,7 +79,7 @@ class SlapOSControler(object): ...@@ -80,7 +79,7 @@ class SlapOSControler(object):
Ex : Ex :
my_controler.supply('kvm.cfg', 'COMP-726') my_controler.supply('kvm.cfg', 'COMP-726')
""" """
self.log('SlapOSControler : supply') logger.debug('SlapOSControler : supply')
parser = argparse.ArgumentParser() parser = argparse.ArgumentParser()
parser.add_argument("configuration_file") parser.add_argument("configuration_file")
parser.add_argument("software_url") parser.add_argument("software_url")
...@@ -92,9 +91,9 @@ class SlapOSControler(object): ...@@ -92,9 +91,9 @@ class SlapOSControler(object):
try: try:
local = client.init(config) local = client.init(config)
local['supply'](software_url, computer_guid=computer_id, state=state) local['supply'](software_url, computer_guid=computer_id, state=state)
self.log('SlapOSControler : supply %s %s %s', software_url, computer_id, state) logger.debug('SlapOSControler: supply %s %s %s', software_url, computer_id, state)
except Exception: except Exception:
self.log("SlapOSControler.supply", exc_info=sys.exc_info()) logger.exception("SlapOSControler.supply")
raise ValueError("Unable to supply (or remove)") raise ValueError("Unable to supply (or remove)")
else: else:
raise ValueError("Configuration file not found.") raise ValueError("Configuration file not found.")
...@@ -113,7 +112,7 @@ class SlapOSControler(object): ...@@ -113,7 +112,7 @@ class SlapOSControler(object):
'kvm.cfg', 'cluster', { "_" : "{'toto' : 'titi'}" } ) 'kvm.cfg', 'cluster', { "_" : "{'toto' : 'titi'}" } )
""" """
self.log('SlapOSControler : request-->SlapOSMaster') logger.debug('SlapOSControler : request-->SlapOSMaster')
current_intance_config = {'software_type':software_type, current_intance_config = {'software_type':software_type,
'software_configuration':software_configuration, 'software_configuration':software_configuration,
'computer_guid':computer_guid, 'computer_guid':computer_guid,
...@@ -145,10 +144,10 @@ class SlapOSControler(object): ...@@ -145,10 +144,10 @@ class SlapOSControler(object):
if state == 'destroyed': if state == 'destroyed':
del self.instance_config[reference] del self.instance_config[reference]
elif state == 'started': elif state == 'started':
self.log('Instance started with configuration: %s', logger.debug('Instance started with configuration: %s',
software_configuration) software_configuration)
except Exception: except Exception:
self.log("SlapOSControler.request", exc_info=sys.exc_info()) logger.exception("SlapOSControler.request")
raise ValueError("Unable to do this request") raise ValueError("Unable to do this request")
else: else:
raise ValueError("Configuration file not found.") raise ValueError("Configuration file not found.")
...@@ -163,21 +162,21 @@ class SlapOSControler(object): ...@@ -163,21 +162,21 @@ class SlapOSControler(object):
) )
def destroyInstance(self, reference): def destroyInstance(self, reference):
self.log('SlapOSControler : delete instance') logger.debug('SlapOSControler : delete instance')
try: try:
self._requestSpecificState(reference, 'destroyed') self._requestSpecificState(reference, 'destroyed')
except Exception: except Exception:
raise ValueError("Can't delete instance %r (instance not created?)" % reference) raise ValueError("Can't delete instance %r (instance not created?)" % reference)
def stopInstance(self, reference): def stopInstance(self, reference):
self.log('SlapOSControler : stop instance') logger.debug('SlapOSControler : stop instance')
try: try:
self._requestSpecificState(reference, 'stopped') self._requestSpecificState(reference, 'stopped')
except Exception: except Exception:
raise ValueError("Can't stop instance %r (instance not created?)" % reference) raise ValueError("Can't stop instance %r (instance not created?)" % reference)
def startInstance(self, reference): def startInstance(self, reference):
self.log('SlapOSControler : start instance') logger.debug('SlapOSControler : start instance')
try: try:
self._requestSpecificState(reference, 'started') self._requestSpecificState(reference, 'started')
except Exception: except Exception:
...@@ -188,8 +187,8 @@ class SlapOSControler(object): ...@@ -188,8 +187,8 @@ class SlapOSControler(object):
Update the XML configuration of an instance Update the XML configuration of an instance
# Request same instance with different parameters. # Request same instance with different parameters.
""" """
self.log('SlapOSControler : updateInstanceXML will request same' logger.debug('SlapOSControler : updateInstanceXML will request same'
' instance with new XML configuration...') ' instance with new XML configuration...')
try: try:
self.request(reference, self.request(reference,
...@@ -203,7 +202,7 @@ class SlapOSControler(object): ...@@ -203,7 +202,7 @@ class SlapOSControler(object):
raise ValueError("Can't update instance '%s' (may not exist?)" %reference) raise ValueError("Can't update instance '%s' (may not exist?)" %reference)
def _resetSoftware(self): def _resetSoftware(self):
self.log('SlapOSControler : GOING TO RESET ALL SOFTWARE : %r', logger.info('SlapOSControler: GOING TO RESET ALL SOFTWARE : %r',
self.software_root) self.software_root)
createFolder(self.software_root, True) createFolder(self.software_root, True)
...@@ -211,7 +210,7 @@ class SlapOSControler(object): ...@@ -211,7 +210,7 @@ class SlapOSControler(object):
reset_software=False, software_path_list=None): reset_software=False, software_path_list=None):
self.process_manager = process_manager self.process_manager = process_manager
self.software_path_list = software_path_list self.software_path_list = software_path_list
self.log('SlapOSControler, initialize, reset_software: %r', reset_software) logger.debug('SlapOSControler, initialize, reset_software: %r', reset_software)
config = self.config config = self.config
slapos_config_dict = config.copy() slapos_config_dict = config.copy()
slapos_config_dict.update(software_root=self.software_root, slapos_config_dict.update(software_root=self.software_root,
...@@ -248,8 +247,7 @@ class SlapOSControler(object): ...@@ -248,8 +247,7 @@ class SlapOSControler(object):
computer_guid=config['computer_id']) computer_guid=config['computer_id'])
computer = slap.registerComputer(config['computer_id']) computer = slap.registerComputer(config['computer_id'])
except Exception: except Exception:
self.log("SlapOSControler.initializeSlapOSControler", logger.exception("SlapOSControler.initializeSlapOSControler")
exc_info=sys.exc_info())
raise ValueError("Unable to registerSupply") raise ValueError("Unable to registerSupply")
# Reset all previously generated software if needed # Reset all previously generated software if needed
if reset_software: if reset_software:
...@@ -289,7 +287,7 @@ class SlapOSControler(object): ...@@ -289,7 +287,7 @@ class SlapOSControler(object):
return self.process_manager.spawn(*args, **kw) return self.process_manager.spawn(*args, **kw)
def runSoftwareRelease(self, config, environment, **kw): def runSoftwareRelease(self, config, environment, **kw):
self.log("SlapOSControler.runSoftwareRelease") logger.debug("SlapOSControler.runSoftwareRelease")
cpu_count = str(os.sysconf("SC_NPROCESSORS_ONLN")) cpu_count = str(os.sysconf("SC_NPROCESSORS_ONLN"))
os.environ['MAKEFLAGS'] = '-j' + cpu_count os.environ['MAKEFLAGS'] = '-j' + cpu_count
os.environ['NPY_NUM_BUILD_JOBS'] = cpu_count os.environ['NPY_NUM_BUILD_JOBS'] = cpu_count
...@@ -309,7 +307,7 @@ class SlapOSControler(object): ...@@ -309,7 +307,7 @@ class SlapOSControler(object):
def runComputerPartition(self, config, environment, def runComputerPartition(self, config, environment,
stdout=None, stderr=None, cluster_configuration=None, **kw): stdout=None, stderr=None, cluster_configuration=None, **kw):
self.log("SlapOSControler.runComputerPartition with cluster_config: %r", logger.debug("SlapOSControler.runComputerPartition with cluster_config: %r",
cluster_configuration) cluster_configuration)
for path in self.software_path_list: for path in self.software_path_list:
try: try:
...@@ -318,7 +316,7 @@ class SlapOSControler(object): ...@@ -318,7 +316,7 @@ class SlapOSControler(object):
self.software_path_list.index(path), self.software_path_list.index(path),
partition_parameter_kw=cluster_configuration) partition_parameter_kw=cluster_configuration)
except Exception: except Exception:
self.log("SlapOSControler.runComputerPartition", exc_info=sys.exc_info()) logger.exception("SlapOSControler.runComputerPartition")
raise ValueError("Unable to registerOpenOrder") raise ValueError("Unable to registerOpenOrder")
# try to run for all partitions as one partition may in theory request another one # try to run for all partitions as one partition may in theory request another one
...@@ -329,7 +327,7 @@ class SlapOSControler(object): ...@@ -329,7 +327,7 @@ class SlapOSControler(object):
'--pidfile', os.path.join(self.instance_root, 'slapos-node.pid'), '--pidfile', os.path.join(self.instance_root, 'slapos-node.pid'),
'--cfg', self.slapos_config, raise_error_if_fail=False, '--cfg', self.slapos_config, raise_error_if_fail=False,
log_prefix='slapgrid_cp', get_output=False) log_prefix='slapgrid_cp', get_output=False)
self.log('slapgrid_cp status_dict : %r', status_dict) logger.debug('slapgrid_cp status_dict : %r', status_dict)
if not status_dict['status_code']: if not status_dict['status_code']:
break break
else: else:
......
erp5/util/testnode/SlapOSMasterCommunicator.py
View file @ 7fe1f931
...@@ -10,6 +10,7 @@ import slapos.slap ...@@ -10,6 +10,7 @@ import slapos.slap
from slapos.slap import SoftwareProductCollection from slapos.slap import SoftwareProductCollection
from requests.exceptions import HTTPError from requests.exceptions import HTTPError
from ..taskdistribution import SAFE_RPC_EXCEPTION_LIST from ..taskdistribution import SAFE_RPC_EXCEPTION_LIST
from . import logger
# max time to instance changing state: 2 hour # max time to instance changing state: 2 hour
MAX_INSTANCE_TIME = 60*60*2 MAX_INSTANCE_TIME = 60*60*2
...@@ -61,8 +62,7 @@ def retryOnNetworkFailure(func, ...@@ -61,8 +62,7 @@ def retryOnNetworkFailure(func,
class SlapOSMasterCommunicator(object): class SlapOSMasterCommunicator(object):
latest_state = None latest_state = None
def __init__(self, slap, slap_supply, slap_order, url, logger): def __init__(self, slap, slap_supply, slap_order, url):
self._logger = logger
self.slap = slap self.slap = slap
self.slap_order = slap_order self.slap_order = slap_order
self.slap_supply = slap_supply self.slap_supply = slap_supply
...@@ -72,20 +72,20 @@ class SlapOSMasterCommunicator(object): ...@@ -72,20 +72,20 @@ class SlapOSMasterCommunicator(object):
if url is not None and \ if url is not None and \
url.startswith(SOFTWARE_PRODUCT_NAMESPACE): url.startswith(SOFTWARE_PRODUCT_NAMESPACE):
product = SoftwareProductCollection(self._logger, self.slap) product = SoftwareProductCollection(logger, self.slap)
try: try:
url = product.__getattr__(url[len(SOFTWARE_PRODUCT_NAMESPACE):]) url = product.__getattr__(url[len(SOFTWARE_PRODUCT_NAMESPACE):])
except AttributeError as e: except AttributeError as e:
self._logger.warning('Error on get software release : %s ' % e.message) logger.warning('Error on get software release: %s ', e.message)
self.url = url self.url = url
@retryOnNetworkFailure @retryOnNetworkFailure
def _supply(self): def _supply(self):
if self.computer_guid is None: if self.computer_guid is None:
self._logger('Nothing to supply for %s.' % (self.name)) logger.info('Nothing to supply for %s.', self.name)
return None return None
self._logger('Supply %s@%s', self.url, self.computer_guid) logger.info('Supply %s@%s', self.url, self.computer_guid)
return self.slap_supply.supply(self.url, self.computer_guid) return self.slap_supply.supply(self.url, self.computer_guid)
@retryOnNetworkFailure @retryOnNetworkFailure
...@@ -97,7 +97,7 @@ class SlapOSMasterCommunicator(object): ...@@ -97,7 +97,7 @@ class SlapOSMasterCommunicator(object):
self.request_kw = json.loads(request_kw) self.request_kw = json.loads(request_kw)
else: else:
self.request_kw = request_kw self.request_kw = request_kw
self._logger('Request %s@%s: %s', self.url, self.name, state) logger.info('Request %s@%s: %s', self.url, self.name, state)
self.latest_state = state self.latest_state = state
return self.slap_order.request( return self.slap_order.request(
software_release=self.url, software_release=self.url,
...@@ -252,7 +252,7 @@ class SlapOSMasterCommunicator(object): ...@@ -252,7 +252,7 @@ class SlapOSMasterCommunicator(object):
@retryOnNetworkFailure @retryOnNetworkFailure
def _getInstanceState(self): def _getInstanceState(self):
latest_state = self.latest_state latest_state = self.latest_state
self._logger('latest_state = %r', latest_state) logger.info('latest_state = %r', latest_state)
if latest_state is None: if latest_state is None:
return INSTANCE_STATE_UNKNOWN return INSTANCE_STATE_UNKNOWN
...@@ -297,8 +297,8 @@ class SlapOSMasterCommunicator(object): ...@@ -297,8 +297,8 @@ class SlapOSMasterCommunicator(object):
try: try:
monitor_information_dict = self.getRSSEntryFromMonitoring(monitor_v6_url) monitor_information_dict = self.getRSSEntryFromMonitoring(monitor_v6_url)
except Exception: except Exception:
self._logger('Unable to download promises for: %s' % (instance["title"])) logger.exception('Unable to download promises for: %s',
self._logger(traceback.format_exc()) instance["title"])
monitor_information_dict = {"message": "Unable to download"} monitor_information_dict = {"message": "Unable to download"}
message_list.append({ message_list.append({
...@@ -311,11 +311,10 @@ class SlapOSMasterCommunicator(object): ...@@ -311,11 +311,10 @@ class SlapOSMasterCommunicator(object):
}) })
except slapos.slap.ServerError: except slapos.slap.ServerError:
self._logger('Got an error requesting partition for ' logger.error('Got an error requesting partition for its state')
'its state')
return INSTANCE_STATE_UNKNOWN return INSTANCE_STATE_UNKNOWN
except Exception: except Exception:
self._logger("ERROR getting instance state") logger.error("ERROR getting instance state")
return INSTANCE_STATE_UNKNOWN return INSTANCE_STATE_UNKNOWN
started = 0 started = 0
...@@ -348,24 +347,24 @@ class SlapOSMasterCommunicator(object): ...@@ -348,24 +347,24 @@ class SlapOSMasterCommunicator(object):
""" """
Wait for 'max_time' an instance specific state Wait for 'max_time' an instance specific state
""" """
self._logger("Waiting for instance state: %s" %state) logger.info("Waiting for instance state: %s", state)
start_time = time.time() start_time = time.time()
while (not self._getInstanceState() == state while (not self._getInstanceState() == state
and (max_time > (time.time()-start_time))): and (max_time > (time.time()-start_time))):
self._logger("Instance(s) not in %s state yet." % state) logger.info("Instance(s) not in %s state yet.", state)
self._logger("Current state: %s" % self._getInstanceState()) logger.info("Current state: %s", self._getInstanceState())
time.sleep(15) time.sleep(15)
if (time.time()-start_time) > max_time: if (time.time()-start_time) > max_time:
error_message = "Instance '%s' not '%s' after %s seconds" %(instance_title, state, str(time.time()-start_time)) error_message = "Instance '%s' not '%s' after %s seconds" %(instance_title, state, str(time.time()-start_time))
return {'error_message' : error_message} return {'error_message' : error_message}
self._logger("Instance correctly '%s' after %s seconds." %(state, str(time.time()-start_time))) logger.info("Instance correctly '%s' after %s seconds.",
state, time.time() - start_time)
return {'error_message' : None} return {'error_message' : None}
class SlapOSTester(SlapOSMasterCommunicator): class SlapOSTester(SlapOSMasterCommunicator):
def __init__(self, def __init__(self,
name, name,
logger,
slap, slap,
slap_order, slap_order,
slap_supply, slap_supply,
...@@ -374,7 +373,7 @@ class SlapOSTester(SlapOSMasterCommunicator): ...@@ -374,7 +373,7 @@ class SlapOSTester(SlapOSMasterCommunicator):
request_kw=None request_kw=None
): ):
super(SlapOSTester, self).__init__( super(SlapOSTester, self).__init__(
slap, slap_supply, slap_order, url, logger) slap, slap_supply, slap_order, url)
self.name = name self.name = name
self.computer_guid = computer_guid self.computer_guid = computer_guid
...@@ -413,9 +412,10 @@ class SlapOSTester(SlapOSMasterCommunicator): ...@@ -413,9 +412,10 @@ class SlapOSTester(SlapOSMasterCommunicator):
def waitInstanceStarted(self, instance_title): def waitInstanceStarted(self, instance_title):
error_message = self._waitInstance(instance_title, INSTANCE_STATE_STARTED)["error_message"] error_message = self._waitInstance(instance_title, INSTANCE_STATE_STARTED)["error_message"]
if error_message is not None: if error_message is not None:
self._logger(error_message) logger.error(error_message)
self._logger("Do you use instance state propagation in your project?") logger.error("Do you use instance state propagation in your project?")
self._logger("Instance '%s' will be stopped and test aborted." %instance_title) logger.error("Instance '%s' will be stopped and test aborted.",
instance_title)
self.requestInstanceStop() self.requestInstanceStop()
time.sleep(60) time.sleep(60)
raise ValueError(error_message) raise ValueError(error_message)
...@@ -423,15 +423,15 @@ class SlapOSTester(SlapOSMasterCommunicator): ...@@ -423,15 +423,15 @@ class SlapOSTester(SlapOSMasterCommunicator):
def waitInstanceStopped(self, instance_title): def waitInstanceStopped(self, instance_title):
error_message = self._waitInstance(instance_title, INSTANCE_STATE_STOPPED)["error_message"] error_message = self._waitInstance(instance_title, INSTANCE_STATE_STOPPED)["error_message"]
if error_message is not None: if error_message is not None:
self._logger(error_message) logger.error(error_message)
self._logger("Do you use instance state propagation in your project?") logger.error("Do you use instance state propagation in your project?")
raise ValueError(error_message) raise ValueError(error_message)
def waitInstanceDestroyed(self, instance_title): def waitInstanceDestroyed(self, instance_title):
error_message = self._waitInstance(instance_title, INSTANCE_STATE_DESTROYED)["error_message"] error_message = self._waitInstance(instance_title, INSTANCE_STATE_DESTROYED)["error_message"]
if error_message is not None: if error_message is not None:
self._logger(error_message) logger.error(error_message)
self._logger("Do you use instance state propagation in your project?") logger.error("Do you use instance state propagation in your project?")
raise ValueError(error_message) raise ValueError(error_message)
class SoftwareReleaseTester(SlapOSTester): class SoftwareReleaseTester(SlapOSTester):
...@@ -439,7 +439,6 @@ class SoftwareReleaseTester(SlapOSTester): ...@@ -439,7 +439,6 @@ class SoftwareReleaseTester(SlapOSTester):
def __init__(self, def __init__(self,
name, name,
logger,
slap, slap,
slap_order, slap_order,
slap_supply, slap_supply,
...@@ -450,7 +449,7 @@ class SoftwareReleaseTester(SlapOSTester): ...@@ -450,7 +449,7 @@ class SoftwareReleaseTester(SlapOSTester):
instance_timeout=3600, instance_timeout=3600,
): ):
super(SoftwareReleaseTester, self).__init__( super(SoftwareReleaseTester, self).__init__(
name, logger, slap, slap_order, slap_supply, url, computer_guid, request_kw) name, slap, slap_order, slap_supply, url, computer_guid, request_kw)
self.state = TESTER_STATE_INITIAL self.state = TESTER_STATE_INITIAL
self.transition_dict = { self.transition_dict = {
...@@ -536,7 +535,7 @@ class SoftwareReleaseTester(SlapOSTester): ...@@ -536,7 +535,7 @@ class SoftwareReleaseTester(SlapOSTester):
""" """
Interrupt a running test sequence, putting it in idle state. Interrupt a running test sequence, putting it in idle state.
""" """
self._logger('Invoking TearDown for %s@%s' % (self.url, self.name)) logger.info('Invoking TearDown for %s@%s', self.url, self.name)
if self.request_kw is not None: if self.request_kw is not None:
self._request(INSTANCE_STATE_DESTROYED) self._request(INSTANCE_STATE_DESTROYED)
if self.computer_guid is not None: if self.computer_guid is not None:
...@@ -548,7 +547,7 @@ class SoftwareReleaseTester(SlapOSTester): ...@@ -548,7 +547,7 @@ class SoftwareReleaseTester(SlapOSTester):
Check for missed deadlines (-> test failure), conditions for moving to Check for missed deadlines (-> test failure), conditions for moving to
next state, and actually moving to next state (executing its payload). next state, and actually moving to next state (executing its payload).
""" """
self._logger('[DEBUG] TIC') logger.debug('TIC')
deadline = self.deadline deadline = self.deadline
if deadline < now and deadline is not None: if deadline < now and deadline is not None:
...@@ -562,7 +561,7 @@ class SoftwareReleaseTester(SlapOSTester): ...@@ -562,7 +561,7 @@ class SoftwareReleaseTester(SlapOSTester):
instance_state is None or instance_state is None or
instance_state == self._getInstanceState()): instance_state == self._getInstanceState()):
self._logger('[DEBUG] Going to state %s (%r)', next_state, instance_state) logger.debug('Going to state %s (%r)', next_state, instance_state)
if next_state is None: if next_state is None:
return None return None
......
erp5/util/testnode/UnitTestRunner.py
View file @ 7fe1f931
...@@ -27,6 +27,7 @@ ...@@ -27,6 +27,7 @@
import os import os
import glob import glob
import json import json
from . import logger
from .ProcessManager import SubprocessError from .ProcessManager import SubprocessError
from .SlapOSControler import SlapOSControler from .SlapOSControler import SlapOSControler
from .Utils import createFolder from .Utils import createFolder
...@@ -49,21 +50,20 @@ class UnitTestRunner(object): ...@@ -49,21 +50,20 @@ class UnitTestRunner(object):
""" """
return SlapOSControler( return SlapOSControler(
working_directory, working_directory,
self.testnode.config, self.testnode.config)
self.testnode.log)
def _prepareSlapOS(self, working_directory, slapos_instance, log, def _prepareSlapOS(self, working_directory, slapos_instance,
create_partition=1, software_path_list=None, **kw): create_partition=1, software_path_list=None, **kw):
""" """
Launch slapos to build software and partitions Launch slapos to build software and partitions
""" """
slapproxy_log = os.path.join(self.testnode.config['log_directory'], slapproxy_log = os.path.join(self.testnode.config['log_directory'],
'slapproxy.log') 'slapproxy.log')
log('Configured slapproxy log to %r', slapproxy_log) logger.debug('Configured slapproxy log to %r', slapproxy_log)
reset_software = slapos_instance.retry_software_count > 10 reset_software = slapos_instance.retry_software_count > 10
if reset_software: if reset_software:
slapos_instance.retry_software_count = 0 slapos_instance.retry_software_count = 0
log('testnode, retry_software_count : %r', logger.info('testnode, retry_software_count: %r',
slapos_instance.retry_software_count) slapos_instance.retry_software_count)
# XXX Create a new controler because working_directory can be # XXX Create a new controler because working_directory can be
...@@ -80,12 +80,12 @@ class UnitTestRunner(object): ...@@ -80,12 +80,12 @@ class UnitTestRunner(object):
method_list.append("runComputerPartition") method_list.append("runComputerPartition")
for method_name in method_list: for method_name in method_list:
slapos_method = getattr(slapos_controler, method_name) slapos_method = getattr(slapos_controler, method_name)
log("Before status_dict = slapos_method(...)") logger.debug("Before status_dict = slapos_method(...)")
status_dict = slapos_method(self.testnode.config, status_dict = slapos_method(self.testnode.config,
environment=self.testnode.config['environment'], environment=self.testnode.config['environment'],
**kw) **kw)
log(status_dict) logger.info(status_dict)
log("After status_dict = slapos_method(...)") logger.debug("After status_dict = slapos_method(...)")
if status_dict['status_code'] != 0: if status_dict['status_code'] != 0:
slapos_instance.retry = True slapos_instance.retry = True
slapos_instance.retry_software_count += 1 slapos_instance.retry_software_count += 1
...@@ -103,7 +103,7 @@ class UnitTestRunner(object): ...@@ -103,7 +103,7 @@ class UnitTestRunner(object):
# instance. This is a hack which must be removed. # instance. This is a hack which must be removed.
config = self.testnode.config config = self.testnode.config
return self._prepareSlapOS(test_node_slapos.working_directory, return self._prepareSlapOS(test_node_slapos.working_directory,
test_node_slapos, self.testnode.log, create_partition=0, test_node_slapos, create_partition=0,
software_path_list=config.get("software_list"), software_path_list=config.get("software_list"),
cluster_configuration={ cluster_configuration={
'report-url': config.get("report-url", ""), 'report-url': config.get("report-url", ""),
...@@ -116,7 +116,7 @@ class UnitTestRunner(object): ...@@ -116,7 +116,7 @@ class UnitTestRunner(object):
Build softwares needed by testsuites Build softwares needed by testsuites
""" """
return self._prepareSlapOS(node_test_suite.working_directory, return self._prepareSlapOS(node_test_suite.working_directory,
node_test_suite, self.testnode.log, node_test_suite,
software_path_list=[node_test_suite.custom_profile_path], software_path_list=[node_test_suite.custom_profile_path],
cluster_configuration={'_': json.dumps(node_test_suite.cluster_configuration)}) cluster_configuration={'_': json.dumps(node_test_suite.cluster_configuration)})
...@@ -124,7 +124,7 @@ class UnitTestRunner(object): ...@@ -124,7 +124,7 @@ class UnitTestRunner(object):
return self._getSlapOSControler( return self._getSlapOSControler(
node_test_suite.working_directory).instance_root node_test_suite.working_directory).instance_root
def runTestSuite(self, node_test_suite, portal_url, log=None): def runTestSuite(self, node_test_suite, portal_url):
config = self.testnode.config config = self.testnode.config
run_test_suite_path_list = glob.glob( run_test_suite_path_list = glob.glob(
self.getInstanceRoot(node_test_suite) + "/*/bin/runTestSuite") self.getInstanceRoot(node_test_suite) + "/*/bin/runTestSuite")
......
erp5/util/testnode/Updater.py
View file @ 7fe1f931
...@@ -28,7 +28,7 @@ import errno ...@@ -28,7 +28,7 @@ import errno
import os import os
import re import re
import shutil import shutil
import sys from . import logger
from .ProcessManager import SubprocessError from .ProcessManager import SubprocessError
SVN_UP_REV = re.compile(r'^(?:At|Updated to) revision (\d+).$') SVN_UP_REV = re.compile(r'^(?:At|Updated to) revision (\d+).$')
...@@ -42,10 +42,9 @@ class Updater(object): ...@@ -42,10 +42,9 @@ class Updater(object):
_git_cache = {} _git_cache = {}
def __init__(self, repository_path, log, revision=None, git_binary='git', def __init__(self, repository_path, revision=None, git_binary='git',
branch=None, realtime_output=True, process_manager=None, url=None, branch=None, realtime_output=True, process_manager=None, url=None,
working_directory=None): working_directory=None):
self.log = log
self.revision = revision self.revision = revision
self._path_list = [] self._path_list = []
self.branch = branch self.branch = branch
...@@ -111,16 +110,16 @@ class Updater(object): ...@@ -111,16 +110,16 @@ class Updater(object):
git_repository_path = os.path.join(self.getRepositoryPath(), '.git') git_repository_path = os.path.join(self.getRepositoryPath(), '.git')
name = os.path.basename(os.path.normpath(self.getRepositoryPath())) name = os.path.basename(os.path.normpath(self.getRepositoryPath()))
git_repository_link_path = os.path.join(self.getRepositoryPath(), '%s.git' %name) git_repository_link_path = os.path.join(self.getRepositoryPath(), '%s.git' %name)
self.log("checking link %s -> %s..", logger.debug("checking link %s -> %s..",
git_repository_link_path, git_repository_path) git_repository_link_path, git_repository_path)
if ( not os.path.lexists(git_repository_link_path) and \ if ( not os.path.lexists(git_repository_link_path) and \
not os.path.exists(git_repository_link_path) ): not os.path.exists(git_repository_link_path) ):
try: try:
os.symlink(git_repository_path, git_repository_link_path) os.symlink(git_repository_path, git_repository_link_path)
self.log("link: %s -> %s created", logger.debug("link: %s -> %s created",
git_repository_link_path, git_repository_path) git_repository_link_path, git_repository_path)
except OSError: except OSError:
self.log("Cannot create link from %s -> %s", logger.error("Cannot create link from %s -> %s",
git_repository_link_path, git_repository_path) git_repository_link_path, git_repository_path)
def _git_find_rev(self, ref): def _git_find_rev(self, ref):
...@@ -148,7 +147,7 @@ class Updater(object): ...@@ -148,7 +147,7 @@ class Updater(object):
raise NotImplementedError raise NotImplementedError
def deleteRepository(self): def deleteRepository(self):
self.log("Wrong repository or wrong url, deleting repos %s", logger.info("Wrong repository or wrong url, deleting repos %s",
self.repository_path) self.repository_path)
shutil.rmtree(self.repository_path) shutil.rmtree(self.repository_path)
...@@ -162,7 +161,7 @@ class Updater(object): ...@@ -162,7 +161,7 @@ class Updater(object):
if remote_url == self.url: if remote_url == self.url:
correct_url = True correct_url = True
except SubprocessError: except SubprocessError:
self.log("SubprocessError", exc_info=sys.exc_info()) logger.exception("")
if not(correct_url): if not(correct_url):
self.deleteRepository() self.deleteRepository()
if not os.path.exists(self.repository_path): if not os.path.exists(self.repository_path):
......
erp5/util/testnode/__init__.py
View file @ 7fe1f931
...@@ -30,9 +30,12 @@ import logging ...@@ -30,9 +30,12 @@ import logging
import logging.handlers import logging.handlers
import os import os
from .testnode import TestNode log_formatter = logging.Formatter('%(asctime)s %(levelname)-8s %(message)s')
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
def main(*args): def main(*args):
from .testnode import TestNode
parser = argparse.ArgumentParser() parser = argparse.ArgumentParser()
parser.add_argument("configuration_file", nargs=1, type=argparse.FileType(), parser.add_argument("configuration_file", nargs=1, type=argparse.FileType(),
help="Configuration file.") help="Configuration file.")
...@@ -43,29 +46,24 @@ def main(*args): ...@@ -43,29 +46,24 @@ def main(*args):
parsed_argument = parser.parse_args(list(args)) parsed_argument = parser.parse_args(list(args))
else: else:
parsed_argument = parser.parse_args() parsed_argument = parser.parse_args()
logger_format = '%(asctime)s %(name)-13s: %(levelname)-8s %(message)s'
formatter = logging.Formatter(logger_format)
logging.basicConfig(level=logging.INFO,
format=logger_format)
logger = logging.getLogger('erp5testnode')
CONFIG = {
'logger': logger.info,
'partition_reference': 'test0',
}
if parsed_argument.console or parsed_argument.logfile: if parsed_argument.console or parsed_argument.logfile:
root = logging.getLogger()
def addHandler(handler):
handler.setFormatter(log_formatter)
root.addHandler(handler)
if parsed_argument.console: if parsed_argument.console:
logger.addHandler(logging.StreamHandler()) addHandler(logging.StreamHandler())
logger.info('Activated console output.')
if parsed_argument.logfile: if parsed_argument.logfile:
file_handler = logging.handlers.RotatingFileHandler( addHandler(logging.handlers.RotatingFileHandler(
filename=parsed_argument.logfile, filename=parsed_argument.logfile,
maxBytes=20000000, backupCount=4) maxBytes=20000000, backupCount=4))
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
logger.info('Activated logfile %r output', parsed_argument.logfile)
CONFIG['log_file'] = parsed_argument.logfile
else: else:
logger.addHandler(logging.NullHandler()) logger.disable(logging.CRITICAL)
CONFIG = {
'partition_reference': 'test0',
}
config = ConfigParser.SafeConfigParser() config = ConfigParser.SafeConfigParser()
# do not change case of option keys # do not change case of option keys
config.optionxform = str config.optionxform = str
...@@ -106,5 +104,4 @@ def main(*args): ...@@ -106,5 +104,4 @@ def main(*args):
CONFIG['software_list'] = filter(None, CONFIG['software_list'] = filter(None,
config.get("software_list", "path_list").split(",")) config.get("software_list", "path_list").split(","))
testnode = TestNode(logger.info, CONFIG) TestNode(CONFIG).run()
testnode.run()
erp5/util/testnode/testnode.py
View file @ 7fe1f931
This diff is collapsed.
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7