def on_message(self, headers, message):
""" This method is where consumed messages are dealt with. It will
consume a message. """
destination = headers["destination"]
self._priority = headers["priority"]
self._logger.info("Destination: %s Priority: %s", destination,
self._priority)
# Load the JSON message and header into dictionaries
try:
if not isinstance(message, Message):
json_string = message
message = Message()
message.populate(json_string)
except ValueError:
self._logger.error("Could not decode message from %s", destination)
self._logger.error(sys.exc_info()[1])
return
try:
if destination == '/queue/DataReady':
self._message_handler.data_ready(message)
elif destination == '/queue/ReductionStarted':
self._message_handler.reduction_started(message)
elif destination == '/queue/ReductionComplete':
self._message_handler.reduction_complete(message)
elif destination == '/queue/ReductionError':
self._message_handler.reduction_error(message)
elif destination == '/queue/ReductionSkipped':
self._message_handler.reduction_skipped(message)
else:
self._logger.warning(
"Received a message on an unknown topic '%s'", destination)
except InvalidStateException as exp:
self._logger.error("Stomp Client message handling exception:"
"%s %s", type(exp).__name__, exp)
self._logger.error(traceback.format_exc())
def run(self) -> Message:
"""
Runs the reduction subprocess
"""
try:
# We need to run the reduction in a new process, otherwise scripts
# will fail when they use things that require access to a main loop
# e.g. a GUI main loop, for matplotlib or Mantid
python_path = sys.executable
with tempfile.NamedTemporaryFile("w+") as temp_output_file:
args = [
python_path, RUNNER_PATH,
self.message.serialize(), temp_output_file.name
]
logging.info(
"Calling: %s %s %s %s", python_path, RUNNER_PATH,
self.message.serialize(limit_reduction_script=True),
temp_output_file.name)
# run process until finished and check the exit code for success
subprocess.run(args, check=True)
# the subprocess will write out the result message in the tempfile, read it back
result_message_raw = temp_output_file.file.read()
result_message = Message()
result_message.populate(result_message_raw)
except subprocess.CalledProcessError:
logging.error("Processing encountered an error: %s",
traceback.format_exc())
self.message.message = f"Processing encountered an error: {traceback.format_exc()}"
result_message = self.message
return result_message
def on_message(self, headers, message):
""" This method is where consumed messages are dealt with. It will
consume a message. """
with self.mark_processing():
destination = headers["destination"]
priority = headers["priority"]
self.logger.info("Destination: %s Priority: %s", destination, priority)
# Load the JSON message and header into dictionaries
try:
if not isinstance(message, Message):
json_string = message
message = Message()
message.populate(json_string)
except ValueError:
self.logger.error("Could not decode message from %s\n\n%s", destination, traceback.format_exc())
return
# the connection is configured with client-individual, meaning that each client
# has to submit an acknowledgement for receiving the message
# (otherwise I think that it is not removed from the queue but I am not sure about that)
self.client.ack(headers["message-id"], headers["subscription"])
try:
if destination == '/queue/DataReady':
self.message_handler.data_ready(message)
else:
self.logger.error("Received a message on an unknown topic '%s'", destination)
except Exception as exp: # pylint:disable=broad-except
self.logger.error("Unhandled exception encountered: %s %s\n\n%s",
type(exp).__name__, exp, traceback.format_exc())
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 test_populate_with_invalid_key(self, mock_log):
"""
Test: A warning is logged
When: An unknown key is used to populate the Message
"""
args = {'unknown': True}
msg = Message()
msg.populate(args)
mock_log.assert_called_once()
def test_populate_with_invalid_key(self):
"""
Test: A warning is logged
When: An unknown key is used to populate the Message
"""
args = {'unknown': True}
msg = Message()
with self.assertRaises(ValueError):
msg.populate(args)
def test_on_message_can_receive_a_prepopulated_message(self):
"Test receiving an already constructed Message object"
message = Message()
message.populate({"run_number": 1234567})
self.listener.on_message(self.headers, message)
self.assertFalse(self.listener.is_processing_message())
self.mocked_logger.info.assert_called_once()
self.mocked_client.ack.assert_called_once_with(
self.headers["message-id"], self.headers["subscription"])
self.mocked_handler.data_ready.assert_called_once()
self.assertIsInstance(self.mocked_handler.data_ready.call_args[0][0],
Message)
class TestReductionProcessManager(unittest.TestCase):
def setUp(self) -> None:
self.data = {
'data': '\\\\isis\\inst$\\data.nxs',
'facility': 'ISIS',
'instrument': 'GEM',
'rb_number': '1234',
'run_number': '4321',
'reduction_script':
'print(\'hello\')', # not actually used for the reduction
'reduction_arguments': 'None'
}
self.message = Message()
self.message.populate(self.data)
def test_init(self):
"Test that the constructor is doing what's expected"
rpm = ReductionProcessManager(self.message)
assert rpm.message == self.message
@patch(
'queue_processors.queue_processor.reduction.process_manager.subprocess.run'
)
def test_run_subprocess_error(self, subprocess_run: Mock):
"""Test proper handling of a subprocess encountering an error"""
def side_effect(args, **_kwargs):
raise CalledProcessError(1, args)
subprocess_run.side_effect = side_effect
rpm = ReductionProcessManager(self.message)
rpm.run()
subprocess_run.assert_called_once()
assert "Processing encountered an error" in rpm.message.message
@patch(
'queue_processors.queue_processor.reduction.process_manager.subprocess.run'
)
def test_run(self, subprocess_run: Mock):
"""Tests success path - it uses side effect to set the expected output file rather than raise an exception"""
def side_effect(args, **_kwargs):
with open(args[-1], 'w') as tmpfile:
tmpfile.write(self.message.serialize())
subprocess_run.side_effect = side_effect
rpm = ReductionProcessManager(self.message)
result_message = rpm.run()
assert result_message == self.message
def on_message(self, headers, data):
""" handles message consuming. It will consume a message. """
destination = headers['destination']
logger.debug("Received frame destination: %s", destination)
logger.debug("Received frame priority: %s", headers["priority"])
self.update_child_process_list()
message = Message()
message.populate(data)
if message.cancel:
self.add_cancel(message)
return
self.hold_message(destination, data, headers)
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 main():
"""
This is the entrypoint when a reduction is started. This is run in a subprocess from
ReductionProcessManager, and the required parameters to perform the reduction are passed
as process arguments.
Additionally, the resulting Message is written to a temporary file which the
parent process reads back to mark the result of the reduction run in the DB.
"""
data, temp_output_file = sys.argv[1], sys.argv[2]
try:
message = Message()
message.populate(data)
except ValueError as exp:
logger.error("Could not populate message from data: %s", str(exp))
raise
try:
reduction = ReductionRunner(message)
except Exception as exp:
message.message = str(exp)
logger.info("Message data error: %s",
message.serialize(limit_reduction_script=True))
raise
log_stream_handler = logging.StreamHandler(reduction.admin_log_stream)
logger.addHandler(log_stream_handler)
try:
reduction.reduce()
# write out the reduction message
with open(temp_output_file, "w") as out_file:
out_file.write(reduction.message.serialize())
except Exception as exp:
logger.info("ReductionRunner error: %s", str(exp))
raise
finally:
logger.removeHandler(log_stream_handler)
class TestPostProcessAdmin(unittest.TestCase):
"""Unit tests for Post Process Admin"""
DIR = "queue_processors.autoreduction_processor"
def setUp(self):
"""Setup values for Post-Process Admin"""
self.data = {
'data': '\\\\isis\\inst$\\data.nxs',
'facility': 'ISIS',
'instrument': 'GEM',
'rb_number': '1234',
'run_number': '4321',
'reduction_script': 'print(\'hello\')',
'reduction_arguments': 'None'
}
self.test_fname = "111.txt"
self.test_root = os.path.join("instrument", "GEM", "RBNumber",
"RB2010163", "autoreduced", "111")
self.test_paths = [
os.path.join(self.test_root, "0"),
os.path.join(self.test_root, "1"),
os.path.join(self.test_root, "2")
]
self.message = Message()
self.message.populate(self.data)
self.ceph_directory = MISC['ceph_directory'] % (
self.data["instrument"], self.data["rb_number"],
self.data["run_number"])
self.temporary_directory = MISC['temp_root_directory']
self.log_and_err_name = f"RB{self.data['rb_number']}Run{self.data['run_number']}"
self.reduce_result_dir = self.temporary_directory + self.ceph_directory
def tearDown(self):
"""Teardown of test directory structure"""
self.teardown_test_dir_structure()
def teardown_test_dir_structure(self):
"""
Removes test directory structure (if one exists) from the root
"""
abs_test_root = os.path.join(os.getcwd(), self.test_root)
if os.path.isdir(abs_test_root):
shutil.rmtree(self.test_root)
def setup_test_dir_structure(self, test_dirs):
"""
Sets up a directory structure within the test environment.
Writes a file within each each directory given
:param test_dirs: The directories to create
"""
for directory in test_dirs:
abs_dir = os.path.join(os.getcwd(), directory)
if not os.path.isdir(abs_dir):
os.makedirs(abs_dir)
abs_path = os.path.join(abs_dir, self.test_fname)
with open(abs_path, 'w') as file:
file.write("test file")
def test_init(self):
"""
Test: init parameters are as expected
When: called with expected arguments
"""
ppa = PostProcessAdmin(self.message, None)
self.assertEqual(ppa.message, self.message)
self.assertEqual(ppa.client, None)
self.assertIsNotNone(ppa.reduction_log_stream)
self.assertIsNotNone(ppa.admin_log_stream)
self.assertEqual(ppa.data_file, '/isis/data.nxs')
self.assertEqual(ppa.facility, 'ISIS')
self.assertEqual(ppa.instrument, 'GEM')
self.assertEqual(ppa.proposal, '1234')
self.assertEqual(ppa.run_number, '4321')
self.assertEqual(ppa.reduction_script, 'print(\'hello\')')
self.assertEqual(ppa.reduction_arguments, 'None')
def test_replace_variables(self):
"""Test replacement of variables"""
print("Should be Unit tested")
def test_load_reduction_script(self):
"""
Test: reduction script location is correct
When: reduction script loaded for a given instrument
"""
ppa = PostProcessAdmin(self.message, None)
file_path = ppa._load_reduction_script('WISH')
self.assertEqual(
file_path,
os.path.join(MISC['scripts_directory'] % 'WISH', 'reduce.py'))
def test_specify_instrument_directories_invalid(self):
"""
Test: Error is returned
When: called with invalid directory format
"""
ppa = PostProcessAdmin(self.message, None)
ceph_directory = MISC["ceph_directory"] % (ppa.instrument,
ppa.proposal, 'invalid')
actual = ppa.specify_instrument_directories(
instrument_output_directory=ceph_directory,
no_run_number_directory=True,
temporary_directory=MISC["temp_root_directory"])
self.assertIsInstance(actual, ValueError)
def test_specify_instrument_directories(self):
"""
Test: Expected instrument, stripped of run number if excitation returned
When: called
"""
ppa = PostProcessAdmin(self.message, None)
ceph_directory = MISC['ceph_directory'] % (
ppa.instrument, ppa.proposal, ppa.run_number)
temporary_directory = MISC['temp_root_directory']
actual = ppa.specify_instrument_directories(
instrument_output_directory=ceph_directory,
no_run_number_directory=True,
temporary_directory=temporary_directory)
actual_directory_list = [i for i in actual.split('/') if i]
expected_directory_list = [i for i in ceph_directory.split('/') if i]
self.assertEqual(expected_directory_list[-5:],
actual_directory_list[-5:])
self.assertEqual(temporary_directory, f"/{actual_directory_list[0]}")
@patch(DIR + '.autoreduction_logging_setup.logger.info')
@patch(DIR + '.autoreduction_logging_setup.logger.debug')
def test_send_reduction_message_(self, mock_log_debug, mock_log_info):
"""
Test: reduction status message has been sent and logged
When: called within reduce method
"""
amq_messages = [
attr for attr in dir(ActiveMQSettings)
if not callable(getattr(ActiveMQSettings, attr))
and attr.startswith("reduction")
]
amq_client_mock = Mock()
ppa = PostProcessAdmin(self.message, amq_client_mock)
for message in amq_messages:
amq_message = getattr(ACTIVEMQ_SETTINGS, message)
ppa.send_reduction_message(message="status",
amq_message=amq_message)
mock_log_debug.assert_called_with(
"Calling: %s\n%s", amq_message,
self.message.serialize(limit_reduction_script=True))
amq_client_mock.send.assert_called_with(amq_message, ppa.message)
self.assertEqual(len(amq_messages), amq_client_mock.send.call_count)
mock_log_info.assert_called_with("Reduction: %s", 'status')
@patch(DIR + '.autoreduction_logging_setup.logger.debug')
def test_send_reduction_message_exception(self, mock_log_debug):
"""
Test: reduction status message has been sent and logged
When: called within reduce method
"""
amq_client_mock = Mock()
amq_client_mock.send.return_value = Exception
amq_message = "invalid"
ppa = PostProcessAdmin(self.message, amq_message)
ppa.send_reduction_message(message="status", amq_message=amq_message)
mock_log_debug.assert_called_with(
"Failed to find send reduction message: %s", amq_message)
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.send_reduction_message")
def test_determine_reduction_status_problem(self, mock_srm):
"""
Test: check the correct reduction message is used
When: when calling send_reduction_message() for each failed use case
"""
messages = [("Skipped", "Run has been skipped in script",
ACTIVEMQ_SETTINGS.reduction_skipped),
("Error", "Permission error: ",
ACTIVEMQ_SETTINGS.reduction_error)]
# message_status = ["skipped", "error"]
amq_client_mock = Mock()
for message in messages:
self.message.message = message[1]
ppa = PostProcessAdmin(self.message, amq_client_mock)
ppa.determine_reduction_status()
mock_srm.assert_called_with(message=message[0],
amq_message=message[2])
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.send_reduction_message")
def test_determine_reduction_status_complete(self, mock_srm):
"""
Test: check the correct reduction message is used
When: when calling send_reduction_message() with complete status
"""
# message_status = ["skipped", "error"]
amq_client_mock = Mock()
self.message.message = None
ppa = PostProcessAdmin(self.message, amq_client_mock)
ppa.determine_reduction_status()
mock_srm.assert_called_with(
message="Complete",
amq_message=ACTIVEMQ_SETTINGS.reduction_complete)
@patch('logging.Logger.info')
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.send_reduction_message")
def test_determine_reduction_status_exception(self, mock_srm, mock_log):
"""
Test: Assert correct number of logs are performed when
When: exception triggered by send_reduction_message
"""
amq_client_mock = Mock()
self.message.message = False
mock_srm.return_value = Exception("invalid")
ppa = PostProcessAdmin(self.message, amq_client_mock)
ppa.determine_reduction_status()
self.assertEqual(mock_log.call_count, 2)
def test_reduction_script_location(self):
"""
Test: Assert reduction location is correct
When: called for a given instrument
"""
location = PostProcessAdmin._reduction_script_location('WISH')
self.assertEqual(location, MISC['scripts_directory'] % 'WISH')
@patch(
f"{DIR}.post_process_admin.PostProcessAdmin.specify_instrument_directories"
)
def test_create_log_path(self, mock_instrument_output_dir):
"""
Test: create_log_path returns a directory path following a specified format
When: called
"""
ppa = PostProcessAdmin(self.message, None)
file_name = "test.log"
log_directory = f"{mock_instrument_output_dir}/reduction_log/"
log_and_error_name = f"RB_{ppa.proposal}_Run_{ppa.run_number}_"
actual = ppa.create_log_path(file_name_with_extension=file_name,
log_directory=log_directory)
expected = PosixPath(f"{log_directory}{log_and_error_name}{file_name}")
self.assertEqual(expected, actual)
@patch('logging.Logger.info')
@patch('os.access')
def test_verify_directory_access(self, mock_os_access, mock_logging):
"""
Test: True is returned if there is no problem with directory path and logged as successful
When: Called with valid path with write access
"""
ppa = PostProcessAdmin(self.message, None)
location = "directory/path/"
mock_os_access.return_value = True
actual = ppa.verify_directory_access(location, "W")
expected_logs_called_with = [
call("Successful %s access to %s", "write", location)
]
self.assertTrue(actual)
self.assertEqual(expected_logs_called_with,
mock_logging.call_args_list)
@patch('os.access')
def test_verify_directory_access_invalid(self, mock_os_access):
"""
Test: OSError is raised if there is a problem with directory path access
When: Called with valid path
"""
ppa = PostProcessAdmin(self.message, None)
location = "directory/path/"
mock_os_access.return_value = False
with self.assertRaises(Exception):
ppa.verify_directory_access(location, 'W')
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.verify_directory_access"
)
def test_write_and_readability_checks(self, mock_vda):
"""
Test: True is returned if there is no problem with directory path and logged as successful
When: Called with valid path and access type
"""
ppa = PostProcessAdmin(self.message, None)
write_list = ["directory/path/"]
mock_vda.return_type = True
actual_write = ppa.write_and_readability_checks(write_list, 'W')
self.assertTrue(actual_write)
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.verify_directory_access"
)
def test_write_and_readability_checks_invalid_path(self, mock_vda):
"""
Test: Exception is raised
When: Called with invalid path/incorrect path access
"""
ppa = PostProcessAdmin(self.message, None)
write_list = ["directory/path/"]
mock_vda.return_value = False
with self.assertRaises(OSError):
ppa.write_and_readability_checks(write_list, 'W')
def test_write_and_readability_checks_invalid_input(self):
"""
Test: ValueError returned
When: Called with invalid read_write argument
"""
ppa = PostProcessAdmin(self.message, None)
write_list = ["directory/path/"]
with self.assertRaises(KeyError):
ppa.write_and_readability_checks(write_list, 'INVALID_KEY')
@patch('os.access')
@patch('os.path.isdir')
@patch(DIR +
'.post_process_admin.PostProcessAdmin.write_and_readability_checks')
def test_create_directory(self, mock_wrc, mock_dir, mock_os_access):
"""
Test: None returned
When: Path checks pass
"""
mock_wrc.return_value = True
mock_dir.return_value = True
mock_os_access.return_value = False
ppa = PostProcessAdmin(self.message, None)
self.assertFalse(
ppa.create_directory(list_of_paths=['should/be/writeable']))
@patch('logging.Logger.info')
@patch(
f"{DIR}.post_process_admin.PostProcessAdmin._new_reduction_data_path")
def test_result_and_log_directory(self, mock_nrdp, mock_logging):
"""
Test: final result and log directories are returned
When: called with temp root directory, result and log locations
"""
ppa = PostProcessAdmin(self.message, None)
instrument_output_dir = MISC["ceph_directory"] % (
ppa.instrument, ppa.proposal, ppa.run_number)
mock_nrdp.return_value = append_path(instrument_output_dir, "0")
instrument_output_directory = instrument_output_dir[:
instrument_output_dir
.rfind('/') + 1]
reduce_directory = MISC[
"temp_root_directory"] + instrument_output_directory
reduction_log = "/reduction_log/"
actual_final_result, actual_log = ppa.create_final_result_and_log_directory(
temporary_root_directory=MISC["temp_root_directory"],
reduce_dir=reduce_directory)
expected_log = f"{instrument_output_directory}0{reduction_log}"
expected_logs_called_with = [
call("Final Result Directory = %s", actual_final_result),
call("Final log directory: %s", actual_log)
]
mock_nrdp.assert_called_once_with(instrument_output_dir)
self.assertEqual(mock_logging.call_count, 2)
self.assertEqual(mock_logging.call_args_list,
expected_logs_called_with)
self.assertEqual(expected_log, actual_log)
def test_result_and_log_directory_incorrect(self):
"""
Test: Value error is raised when
When: Result_and_log_directory called with invalid path format
"""
ppa = PostProcessAdmin(self.message, None)
instrument_output_dir = MISC["ceph_directory"] % (
ppa.instrument, ppa.proposal, ppa.run_number)
incorrect_temporary_directory = "incorrect_directory_format"
instrument_output_directory = instrument_output_dir[:
instrument_output_dir
.rfind('/') + 1]
reduce_directory = MISC[
"temp_root_directory"] + instrument_output_directory
actual_final_result = ppa.create_final_result_and_log_directory(
temporary_root_directory=incorrect_temporary_directory,
reduce_dir=reduce_directory)
self.assertIsInstance(actual_final_result, ValueError)
def test_check_for_skipped_runs(self):
"""
This method will be left untested for the moment due to the complexity of mocking
importlib.util usage effectively and current time constraints on the overall refactoring of
reduce().
This should be tested correctly later as it would be a very useful, and crucial test to
have!
See here:
Test:
When:
"""
print(
"TODO: COMPLETE THIS TEST METHOD WHEN POSSIBLE AS CURRENTLY UNTESTED"
)
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.check_for_skipped_runs")
def test_reduction_as_module(self, _):
"""
This method will be left untested for the moment due to the complexity of mocking
importlib.util usage effectively and current time constraints on the overall refactoring of
reduce().
This should be tested correctly later as it would be a very useful, and crucial test to
have!
See here:
Test:
When:
"""
print(
"TODO: COMPLETE THIS TEST METHOD WHEN POSSIBLE AS CURRENTLY UNTESTED"
)
@patch("builtins.open", mock_open(read_data="data"))
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.delete_temp_directory")
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.copy_temp_directory")
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.reduction_as_module")
@patch(
f"{DIR}.post_process_admin.PostProcessAdmin.specify_instrument_directories"
)
def test_validate_reduction_as_module_exp(self, mock_sid, mock_ram,
mock_ctd, mock_dtd, *_):
"""
Test: Exception is called and temporary dir path handling takes place
When: Reduction fails to load as module
"""
mock_ram.side_effect = Exception('warning')
log_dir = mock_sid + "/reduction_log"
error_str = f"Error in user reduction script: {type(Exception('warning')).__name__} - " \
f"{Exception('warning')}"
ppa = PostProcessAdmin(self.message, None)
script_out = os.path.join(log_dir,
f"{self.log_and_err_name}Script.out")
mantid_log = os.path.join(log_dir,
f"{self.log_and_err_name}Mantid.log")
instrument_output_directory = self.ceph_directory[:self.ceph_directory.
rfind('/') + 1]
final_result_dir = instrument_output_directory + "0/"
actual = ppa.validate_reduction_as_module(
script_out=script_out,
mantid_log=mantid_log,
reduce_result=self.reduce_result_dir,
final_result=final_result_dir)
self.assertEqual(open(script_out).read(), "data")
mock_ram.assert_called_with(self.reduce_result_dir)
mock_ctd.assert_called()
mock_dtd.assert_called()
self.assertEqual(str(Exception(error_str)), str(actual))
@patch("builtins.open")
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.delete_temp_directory")
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.copy_temp_directory")
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.reduction_as_module")
@patch(
f"{DIR}.post_process_admin.PostProcessAdmin.specify_instrument_directories"
)
def test_validate_reduction_as_module(self, mock_sid, mock_ram, mock_ctd,
mock_dtd, _):
"""
Test: reduce_result returned
When: Called with correct arguments and no error produced by reduction_as_module()
"""
ppa = PostProcessAdmin(self.message, None)
mock_ram.return_value = True
log_dir = mock_sid + "/reduction_log"
script_out = os.path.join(log_dir,
f"{self.log_and_err_name}Script.out")
mantid_log = os.path.join(log_dir,
f"{self.log_and_err_name}Mantid.log")
instrument_output_directory = self.ceph_directory[:self.ceph_directory.
rfind('/') + 1]
final_result_dir = instrument_output_directory + "0/"
actual = ppa.validate_reduction_as_module(
script_out=script_out,
mantid_log=mantid_log,
reduce_result=self.reduce_result_dir,
final_result=final_result_dir)
mock_ram.assert_called_with(self.reduce_result_dir)
self.assertEqual(mock_ctd.call_count, 0)
self.assertEqual(mock_dtd.call_count, 0)
self.assertEqual(True, actual)
@patch(DIR + '.post_process_admin.PostProcessAdmin.reduction_as_module')
@patch(DIR + '.post_process_admin.PostProcessAdmin._remove_directory')
@patch(DIR + '.post_process_admin.PostProcessAdmin._copy_tree')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_copy_temp_dir(self, mock_logger, mock_copy, mock_remove, _):
"""
Test: Assert directory is copied correctly
When: Called with valid arguments
"""
result_dir = mkdtemp()
copy_dir = mkdtemp()
ppa = PostProcessAdmin(self.message, None)
ppa.instrument = 'POLARIS'
ppa.message.reduction_data = ['']
ppa.copy_temp_directory(result_dir, copy_dir)
mock_remove.assert_called_once_with(copy_dir)
mock_logger.assert_called_with("Moving %s to %s", result_dir, copy_dir)
mock_copy.assert_called_once_with(result_dir, copy_dir)
shutil.rmtree(result_dir)
shutil.rmtree(copy_dir)
@patch(DIR + '.post_process_admin.PostProcessAdmin._copy_tree')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_copy_temp_dir_with_excitation(self, _, mock_copy):
"""
Test: Excitation instrument temporary directories are handled correctly
When: When called for an excitation instrument
"""
result_dir = mkdtemp()
ppa = PostProcessAdmin(self.message, None)
ppa.instrument = 'WISH'
ppa.message.reduction_data = ['']
ppa.copy_temp_directory(result_dir, 'copy-dir')
mock_copy.assert_called_once_with(result_dir, 'copy-dir')
shutil.rmtree(result_dir)
@patch(DIR + '.post_process_admin.PostProcessAdmin._copy_tree')
@patch(DIR + '.post_process_admin.PostProcessAdmin.log_and_message')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_copy_temp_dir_with_error(self, _, mock_log_and_msg, mock_copy):
"""
Test: Errors are handled correctly
When: Runtime error raised
"""
# pylint:disable=unused-argument
def raise_runtime(arg1, arg2): # pragma : no cover
"""Raise Runtime Error"""
raise RuntimeError('test')
mock_copy.side_effect = raise_runtime
result_dir = mkdtemp()
ppa = PostProcessAdmin(self.message, None)
ppa.instrument = 'WISH'
ppa.message.reduction_data = ['']
ppa.copy_temp_directory(result_dir, 'copy-dir')
mock_log_and_msg.assert_called_once_with("Unable to copy to %s - %s" %
('copy-dir', 'test'))
shutil.rmtree(result_dir)
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.copy_temp_directory")
def test_additional_save_directories_check_string(self, mock_ctd):
"""
Test: Correctly copies temp directory
When: Called with valid path as string
"""
out_directories = "valid/path"
reduce_result_dir = self.temporary_directory + self.ceph_directory
ppa = PostProcessAdmin(self.message, None)
ppa.additional_save_directories_check(out_directories,
reduce_result_dir)
mock_ctd.assert_called_with(reduce_result_dir, out_directories)
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.copy_temp_directory")
def test_additional_save_directories_check_list(self, mock_ctd):
"""
Test: Correctly copies N temp directories
When: Called with valid list of paths
"""
# mock_ctd.return_value =
out_directories = ["valid/path/", "valid/path/"]
reduce_result_dir = self.temporary_directory + self.ceph_directory
ppa = PostProcessAdmin(self.message, None)
ppa.additional_save_directories_check(out_directories,
reduce_result_dir)
for path in out_directories:
mock_ctd.assert_called_with(reduce_result_dir, path)
self.assertEqual(mock_ctd.call_count, 2)
@patch(DIR + '.autoreduction_logging_setup.logger.info')
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.copy_temp_directory")
def test_additional_save_directories_check_invalid_list(
self, mock_ctd, mock_logger):
"""
Test: Logs invalid list input
When: List containing non strings is passed
"""
out_directories = ["valid/path/", 404, "valid/path/"]
reduce_result_dir = self.temporary_directory + self.ceph_directory
ppa = PostProcessAdmin(self.message, None)
ppa.additional_save_directories_check(out_directories,
reduce_result_dir)
mock_ctd.assert_called_with(reduce_result_dir, out_directories[0])
mock_ctd.assert_called_with(reduce_result_dir, out_directories[2])
self.assertEqual(mock_ctd.call_count, 2)
mock_logger.assert_called_once_with(
"Optional output directories of reduce.py must be "
f"strings: {out_directories[1]}")
@patch(DIR + '.autoreduction_logging_setup.logger.info')
@patch(f"{DIR}.post_process_admin.PostProcessAdmin.copy_temp_directory")
def test_additional_save_directories_check_invalid_argument(
self, mock_ctd, mock_logger):
"""
Test: Logs invalid argument
When: Called with invalid argument type
"""
out_directories = {404}
reduce_result_dir = self.temporary_directory + self.ceph_directory
ppa = PostProcessAdmin(self.message, None)
ppa.additional_save_directories_check(out_directories,
reduce_result_dir)
self.assertEqual(mock_ctd.call_count, 0)
mock_logger.assert_called_once_with(
"Optional output directories of reduce.py must "
f"be a string or list of stings: {out_directories}")
@patch('shutil.rmtree')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_delete_temp_dir_valid(self, mock_logger, mock_remove_dir):
"""
Test: Assert deletion of temporary directory
When: Called with valid arguments
"""
temp_dir = mkdtemp()
PostProcessAdmin.delete_temp_directory(temp_dir)
rm_args = {'ignore_errors': True}
mock_remove_dir.assert_called_once_with(temp_dir, **rm_args)
mock_logger.assert_called_once_with('Remove temp dir %s', temp_dir)
shutil.rmtree(temp_dir)
@patch('shutil.rmtree')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_delete_temp_dir_invalid(self, mock_logger, mock_remove_dir):
"""
Test: Assert the inability to delete a record
When: Runtime error raised
"""
def raise_runtime(): # pragma: no cover
"""Raise Runtime Error"""
raise RuntimeError('test')
mock_remove_dir.side_effect = raise_runtime
PostProcessAdmin.delete_temp_directory('not-a-file-path.test')
mock_logger.assert_has_calls([
call('Remove temp dir %s', 'not-a-file-path.test'),
call('Unable to remove temporary directory - %s',
'not-a-file-path.test')
])
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_empty_log_and_message(self, mock_logger):
"""
Test: Log and message are correctly cleared repopulated with method argument
When: Called and message.message = ''
"""
ppa = PostProcessAdmin(self.message, None)
ppa.message.message = ''
ppa.log_and_message('test')
self.assertEqual(ppa.message.message, 'test')
mock_logger.assert_called_with('test')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
def test_load_and_message_with_preexisting_message(self, mock_logger):
"""
Test: Assert existing message persists and new message logged.
When: called with new message
"""
ppa = PostProcessAdmin(self.message, None)
ppa.message.message = 'Old message'
ppa.log_and_message('New message')
self.assertEqual(ppa.message.message, 'Old message')
mock_logger.assert_called_with('New message')
def test_remove_with_wait_folder(self):
"""
Test: Directory removed
When: Called
"""
directory_to_remove = mkdtemp()
self.assertTrue(os.path.exists(directory_to_remove))
ppa = PostProcessAdmin(self.message, None)
ppa._remove_with_wait(True, directory_to_remove)
self.assertFalse(os.path.exists(directory_to_remove))
def test_remove_with_wait_file(self):
"""
Test: File removed
When: Called
"""
file_to_remove = NamedTemporaryFile(delete=False).name
self.assertTrue(os.path.exists(str(file_to_remove)))
ppa = PostProcessAdmin(self.message, None)
ppa._remove_with_wait(False, file_to_remove)
self.assertFalse(os.path.exists(file_to_remove))
def test_copy_tree_folder(self):
"""
Test: Expected directory structure found
When: Called for a given file
"""
directory_to_copy = mkdtemp(prefix='test-dir')
with open(os.path.join(directory_to_copy, 'test-file.txt'),
'w+') as test_file:
test_file.write('test content')
ppa = PostProcessAdmin(self.message, None)
ppa._copy_tree(directory_to_copy,
os.path.join(get_project_root(), 'test-dir'))
self.assertTrue(
os.path.exists(os.path.join(get_project_root(), 'test-dir')))
self.assertTrue(
os.path.isdir(os.path.join(get_project_root(), 'test-dir')))
self.assertTrue(
os.path.exists(
os.path.join(get_project_root(), 'test-dir', 'test-file.txt')))
self.assertTrue(
os.path.isfile(
os.path.join(get_project_root(), 'test-dir', 'test-file.txt')))
shutil.rmtree(os.path.join(get_project_root(), 'test-dir'))
def test_remove_directory(self):
"""
Test: Directory removed
When: Called
"""
directory_to_remove = mkdtemp()
self.assertTrue(os.path.exists(directory_to_remove))
ppa = PostProcessAdmin(self.message, None)
ppa._remove_directory(directory_to_remove)
self.assertFalse(os.path.exists(directory_to_remove))
@patch(DIR + '.post_process_admin_utilities.windows_to_linux_path',
return_value='path')
@patch(DIR + '.post_process_admin.PostProcessAdmin.reduce')
@patch('utils.clients.queue_client.QueueClient.connect')
@patch('utils.clients.queue_client.QueueClient.__init__',
return_value=None)
def test_main(self, mock_init, mock_connect, mock_reduce, _):
"""
Test: A QueueClient is initialised and connected and ppa.reduce is called
When: The main method is called
"""
sys.argv = ['', '/queue/ReductionPending', json.dumps(self.data)]
main()
mock_init.assert_called_once()
mock_connect.assert_called_once()
mock_reduce.assert_called_once()
# pylint: disable = too-many-arguments
@patch('model.message.message.Message.serialize', return_value='test')
@patch('sys.exit')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
@patch(DIR + '.post_process_admin.PostProcessAdmin.__init__',
return_value=None)
@patch('utils.clients.queue_client.QueueClient.send')
@patch('utils.clients.queue_client.QueueClient.connect')
@patch('utils.clients.queue_client.QueueClient.__init__',
return_value=None)
def test_main_inner_value_error(self, mock_client_init, mock_connect,
mock_send, mock_ppa_init, mock_logger,
mock_exit, _):
"""
Test: The correct message is sent from the exception handlers in main
When: A ValueError exception is raised from ppa.reduce
"""
def raise_value_error(arg1, _):
"""Raise Value Error"""
self.assertEqual(arg1, self.message)
raise ValueError('error-message')
mock_ppa_init.side_effect = raise_value_error
sys.argv = ['', '/queue/ReductionPending', json.dumps(self.data)]
main()
mock_connect.assert_called_once()
mock_client_init.assert_called_once()
mock_logger.assert_has_calls([call('Message data error: %s', 'test')])
mock_exit.assert_called_once()
self.message.message = 'error-message'
mock_send.assert_called_once_with(ACTIVEMQ_SETTINGS.reduction_error,
self.message)
# pylint: disable = too-many-arguments
@patch('sys.exit')
@patch(DIR + '.autoreduction_logging_setup.logger.info')
@patch(DIR + '.post_process_admin.PostProcessAdmin.__init__',
return_value=None)
@patch('utils.clients.queue_client.QueueClient.send')
@patch('utils.clients.queue_client.QueueClient.connect')
@patch('utils.clients.queue_client.QueueClient.__init__',
return_value=None)
def test_main_inner_exception(self, mock_client_init, mock_connect,
mock_send, mock_ppa_init, mock_logger,
mock_exit):
"""
Test: The correct message is sent from the exception handlers in main
When: A bare Exception is raised from ppa.reduce
"""
def raise_exception(arg1, _):
"""Raise Exception"""
self.assertEqual(arg1, self.message)
raise Exception('error-message')
mock_ppa_init.side_effect = raise_exception
sys.argv = ['', '/queue/ReductionPending', json.dumps(self.data)]
main()
mock_connect.assert_called_once()
mock_client_init.assert_called_once()
mock_logger.assert_has_calls(
[call('PostProcessAdmin error: %s', 'error-message')])
mock_exit.assert_called_once()
mock_send.assert_called_once_with(ACTIVEMQ_SETTINGS.reduction_error,
self.message)
@patch("os.access")
def test_new_reduction_data_path_no_overwrite_paths_exist(self, _):
"""
Test: A path is returned with a final directory one higher than the current highest
When: _new_reduction_data_path is called on an existing path with overwrite: None
"""
self.setup_test_dir_structure(self.test_paths)
mock_self = Mock()
mock_self.message = Message(overwrite=None)
expected = append_path(self.test_root, "3")
actual = PostProcessAdmin._new_reduction_data_path(
mock_self, self.test_root)
self.assertEqual(expected, actual)
@patch("os.access")
def test_new_reduction_data_path_overwrite_paths_exist(self, _):
"""
Test: The given path is returned with a 0 directory appended
When: _new_reduction_data_path is called on an existing path with overwrite: True
"""
self.setup_test_dir_structure(self.test_paths)
mock_self = Mock()
mock_self.message = Message(overwrite=True)
expected = append_path(self.test_root, "0")
actual = PostProcessAdmin._new_reduction_data_path(
mock_self, self.test_root)
self.assertEqual(expected, actual)
def test_new_reduction_data_only_root_path_exists(self):
"""
Test: The given path is returned with a 0 directory appended
When: _new_reduction_data_path is called on a path without version sub-directories
"""
self.setup_test_dir_structure([self.test_root])
mock_self = Mock()
mock_self.message = Message(overwrite=None)
expected = append_path(self.test_root, "0")
actual = PostProcessAdmin._new_reduction_data_path(
mock_self, self.test_root)
self.assertEqual(expected, actual)
@patch(DIR + '.post_process_admin.PostProcessAdmin.__init__',
return_value=None)
def test_validate_input_success(self, _):
"""
Test: The attribute value is returned
When: validate_input is called with an attribute which is not None
"""
mock_self = Mock()
mock_self.message = self.message
actual = PostProcessAdmin.validate_input(mock_self, 'facility')
self.assertEqual(actual, self.message.facility)
@patch(DIR + '.post_process_admin.PostProcessAdmin.__init__',
return_value=None)
def test_validate_input_failure(self, _):
"""
Test: A ValueError is raised
When: validate_input is called with an attribute who's value is None
"""
mock_self = Mock()
mock_self.message = self.message
mock_self.message.facility = None
with self.assertRaises(ValueError):
PostProcessAdmin.validate_input(mock_self, 'facility')
class TestReductionRunner(unittest.TestCase):
DIR = "queue_processors.queue_processor.reduction"
def setUp(self):
"""Setup values for Post-Process Admin"""
self.data = {
'data': '\\\\isis\\inst$\\data.nxs',
'facility': 'ISIS',
'instrument': 'GEM',
'rb_number': '1234',
'run_number': '4321',
'reduction_script':
'print(\'hello\')', # not actually used for the reduction
'reduction_arguments': 'None'
}
self.message = Message()
self.message.populate(self.data)
def test_init(self):
"""
Test: init parameters are as expected
When: called with expected arguments
"""
runner = ReductionRunner(self.message)
self.assertEqual(runner.message, self.message)
self.assertIsNotNone(runner.admin_log_stream)
self.assertEqual(runner.data_file, '/isis/data.nxs')
self.assertEqual(runner.facility, 'ISIS')
self.assertEqual(runner.instrument, 'GEM')
self.assertEqual(runner.proposal, '1234')
self.assertEqual(runner.run_number, '4321')
self.assertEqual(runner.reduction_arguments, 'None')
@patch(f'{DIR}.runner.ReductionRunner.validate_input',
side_effect=ValueError)
def test_init_validate_throws(self, _: Mock):
"""
Test: Failing to parse a parameter will raise a ValueError
When: called with a parameter that can't be validated
"""
with self.assertRaises(ValueError):
ReductionRunner(self.message)
@patch(f'{DIR}.runner.ReductionRunner.reduce')
def test_main(self, mock_reduce):
"""
Test: the reduction is run and on success finishes as expected
When: The main method is called
"""
with tempfile.NamedTemporaryFile() as tmp_file:
sys.argv = ['', json.dumps(self.data), tmp_file.name]
main()
out_data = json.loads(tmp_file.read())
mock_reduce.assert_called_once()
assert self.data["facility"] == out_data["facility"]
assert self.data["run_number"] == out_data["run_number"]
assert self.data["instrument"] == out_data["instrument"]
assert self.data["rb_number"] == out_data["rb_number"]
assert self.data["data"] == out_data["data"]
assert self.data["reduction_script"] == out_data["reduction_script"]
assert self.data["reduction_arguments"] == out_data[
"reduction_arguments"]
@patch(f'{DIR}.runner.ReductionRunner.reduce', side_effect=Exception)
def test_main_reduce_raises(self, mock_reduce):
"""
Test: the reduction is called but the reduce function raises an Exception
When: The main method is called
"""
with tempfile.NamedTemporaryFile() as tmp_file:
sys.argv = ['', json.dumps(self.data), tmp_file.name]
self.assertRaises(Exception, main)
mock_reduce.assert_called_once()
def test_main_bad_data_for_populate(self):
with tempfile.NamedTemporaryFile() as tmp_file:
sys.argv = ['', json.dumps({"apples": 13}), tmp_file.name]
self.assertRaises(ValueError, main)
@patch(f'{DIR}.runner.logger.info')
@patch(f'{DIR}.runner.ReductionRunner.__init__')
def test_main_inner_exception(self, mock_runner_init, mock_logger_info):
"""
Test: The correct message is sent from the exception handlers in main
When: A ValueError exception is raised from ppa.reduce
"""
expected_error_msg = 'error-message'
def raise_value_error(arg1):
"""Raise Value Error"""
self.assertEqual(arg1, self.message)
raise Exception(expected_error_msg)
mock_runner_init.side_effect = raise_value_error
with tempfile.NamedTemporaryFile() as tmp_file:
sys.argv = ['', json.dumps(self.data), tmp_file.name]
self.assertRaises(Exception, main)
self.message.message = expected_error_msg
mock_logger_info.assert_has_calls([
call('Message data error: %s',
self.message.serialize(limit_reduction_script=True))
])
@patch(f'{DIR}.runner.ReductionRunner.__init__', return_value=None)
def test_validate_input_success(self, _):
"""
Test: The attribute value is returned
When: validate_input is called with an attribute which is not None
"""
mock_self = Mock()
mock_self.message = self.message
actual = ReductionRunner.validate_input(mock_self, 'facility')
self.assertEqual(actual, self.message.facility)
@patch(f'{DIR}.runner.ReductionRunner.__init__', return_value=None)
def test_validate_input_failure(self, _):
"""
Test: A ValueError is raised
When: validate_input is called with an attribute who's value is None
"""
mock_self = Mock()
mock_self.message = self.message
mock_self.message.facility = None
with self.assertRaises(ValueError):
ReductionRunner.validate_input(mock_self, 'facility')
@patch(f'{DIR}.runner.logger.info')
@patch(f'{DIR}.runner.ReductionRunner._get_mantid_version',
return_value="5.1.0")
def test_reduce_bad_datafile(self, _get_mantid_version: Mock,
mock_logger_info: Mock):
self.message.description = "testdescription"
runner = ReductionRunner(self.message)
runner.reduce()
mock_logger_info.assert_called_once()
assert mock_logger_info.call_args[0][1] == "testdescription"
_get_mantid_version.assert_called_once()
assert runner.message.message == 'REDUCTION Error: Problem reading datafile: /isis/data.nxs'
@patch(f'{DIR}.runner.ReductionRunner._get_mantid_version',
return_value="5.1.0")
@patch(f'{DIR}.runner.reduce')
def test_reduce_throws_reductionscripterror(self, reduce: Mock,
_get_mantid_version: Mock):
reduce.side_effect = ReductionScriptError
with tempfile.NamedTemporaryFile() as tmpfile:
self.message.data = tmpfile.name
runner = ReductionRunner(self.message)
runner.reduce()
reduce.assert_called_once()
_get_mantid_version.assert_called_once()
assert str(reduce.call_args[0][2].path) == tmpfile.name
assert runner.message.reduction_data is None
assert runner.message.software == "5.1.0"
assert "REDUCTION Error: Error encountered when running the reduction script" in runner.message.message
@patch(f'{DIR}.runner.ReductionRunner._get_mantid_version',
return_value="5.1.0")
@patch(f'{DIR}.runner.reduce')
def test_reduce_throws_any_exception(self, reduce: Mock,
_get_mantid_version: Mock):
reduce.side_effect = Exception
with tempfile.NamedTemporaryFile() as tmpfile:
self.message.data = tmpfile.name
runner = ReductionRunner(self.message)
runner.reduce()
reduce.assert_called_once()
_get_mantid_version.assert_called_once()
assert str(reduce.call_args[0][2].path) == tmpfile.name
assert runner.message.reduction_data is None
assert runner.message.software == "5.1.0"
assert "REDUCTION Error:" in runner.message.message
@patch(f'{DIR}.runner.ReductionRunner._get_mantid_version',
return_value="5.1.0")
@patch(f'{DIR}.runner.reduce')
def test_reduce_ok(self, reduce: Mock, _get_mantid_version: Mock):
with tempfile.NamedTemporaryFile() as tmpfile:
self.message.data = tmpfile.name
runner = ReductionRunner(self.message)
runner.reduce()
reduce.assert_called_once()
_get_mantid_version.assert_called_once()
assert str(reduce.call_args[0][2].path) == tmpfile.name
assert runner.message.reduction_data is not None
assert runner.message.reduction_log is not None
assert runner.message.message is None
assert runner.message.software == "5.1.0"
@patch(f'{DIR}.runner.logger')
def test_get_mantid_version(self, logger: Mock):
assert ReductionRunner._get_mantid_version() is None
assert logger.error.call_count == 2
class TestHandleMessage(TestCase):
"""
Directly tests the message handling classes
"""
def setUp(self):
self.mocked_client = mock.Mock(spec=QueueListener)
self.msg = Message()
self.msg.populate({
"run_number": 7654321,
"rb_number": 1234567,
"run_version": 0,
"reduction_data": "/path/1",
"started_by": -1,
"data": "/path",
"description": "This is a fake description",
"instrument": "ARMI" # Autoreduction Mock Instrument
})
with patch("logging.getLogger") as patched_logger:
self.handler = HandleMessage(self.mocked_client)
self.mocked_logger = patched_logger.return_value
db_handle = model.database.access.start_database()
self.data_model = db_handle.data_model
self.variable_model = db_handle.variable_model
self.experiment, _ = self.data_model.Experiment.objects.get_or_create(
reference_number=1231231)
self.instrument, _ = self.data_model.Instrument.objects.get_or_create(
name="ARMI")
status = STATUS.get_queued()
fake_script_text = "scripttext"
self.reduction_run = create_reduction_run_record(
self.experiment, self.instrument, FakeMessage(), 0,
fake_script_text, status)
self.reduction_run.save()
def tearDown(self) -> None:
self.experiment.delete()
self.instrument.delete()
self.reduction_run.delete()
@parameterized.expand([
["reduction_error", STATUS.get_error()],
["reduction_skipped", STATUS.get_skipped()],
])
def test_reduction_with_message(self, function_to_call, expected_status):
"""
Tests a reduction error where the message contains an error message
"""
self.msg.message = "I am a message"
getattr(self.handler, function_to_call)(self.reduction_run, self.msg)
assert self.reduction_run.status == expected_status
assert self.reduction_run.message == "I am a message"
assert self.reduction_run.run_name == "This is a fake description"
self.mocked_logger.info.assert_called_once()
assert self.mocked_logger.info.call_args[0][1] == self.msg.run_number
@parameterized.expand([
["reduction_error", STATUS.get_error()],
["reduction_skipped", STATUS.get_skipped()],
])
def test_reduction_without_message(self, function_to_call,
expected_status):
"""
Tests a reduction error where the message does not contain an error message
"""
getattr(self.handler, function_to_call)(self.reduction_run, self.msg)
assert self.reduction_run.status == expected_status
self.mocked_logger.info.assert_called_once()
assert self.mocked_logger.info.call_args[0][1] == self.msg.run_number
def test_reduction_started(self):
"Tests starting a reduction"
assert self.reduction_run.started is None
assert self.reduction_run.finished is None
self.handler.reduction_started(self.reduction_run, self.msg)
self.mocked_logger.info.assert_called_once()
assert self.reduction_run.started is not None
assert self.reduction_run.finished is None
assert self.reduction_run.status == STATUS.get_processing()
self.mocked_logger.info.assert_called_once()
def test_reduction_complete(self):
"Tests completing a reduction"
self.msg.reduction_data = None
assert self.reduction_run.finished is None
self.handler.reduction_complete(self.reduction_run, self.msg)
self.mocked_logger.info.assert_called_once()
assert self.reduction_run.finished is not None
assert self.reduction_run.status == STATUS.get_completed()
self.mocked_logger.info.assert_called_once()
assert self.reduction_run.reduction_location.count() == 0
def test_reduction_complete_with_reduction_data(self):
"Tests completing a reduction that has an output location at reduction_data"
assert self.reduction_run.finished is None
self.handler.reduction_complete(self.reduction_run, self.msg)
self.mocked_logger.info.assert_called_once()
assert self.reduction_run.finished is not None
assert self.reduction_run.status == STATUS.get_completed()
self.mocked_logger.info.assert_called_once()
assert self.reduction_run.reduction_location.first(
).file_path == "/path/1"
@patch(
"queue_processors.queue_processor.handle_message.ReductionProcessManager"
)
def test_do_reduction_success(self, rpm):
"Tests do_reduction success path"
rpm.return_value.run = self.do_post_started_assertions
self.handler.do_reduction(self.reduction_run, self.msg)
assert self.reduction_run.status == STATUS.get_completed()
assert self.reduction_run.started is not None
assert self.reduction_run.finished is not None
assert self.reduction_run.reduction_location.first(
).file_path == "/path/1"
def do_post_started_assertions(self, expected_info_calls=1):
"Helper to capture common assertions between tests"
assert self.reduction_run.status == STATUS.get_processing()
assert self.reduction_run.started is not None
assert self.reduction_run.finished is None
assert self.mocked_logger.info.call_count == expected_info_calls
# reset for follow logger calls
self.mocked_logger.info.reset_mock()
return self.msg
# a bit of a nasty patch, but everything underneath should be unit tested separately
@patch(
"queue_processors.queue_processor.handle_message.ReductionProcessManager"
)
def test_do_reduction_fail(self, rpm):
"Tests do_reduction failure path"
self.msg.message = "Something failed"
rpm.return_value.run = self.do_post_started_assertions
self.handler.do_reduction(self.reduction_run, self.msg)
assert self.reduction_run.status == STATUS.get_error()
assert self.reduction_run.started is not None
assert self.reduction_run.finished is not None
assert self.reduction_run.message == "Something failed"
def test_activate_db_inst(self):
"""
Tests whether the function enables the instrument
"""
self.instrument.is_active = False
self.instrument.save()
self.handler.activate_db_inst(self.instrument)
assert self.instrument.is_active
def test_find_reason_to_skip_run_empty_script(self):
"""
Test find_reason_to_skip_run correctly captures validation failing on the message
"""
self.reduction_run.script = ""
assert "Script text for current instrument is empty" in self.handler.find_reason_to_skip_run(
self.reduction_run, self.msg, self.instrument)
def test_find_reason_to_skip_run_message_validation_fails(self):
"""
Test find_reason_to_skip_run correctly captures validation failing on the message
"""
self.msg.rb_number = 123 # invalid RB number, should be 7 digits
assert "Validation error" in self.handler.find_reason_to_skip_run(
self.reduction_run, self.msg, self.instrument)
def test_find_reason_to_skip_run_instrument_paused(self):
"""
Test find_reason_to_skip_run correctly captures that the instrument is paused
"""
self.instrument.is_paused = True
assert "is paused" in self.handler.find_reason_to_skip_run(
self.reduction_run, self.msg, self.instrument)
def test_find_reason_to_skip_run_doesnt_skip_when_all_is_ok(self):
"""
Test find_reason_to_skip_run returns None when all the validation passes
"""
assert self.handler.find_reason_to_skip_run(
self.reduction_run, self.msg, self.instrument) is None
@patch(
"queue_processors.queue_processor.handle_message.ReductionProcessManager"
)
def test_send_message_onwards_ok(self, rpm):
"""
Test that a run where all is OK is reduced
"""
self.instrument.is_active = False
rpm.return_value.run = partial(self.do_post_started_assertions, 2)
self.handler.send_message_onwards(self.reduction_run, self.msg,
self.instrument)
assert self.reduction_run.status == STATUS.get_completed()
assert self.instrument.is_active
@patch(
"queue_processors.queue_processor.handle_message.ReductionProcessManager"
)
def test_send_message_onwards_skip_run(self, rpm):
"""
Test that a run that fails validation is skipped
"""
self.msg.rb_number = 123
self.handler.send_message_onwards(self.reduction_run, self.msg,
self.instrument)
rpm.return_value.run.assert_not_called()
assert self.reduction_run.status == STATUS.get_skipped()
assert "Validation error" in self.reduction_run.message
@patch("queue_processors.queue_processor.handle_message.ReductionScript")
def test_create_run_records_multiple_versions(self,
reduction_script: Mock):
"Test creating multiple version of the same run"
self.instrument.is_active = False
self.msg.description = "Testing multiple versions"
reduction_script.return_value.text.return_value = "print(123)"
self.msg.run_number = random.randint(1000000, 10000000)
db_objects_to_delete = []
for i in range(5):
reduction_run, message, instrument = self.handler.create_run_records(
self.msg)
db_objects_to_delete.append(reduction_run)
assert reduction_run.run_number == self.msg.run_number
assert reduction_run.experiment.reference_number == self.msg.rb_number
assert reduction_run.run_version == i
assert reduction_run.run_name == "Testing multiple versions"
assert message.run_version == i
assert instrument == self.instrument
assert instrument.name == self.msg.instrument
assert reduction_run.script == "print(123)"
assert reduction_run.data_location.first(
).file_path == message.data
assert reduction_run.status == STATUS.get_queued()
for obj in db_objects_to_delete:
obj.delete()
def test_create_run_variables_no_variables_creates_nothing(self):
"Test running a reduction run with an empty reduce_vars.py"
expected_args = {'standard_vars': {}, 'advanced_vars': {}}
self.handler.instrument_variable.create_run_variables = mock.Mock(
return_value=[])
message = self.handler.create_run_variables(self.reduction_run,
self.msg, self.instrument)
self.handler.instrument_variable.create_run_variables.assert_called_once_with(
self.reduction_run, {})
assert self.mocked_logger.info.call_count == 2
self.mocked_logger.warning.assert_called_once()
assert message.reduction_arguments == expected_args
@patch(
'queue_processors.queue_processor.reduction.service.ReductionScript.load',
return_value=FakeModule())
def test_create_run_variables(self, import_module: Mock):
"Test the creation of RunVariables for the ReductionRun"
expected_args = {
'standard_vars': FakeModule().standard_vars,
'advanced_vars': FakeModule().advanced_vars
}
message = self.handler.create_run_variables(self.reduction_run,
self.msg, self.instrument)
assert self.mocked_logger.info.call_count == 2
assert message.reduction_arguments == expected_args
import_module.assert_called_once()
def test_data_ready_other_exception_raised_ends_processing(self):
"Test an exception being raised inside data_ready handler"
self.handler.create_run_records = Mock(side_effect=RuntimeError)
with self.assertRaises(RuntimeError):
self.handler.data_ready(self.msg)
self.mocked_logger.info.assert_called_once()
self.mocked_logger.error.assert_called_once()
def test_data_ready_variable_integrity_error_marks_reduction_error(self):
"Test that an integrity error inside data_ready marks the reduction as errored"
self.handler.create_run_records = Mock(
return_value=(self.reduction_run, self.msg, self.instrument))
self.handler.create_run_variables = Mock(side_effect=IntegrityError)
with self.assertRaises(IntegrityError):
self.handler.data_ready(self.msg)
assert self.mocked_logger.info.call_count == 2
self.mocked_logger.error.assert_called_once()
assert self.reduction_run.status == STATUS.get_error()
assert "Encountered error in transaction to save RunVariables" in self.reduction_run.message
def test_data_ready_no_reduce_vars(self):
"Test data_ready when the reduce_vars script does not exist and throws a FileNotFoundError"
self.handler.create_run_records = Mock(
return_value=(self.reduction_run, self.msg, self.instrument))
with self.assertRaises(FileNotFoundError):
self.handler.data_ready(self.msg)
assert self.mocked_logger.info.call_count == 3
self.mocked_logger.error.assert_called_once()
assert self.reduction_run.status == STATUS.get_error()
assert "Encountered error in transaction to save RunVariables" in self.reduction_run.message
@patch(
'queue_processors.queue_processor.reduction.service.ReductionScript.load',
return_value=FakeModule())
@patch(
"queue_processors.queue_processor.handle_message.ReductionProcessManager"
)
def test_data_ready_sends_onwards_completed(self, rpm, load: Mock):
"Test data_ready success path sends the message onwards for reduction"
rpm.return_value.run = partial(self.do_post_started_assertions, 5)
self.handler.create_run_records = Mock(
return_value=(self.reduction_run, self.msg, self.instrument))
self.handler.data_ready(self.msg)
assert self.mocked_logger.info.call_count == 1
assert self.reduction_run.finished is not None
assert self.reduction_run.status == STATUS.get_completed()
load.assert_called_once()
@patch(
'queue_processors.queue_processor.reduction.service.ReductionScript.load',
return_value=FakeModule())
@patch(
"queue_processors.queue_processor.handle_message.ReductionProcessManager"
)
def test_data_ready_sends_onwards_error(self, rpm, load: Mock):
"Test data_ready error path sends the message onwards to be marked as errored"
self.msg.message = "I am error"
rpm.return_value.run = partial(self.do_post_started_assertions, 5)
self.handler.create_run_records = Mock(
return_value=(self.reduction_run, self.msg, self.instrument))
self.handler.data_ready(self.msg)
assert self.mocked_logger.info.call_count == 1
assert self.reduction_run.finished is not None
assert self.reduction_run.status == STATUS.get_error()
assert self.reduction_run.message == "I am error"
load.assert_called_once()
