def __init__(self, message, client):
logger.debug("Message data: %s",
message.serialize(limit_reduction_script=True))
self.read_write_map = {"R": "read", "W": "write"}
self.message = message
self.client = client
self.reduction_log_stream = io.StringIO()
self.admin_log_stream = io.StringIO()
try:
self.data_file = windows_to_linux_path(self.validate_input('data'),
MISC["temp_root_directory"])
self.facility = self.validate_input('facility')
self.instrument = self.validate_input('instrument').upper()
self.proposal = str(int(
self.validate_input('rb_number'))) # Integer-string validation
self.run_number = str(int(self.validate_input('run_number')))
self.reduction_script = self.validate_input('reduction_script')
self.reduction_arguments = self.validate_input(
'reduction_arguments')
except ValueError:
logger.info('JSON data error', exc_info=True)
raise
def main(): # pragma: no cover
""" Main method, starts consumer. """
logger.info("Start post process asynchronous listener!")
# pylint: disable=maybe-no-member
reactor.callWhenRunning(Consumer().run)
reactor.run()
logger.info("Stop post process asynchronous listener!")
def create_final_result_and_log_directory(self, temporary_root_directory,
reduce_dir):
"""
Create final result and final log directories, stripping temporary path off of the
front of temporary directories
:param temporary_root_directory: (str) temporary root directory
:param reduce_dir: (str) final reduce directory
:return (tuple) - (str, str) final result and final log directory paths
"""
# validate dir before slicing
if reduce_dir.startswith(temporary_root_directory):
result_directory = reduce_dir[len(temporary_root_directory):]
else:
return ValueError(
"The reduce directory does not start by following the expected "
"format: %s \n", temporary_root_directory)
final_result_directory = self._new_reduction_data_path(
result_directory)
final_log_directory = append_path(final_result_directory,
['reduction_log'])
logger.info("Final Result Directory = %s", final_result_directory)
logger.info("Final log directory: %s", final_log_directory)
return final_result_directory, final_log_directory
def determine_reduction_status(self):
"""
Determine which message type to log and send to AMQ, triggering exception if job failed
"""
if self.message.message is not None:
# This means an error has been produced somewhere
try:
if 'skip' in self.message.message.lower():
self.send_reduction_message(
message="Skipped",
amq_message=ACTIVEMQ_SETTINGS.reduction_skipped)
else:
self.send_reduction_message(
message="Error",
amq_message=ACTIVEMQ_SETTINGS.reduction_error)
except Exception as exp2:
logger.info("Failed to send to queue! - %s - %s", exp2,
repr(exp2))
finally:
logger.info("Reduction job failed")
else:
# Reduction has successfully completed
self.send_reduction_message(
message="Complete",
amq_message=ACTIVEMQ_SETTINGS.reduction_complete)
def hold_message(self, destination, data, headers):
""" Calls the reduction script. """
logger.debug("holding thread")
message = Message()
message.populate(data)
self.update_child_process_list()
if not self.should_proceed(message): # wait while the run shouldn't proceed
# pylint: disable=maybe-no-member
reactor.callLater(10, self.hold_message, # pragma: no cover
destination, data,
headers)
return
if self.should_cancel(message):
self.cancel_run(message) # pylint: disable=maybe-no-member
return
if not os.path.isfile(MISC['post_process_directory']):
logger.warning("Could not find autoreduction post processing file "
"- please contact a system administrator")
python_path = sys.executable
logger.info("Calling: %s %s %s %s",
python_path, MISC['post_process_directory'], destination,
message.serialize(limit_reduction_script=True))
proc = subprocess.Popen([python_path,
MISC['post_process_directory'],
destination,
message.serialize()]) # PPA expects json data
self.add_process(proc, message)
def should_proceed(self, message):
""" Check whether there's a job already running with the same RB. """
if message.rb_number in self.rb_list:
logger.info("Duplicate RB run #%s, waiting for the first to finish.",
message.rb_number)
return False
# else return True
return True
def delete_temp_directory(temp_result_dir):
""" Remove temporary working directory """
logger.info("Remove temp dir %s", temp_result_dir)
try:
shutil.rmtree(temp_result_dir, ignore_errors=True)
except:
logger.info("Unable to remove temporary directory - %s",
temp_result_dir)
def create_directory(list_of_paths):
"""
Creates directory that should exist if it does not already.
:param list_of_paths: (list) directories that should be writeable
"""
# try to make directories which should exist
for path in filter(lambda p: not os.path.isdir(p), list_of_paths):
logger.info(
"path %s does not exist. \n "
"Attempting to make path.", path)
os.makedirs(path)
def send_reduction_message(self, message, amq_message):
"""Send/Update AMQ reduction message
:param message: (str) amq reduction status
:param amq_message: (str) reduction status path
"""
try:
logger.debug("Calling: %s\n%s", amq_message,
self.message.serialize(limit_reduction_script=True))
self.client.send(amq_message, self.message)
logger.info("Reduction: %s", message)
except AttributeError:
logger.debug("Failed to find send reduction message: %s",
amq_message)
def copy_temp_directory(self, temp_result_dir, copy_destination):
"""
Method that copies the temporary files held in results_directory to CEPH/archive, replacing
old data if it exists.
EXCITATION instrument are treated as a special case because they're done with run number
sub-folders.
"""
if os.path.isdir(copy_destination) \
and self.instrument not in MISC["excitation_instruments"]:
self._remove_directory(copy_destination)
self.message.reduction_data.append(copy_destination)
logger.info("Moving %s to %s", temp_result_dir, copy_destination)
try:
self._copy_tree(temp_result_dir, copy_destination)
except Exception as exp:
self.log_and_message("Unable to copy to %s - %s" %
(copy_destination, exp))
def verify_directory_access(self, location, access_type):
"""
Tests directory access for a given location and type of access
:param location: (str) directory location
:param access_type: (str) type of access to location e.g "W", "R"
"""
if not os.access(
location, getattr(sys.modules[os.__name__],
f"{access_type}_OK")):
if not os.access(location, os.F_OK):
problem = "does not exist"
else:
problem = "no %s access", access_type
raise Exception(
"Couldn't %s %s - %s" %
(self.read_write_map[access_type], location, problem))
logger.info("Successful %s access to %s",
self.read_write_map[access_type], location)
return True
def _new_reduction_data_path(self, path):
"""
Creates a pathname for the reduction data, factoring in existing run data.
:param path: Base path for the run data (should follow convention, without version number)
:return: A pathname for the new reduction data
"""
logger.info("_new_reduction_data_path argument: %s", path)
# if there is an 'overwrite' key/member with a None/False value
if not self.message.overwrite:
if os.path.isdir(path): # if the given path already exists..
contents = os.listdir(path)
highest_vers = -1
for item in contents: # ..for every item, if it's a dir and a int..
if os.path.isdir(os.path.join(path, item)):
try: # ..store the highest int
vers = int(item)
highest_vers = max(highest_vers, vers)
except ValueError:
pass
this_vers = highest_vers + 1
return append_path(path, [str(this_vers)])
# (else) if no overwrite, overwrite true, or the path doesn't exist: return version 0 path
return append_path(path, "0")
def main():
""" Main method. """
queue_client = QueueClient()
try:
logger.info("PostProcessAdmin Connecting to ActiveMQ")
queue_client.connect()
logger.info("PostProcessAdmin Successfully Connected to ActiveMQ")
destination, data = sys.argv[1:3] # pylint: disable=unbalanced-tuple-unpacking
message = Message()
message.populate(data)
logger.info("destination: %s", destination)
logger.info("message: %s",
message.serialize(limit_reduction_script=True))
try:
post_proc = PostProcessAdmin(message, queue_client)
log_stream_handler = logging.StreamHandler(
post_proc.admin_log_stream)
logger.addHandler(log_stream_handler)
if destination == '/queue/ReductionPending':
post_proc.reduce()
except ValueError as exp:
message.message = str(
exp) # Note: I believe this should be .message
logger.info("Message data error: %s",
message.serialize(limit_reduction_script=True))
raise
except Exception as exp:
logger.info("PostProcessAdmin error: %s", str(exp))
raise
finally:
try:
logger.removeHandler(log_stream_handler)
except:
pass
except Exception as exp:
logger.info("Something went wrong: %s", str(exp))
try:
queue_client.send(ACTIVEMQ_SETTINGS.reduction_error, message)
logger.info("Called %s ---- %s", ACTIVEMQ_SETTINGS.reduction_error,
message.serialize(limit_reduction_script=True))
finally:
sys.exit()
def log_and_message(self, msg):
""" Helper function to add text to the outgoing activemq message and to the info logs """
logger.info(msg)
if self.message.message == "" or self.message.message is None:
# Only send back first message as there is a char limit
self.message.message = msg
def reduce(self):
"""Start the reduction job."""
# pylint: disable=too-many-nested-blocks
self.message.software = self._get_mantid_version()
try:
# log and update AMQ message to reduction started
self.send_reduction_message(
message="started",
amq_message=ACTIVEMQ_SETTINGS.reduction_started)
# Specify instrument directories - if excitation instrument remove run_number from dir
no_run_number_directory = False
if self.instrument in MISC["excitation_instruments"]:
no_run_number_directory = True
instrument_output_directory = MISC["ceph_directory"] % (
self.instrument, self.proposal, self.run_number)
reduce_result_dir = self.specify_instrument_directories(
instrument_output_directory=instrument_output_directory,
no_run_number_directory=no_run_number_directory,
temporary_directory=MISC["temp_root_directory"])
if self.message.description is not None:
logger.info("DESCRIPTION: %s", self.message.description)
log_dir = reduce_result_dir + "/reduction_log/"
# strip temp path off front of the temp directory to get the final archives directory
final_result_dir, final_log_dir = self.create_final_result_and_log_directory(
temporary_root_directory=MISC["temp_root_directory"],
reduce_dir=reduce_result_dir)
# Test path exists and access
should_be_writeable = [
reduce_result_dir, log_dir, final_result_dir, final_log_dir
]
should_be_readable = [self.data_file]
# Try to create directory if does not exist
self.create_directory(should_be_writeable)
# Check permissions of paths which should be writeable and readable
self.write_and_readability_checks(
directory_list=should_be_writeable, read_write="W")
self.write_and_readability_checks(
directory_list=should_be_readable, read_write="R")
self.message.reduction_data = []
logger.info("----------------")
logger.info("Reduction script: %s ...", self.reduction_script[:50])
logger.info("Result dir: %s", reduce_result_dir)
logger.info("Log dir: %s", log_dir)
logger.info(
"Out log: %s",
self.create_log_path(file_name_with_extension="Script.out",
log_directory=log_dir))
logger.info("Datafile: %s", self.data_file)
logger.info("----------------")
logger.info("Reduction subprocess started.")
logger.info(reduce_result_dir)
out_directories = None
# Create script out and mantid log paths
script_out = self.create_log_path(
file_name_with_extension="Script.out", log_directory=log_dir)
mantid_log = self.create_log_path(
file_name_with_extension="Mantid.log", log_directory=log_dir)
# Load reduction script as module and validate
out_directories = self.validate_reduction_as_module(
script_out=script_out,
mantid_log=mantid_log,
reduce_result=reduce_result_dir,
final_result=final_result_dir)
self.copy_temp_directory(reduce_result_dir, final_result_dir)
# Copy to additional directories if present in reduce script
self.additional_save_directories_check(
out_directories=out_directories,
reduce_result=reduce_result_dir)
# no longer a need for the temp directory used for storing of reduction results
self.delete_temp_directory(reduce_result_dir)
except SkippedRunException as skip_exception:
logger.info("Run %s has been skipped on %s",
self.message.run_number, self.message.instrument)
self.message.message = "Reduction Skipped: %s" % str(
skip_exception)
except Exception as exp:
logger.error(traceback.format_exc())
self.message.message = "REDUCTION Error: %s " % exp
self.message.reduction_log = self.reduction_log_stream.getvalue()
self.message.admin_log = self.admin_log_stream.getvalue()
self.determine_reduction_status(
) # Send AMQ reduce status message Skipped|Error|Complete
def add_process(self, proc, message):
""" Add child process to list. """
logger.info("Entered add_process. proc=%s message=%s", proc,
message.serialize(limit_reduction_script=True))
self.proc_list.append(proc)
self.rb_list.append(message.rb_number)
def add_process(self, proc, message):
""" Add child process to list. """
logger.info("Entered add_process. proc=%s message=%s", proc, message)
self.proc_list.append(proc)
self.rb_list.append(message.rb_number)
