def __init__(self, *args, **kwargs):
super(Quote, self).__init__(*args, **kwargs)
if "process" not in self:
raise TypeError("Field 'Quote.process' is required")
if not isinstance(self.get("process"), str):
raise ValueError("Field 'Quote.process' must be a string.")
if "user" not in self:
raise TypeError("Field 'Quote.user' is required")
if not isinstance(self.get("user"), str):
raise ValueError("Field 'Quote.user' must be a string.")
if "price" not in self:
raise TypeError("Field 'Quote.price' is required")
if not isinstance(self.get("price"), float):
raise ValueError("Field 'Quote.price' must be a float number.")
if "currency" not in self:
raise TypeError("Field 'Quote.currency' is required")
if not isinstance(self.get("currency"), str) or len(self.get("currency")) != 3:
raise ValueError("Field 'Quote.currency' must be an ISO-4217 currency string code.")
if "created" not in self:
self["created"] = now()
try:
self["created"] = dt_parse(str(self.get("created"))).isoformat()
except ValueError:
raise ValueError("Field 'Quote.created' must be an ISO-8601 datetime string.")
if "expire" not in self:
self["expire"] = now() + timedelta(days=1)
try:
self["expire"] = dt_parse(str(self.get("expire"))).isoformat()
except ValueError:
raise ValueError("Field 'Quote.expire' must be an ISO-8601 datetime string.")
if "id" not in self:
self["id"] = str(uuid.uuid4())
def __init__(self, *args, **kwargs):
super(Bill, self).__init__(*args, **kwargs)
if "quote" not in self:
raise TypeError("Field 'Bill.quote' is required")
if not isinstance(self.get("quote"), str):
raise ValueError("Field 'Bill.quote' must be a string.")
if "job" not in self:
raise TypeError("Field 'Bill.job' is required")
if not isinstance(self.get("job"), str):
raise ValueError("Field 'Bill.job' must be a string.")
if "user" not in self:
raise TypeError("Field 'Bill.user' is required")
if not isinstance(self.get("user"), str):
raise ValueError("Field 'Bill.user' must be a string.")
if "price" not in self:
raise TypeError("Field 'Bill.price' is required")
if not isinstance(self.get("price"), float):
raise ValueError("Field 'Bill.price' must be a float number.")
if "currency" not in self:
raise TypeError("Field 'Bill.currency' is required")
if not isinstance(self.get("currency"), str) or len(self.get("currency")) != 3:
raise ValueError("Field 'Bill.currency' must be an ISO-4217 currency string code.")
if "created" not in self:
self["created"] = now()
try:
self["created"] = dt_parse(str(self.get("created"))).isoformat()
except ValueError:
raise ValueError("Field 'Bill.created' must be an ISO-8601 datetime string.")
if "id" not in self:
self["id"] = str(uuid.uuid4())
def setUp(self):
# reset in case it was modified during another test
self.__class__.log_full_trace = True
self.log("{}Start of '{}': {}\n{}"
.format(self.logger_separator_tests, self.current_test_name(), now(), self.logger_separator_tests))
# cleanup old processes as required
headers, cookies = self.user_headers_cookies(self.WEAVER_TEST_ADMIN_CREDENTIALS, force_magpie=True)
self.clear_test_processes(headers, cookies)
def setUpClass(cls):
# disable SSL warnings from logs
try:
import urllib3 # noqa
urllib3.disable_warnings(urllib3.exceptions.InsecureRequestWarning)
except ImportError:
pass
# logging parameter overrides
cls.logger_level = os.getenv("WEAVER_TEST_LOGGER_LEVEL", cls.logger_level)
cls.logger_enabled = asbool(os.getenv("WEAVER_TEST_LOGGER_ENABLED", cls.logger_enabled))
cls.logger_result_dir = os.getenv("WEAVER_TEST_LOGGER_RESULT_DIR", os.path.join(WEAVER_ROOT_DIR))
cls.logger_json_indent = os.getenv("WEAVER_TEST_LOGGER_JSON_INDENT", cls.logger_json_indent)
cls.logger_field_indent = os.getenv("WEAVER_TEST_LOGGER_FIELD_INDENT", cls.logger_field_indent)
cls.logger_separator_calls = os.getenv("WEAVER_TEST_LOGGER_SEPARATOR_CALLS", cls.logger_separator_calls)
cls.logger_separator_steps = os.getenv("WEAVER_TEST_LOGGER_SEPARATOR_STEPS", cls.logger_separator_steps)
cls.logger_separator_tests = os.getenv("WEAVER_TEST_LOGGER_SEPARATOR_TESTS", cls.logger_separator_tests)
cls.logger_separator_cases = os.getenv("WEAVER_TEST_LOGGER_SEPARATOR_CASES", cls.logger_separator_cases)
cls.setup_logger()
cls.log("{}Start of '{}': {}\n{}"
.format(cls.logger_separator_cases, cls.current_case_name(), now(), cls.logger_separator_cases))
# test execution configs
cls.WEAVER_TEST_REQUEST_TIMEOUT = int(os.getenv("WEAVER_TEST_REQUEST_TIMEOUT", 10))
cls.WEAVER_TEST_JOB_ACCEPTED_MAX_TIMEOUT = int(os.getenv("WEAVER_TEST_JOB_ACCEPTED_MAX_TIMEOUT", 30))
cls.WEAVER_TEST_JOB_RUNNING_MAX_TIMEOUT = int(os.getenv("WEAVER_TEST_JOB_RUNNING_MAX_TIMEOUT", 6000))
cls.WEAVER_TEST_JOB_GET_STATUS_INTERVAL = int(os.getenv("WEAVER_TEST_JOB_GET_STATUS_INTERVAL", 5))
# security configs if enabled
cls.WEAVER_TEST_PROTECTED_ENABLED = asbool(os.getenv("WEAVER_TEST_PROTECTED_ENABLED", False))
cls.WEAVER_TEST_WSO2_CLIENT_HOSTNAME = os.getenv("WEAVER_TEST_WSO2_CLIENT_HOSTNAME", "")
cls.WEAVER_TEST_WSO2_CLIENT_ID = os.getenv("WEAVER_TEST_WSO2_CLIENT_ID", "")
cls.WEAVER_TEST_WSO2_CLIENT_SECRET = os.getenv("WEAVER_TEST_WSO2_CLIENT_SECRET", "")
cls.WEAVER_TEST_WSO2_URL = os.getenv("WEAVER_TEST_WSO2_URL", "")
cls.WEAVER_TEST_MAGPIE_URL = os.getenv("WEAVER_TEST_MAGPIE_URL", "")
cls.WEAVER_TEST_ADMIN_CREDENTIALS = {"username": get_setting("ADMIN_USERNAME", cls.app),
"password": get_setting("ADMIN_PASSWORD", cls.app)}
cls.WEAVER_TEST_ALICE_CREDENTIALS = {"username": get_setting("ALICE_USERNAME", cls.app),
"password": get_setting("ALICE_PASSWORD", cls.app)}
cls.WEAVER_TEST_BOB_CREDENTIALS = {"username": get_setting("BOD_USERNAME", cls.app),
"password": get_setting("BOB_PASSWORD", cls.app)}
# server settings
cls.WEAVER_TEST_SERVER_HOSTNAME = os.getenv("WEAVER_TEST_SERVER_HOSTNAME")
cls.WEAVER_TEST_SERVER_BASE_PATH = os.getenv("WEAVER_TEST_SERVER_BASE_PATH", "/weaver")
cls.WEAVER_TEST_SERVER_API_PATH = os.getenv("WEAVER_TEST_SERVER_API_PATH", "/")
cls.WEAVER_TEST_CONFIG_INI_PATH = os.getenv("WEAVER_TEST_CONFIG_INI_PATH") # none uses default path
cls.app = WebTestApp(cls.WEAVER_TEST_SERVER_HOSTNAME)
cls.WEAVER_URL = get_weaver_url(cls.settings())
cls.WEAVER_RESTAPI_URL = get_wps_restapi_base_url(cls.settings())
# validation
cls.validate_test_server()
cls.setup_test_processes()
def save_job(self,
task_id, # type: str
process, # type: str
service=None, # type: Optional[str]
inputs=None, # type: Optional[List[Any]]
is_workflow=False, # type: bool
is_local=False, # type: bool
user_id=None, # type: Optional[int]
execute_async=True, # type: bool
custom_tags=None, # type: Optional[List[str]]
access=None, # type: Optional[str]
notification_email=None, # type: Optional[str]
accept_language=None, # type: Optional[str]
): # type: (...) -> Job
"""
Stores a job in mongodb.
"""
try:
tags = ["dev"]
tags.extend(list(filter(lambda t: bool(t), custom_tags or []))) # remove empty tags
if is_workflow:
tags.append(PROCESS_WORKFLOW)
else:
tags.append(PROCESS_APPLICATION)
if execute_async:
tags.append(EXECUTE_MODE_ASYNC)
else:
tags.append(EXECUTE_MODE_SYNC)
if not access:
access = VISIBILITY_PRIVATE
new_job = Job({
"task_id": task_id,
"user_id": user_id,
"service": service, # provider identifier (WPS service)
"process": process, # process identifier (WPS request)
"inputs": inputs,
"status": map_status(STATUS_ACCEPTED),
"execute_async": execute_async,
"is_workflow": is_workflow,
"is_local": is_local,
"created": now(),
"tags": list(set(tags)), # remove duplicates
"access": access,
"notification_email": notification_email,
"accept_language": accept_language,
})
self.collection.insert_one(new_job.params())
job = self.fetch_by_id(job_id=new_job.id)
except Exception as ex:
raise JobRegistrationError("Error occurred during job registration: [{}]".format(repr(ex)))
if job is None:
raise JobRegistrationError("Failed to retrieve registered job.")
return job
def save_log(self,
errors=None, # type: Optional[Union[str, List[WPSException]]]
logger=None, # type: Optional[Logger]
message=None, # type: Optional[str]
level=INFO, # type: int
): # type: (...) -> None
"""
Logs the specified error and/or message, and adds the log entry to the complete job log.
For each new log entry, additional :class:`Job` properties are added according to :meth:`Job._get_log_msg`
and the format defined by :func:`get_job_log_msg`.
:param errors:
An error message or a list of WPS exceptions from which to log and save generated message stack.
:param logger:
An additional :class:`Logger` for which to propagate logged messages on top saving them to the job.
:param message:
Explicit string to be logged, otherwise use the current :py:attr:`Job.status_message` is used.
:param level:
Logging level to apply to the logged ``message``. This parameter is ignored if ``errors`` are logged.
.. note::
The job object is updated with the log but still requires to be pushed to database to actually persist it.
"""
if isinstance(errors, str):
log_msg = [(ERROR, self._get_log_msg(message))]
self.exceptions.append(errors)
elif isinstance(errors, list):
log_msg = [(ERROR, self._get_log_msg("{0.text} - code={0.code} - locator={0.locator}".format(error)))
for error in errors]
self.exceptions.extend([{
"Code": error.code,
"Locator": error.locator,
"Text": error.text
} for error in errors])
else:
log_msg = [(level, self._get_log_msg(message))]
for lvl, msg in log_msg:
fmt_msg = get_log_fmt() % dict(asctime=now().strftime(get_log_date_fmt()),
levelname=getLevelName(lvl),
name=fully_qualified_name(self),
message=msg)
if len(self.logs) == 0 or self.logs[-1] != fmt_msg:
self.logs.append(fmt_msg)
if logger:
logger.log(lvl, msg)
def update_job(self, job):
# type: (Job) -> Job
"""
Updates a job parameters in `MongoDB` storage.
:param job: instance of ``weaver.datatype.Job``.
"""
try:
job.updated = now()
result = self.collection.update_one({"id": job.id},
{"$set": job.params()})
if result.acknowledged and result.matched_count == 1:
return self.fetch_by_id(job.id)
except Exception as ex:
raise JobUpdateError(
"Error occurred during job update: [{}]".format(repr(ex)))
raise JobUpdateError("Failed to update specified job: '{}'".format(
str(job)))
def duration(self):
# type: () -> timedelta
final_time = self.finished or now()
return localize_datetime(final_time) - localize_datetime(self.created)
def mark_finished(self):
# type: () -> None
self["finished"] = now()
def created(self):
# type: () -> datetime
created = self.get("created", None)
if not created:
self["created"] = now()
return localize_datetime(self.get("created"))
def execute(self, runtime, env, runtime_context): # noqa: E811
# type: (List[Text], MutableMapping[Text, Text], RuntimeContext) -> None
self.results = self.wps_process.execute(self.builder.job, self.outdir,
self.expected_outputs)
if self.joborder and runtime_context.research_obj:
job_order = self.joborder
assert runtime_context.prov_obj
assert runtime_context.process_run_id
runtime_context.prov_obj.used_artefacts(
job_order, runtime_context.process_run_id, str(self.name))
outputs = {} # type: Dict[Text, Text]
try:
rcode = 0
if self.successCodes:
process_status = "success"
elif self.temporaryFailCodes:
process_status = "temporaryFail"
elif self.permanentFailCodes:
process_status = "permanentFail"
elif rcode == 0:
process_status = "success"
else:
process_status = "permanentFail"
if self.generatefiles["listing"]:
assert self.generatemapper is not None
relink_initialworkdir(self.generatemapper,
self.outdir,
self.builder.outdir,
inplace_update=self.inplace_update)
outputs = self.collect_outputs(self.outdir)
outputs = bytes2str_in_dicts(outputs) # type: ignore
except OSError as exc:
if exc.errno == 2:
if runtime:
LOGGER.exception(u"'%s' not found", runtime[0])
else:
LOGGER.exception(u"'%s' not found", self.command_line[0])
else:
LOGGER.exception("Exception while running job")
process_status = "permanentFail"
except WorkflowException as err:
LOGGER.exception(u"[job %s] Job error:\n%s", self.name, err)
process_status = "permanentFail"
except Exception: # noqa: W0703 # nosec: B110
LOGGER.exception("Exception while running job")
process_status = "permanentFail"
if runtime_context.research_obj and self.prov_obj and \
runtime_context.process_run_id:
# creating entities for the outputs produced by each step (in the provenance document)
self.prov_obj.generate_output_prov(outputs,
runtime_context.process_run_id,
str(self.name))
self.prov_obj.document.wasEndedBy(runtime_context.process_run_id,
None,
self.prov_obj.workflow_run_uri,
now())
if process_status != "success":
LOGGER.warning(u"[job %s] completed %s", self.name, process_status)
else:
LOGGER.info(u"[job %s] completed %s", self.name, process_status)
if LOGGER.isEnabledFor(logging.DEBUG):
LOGGER.debug(u"[job %s] %s", self.name,
json.dumps(outputs, indent=4))
if self.generatemapper and runtime_context.secret_store:
# Delete any runtime-generated files containing secrets.
for _, path_item in self.generatemapper.items():
if path_item.type == "CreateFile":
if runtime_context.secret_store.has_secret(
path_item.resolved):
host_outdir = self.outdir
container_outdir = self.builder.outdir
host_outdir_tgt = path_item.target
if path_item.target.startswith(container_outdir + "/"):
host_outdir_tgt = os.path.join(
host_outdir,
path_item.target[len(container_outdir) + 1:])
os.remove(host_outdir_tgt)
if runtime_context.workflow_eval_lock is None:
raise WorkflowException(
"runtime_context.workflow_eval_lock must not be None")
with runtime_context.workflow_eval_lock:
self.output_callback(outputs, process_status)
if self.stagedir and os.path.exists(self.stagedir):
LOGGER.debug(u"[job %s] Removing input staging directory %s",
self.name, self.stagedir)
shutil.rmtree(self.stagedir, True)
if runtime_context.rm_tmpdir:
LOGGER.debug(u"[job %s] Removing temporary directory %s",
self.name, self.tmpdir)
shutil.rmtree(self.tmpdir, True)
def execute_process(task, job_id, wps_url, headers=None):
# type: (Task, UUID, str, Optional[HeadersType]) -> StatusType
"""
Celery task that executes the WPS process job monitoring as status updates (local and remote).
"""
from weaver.wps.service import get_pywps_service
LOGGER.debug("Job execute process called.")
task_process = get_celery_process()
rss_start = task_process.memory_info().rss
registry = get_registry(
None) # local thread, whether locally or dispatched celery
settings = get_settings(registry)
db = get_db(
registry, reset_connection=True
) # reset the connection because we are in a forked celery process
store = db.get_store(StoreJobs)
job = store.fetch_by_id(job_id)
job.started = now()
job.status = Status.STARTED # will be mapped to 'RUNNING'
job.status_message = f"Job {Status.STARTED}." # will preserve detail of STARTED vs RUNNING
job.save_log(message=job.status_message)
task_logger = get_task_logger(__name__)
job.save_log(logger=task_logger, message="Job task setup initiated.")
load_pywps_config(settings)
job.progress = JobProgress.SETUP
job.task_id = task.request.id
job.save_log(logger=task_logger, message="Job task setup completed.")
job = store.update_job(job)
# Flag to keep track if job is running in background (remote-WPS, CWL app, etc.).
# If terminate signal is sent to worker task via API dismiss request while still running in background,
# the raised exception within the task will switch the job to Status.FAILED, but this will not raise an
# exception here. Since the task execution 'succeeds' without raising, it skips directly to the last 'finally'.
# Patch it back to Status.DISMISSED in this case.
task_terminated = True
try:
job.progress = JobProgress.DESCRIBE
job.save_log(logger=task_logger,
message=f"Employed WPS URL: [{wps_url!s}]",
level=logging.DEBUG)
job.save_log(
logger=task_logger,
message=f"Execute WPS request for process [{job.process!s}]")
wps_process = fetch_wps_process(job, wps_url, headers, settings)
# prepare inputs
job.progress = JobProgress.GET_INPUTS
job.save_log(logger=task_logger,
message="Fetching job input definitions.")
wps_inputs = parse_wps_inputs(wps_process, job)
# prepare outputs
job.progress = JobProgress.GET_OUTPUTS
job.save_log(logger=task_logger,
message="Fetching job output definitions.")
wps_outputs = [(o.identifier, o.dataType == WPS_COMPLEX_DATA)
for o in wps_process.processOutputs]
# if process refers to a remote WPS provider, pass it down to avoid unnecessary re-fetch request
if job.is_local:
process = None # already got all the information needed pre-loaded in PyWPS service
else:
service = Service(name=job.service, url=wps_url)
process = Process.from_ows(wps_process, service, settings)
job.progress = JobProgress.EXECUTE_REQUEST
job.save_log(logger=task_logger,
message="Starting job process execution.")
job.save_log(
logger=task_logger,
message=
"Following updates could take a while until the Application Package answers..."
)
wps_worker = get_pywps_service(environ=settings, is_worker=True)
execution = wps_worker.execute_job(job,
wps_inputs=wps_inputs,
wps_outputs=wps_outputs,
remote_process=process,
headers=headers)
if not execution.process and execution.errors:
raise execution.errors[0]
# adjust status location
wps_status_path = get_wps_local_status_location(
execution.statusLocation, settings)
job.progress = JobProgress.EXECUTE_STATUS_LOCATION
LOGGER.debug("WPS status location that will be queried: [%s]",
wps_status_path)
if not wps_status_path.startswith("http") and not os.path.isfile(
wps_status_path):
LOGGER.warning(
"WPS status location not resolved to local path: [%s]",
wps_status_path)
job.save_log(
logger=task_logger,
level=logging.DEBUG,
message=f"Updated job status location: [{wps_status_path}].")
job.status = Status.RUNNING
job.status_message = execution.statusMessage or f"{job!s} initiation done."
job.status_location = wps_status_path
job.request = execution.request
job.response = execution.response
job.progress = JobProgress.EXECUTE_MONITOR_START
job.save_log(logger=task_logger,
message="Starting monitoring of job execution.")
job = store.update_job(job)
max_retries = 5
num_retries = 0
run_step = 0
while execution.isNotComplete() or run_step == 0:
if num_retries >= max_retries:
job.save_log(errors=execution.errors, logger=task_logger)
job = store.update_job(job)
raise Exception(
f"Could not read status document after {max_retries} retries. Giving up."
)
try:
# NOTE:
# Don't actually log anything here until process is completed (success or fail) so that underlying
# WPS execution logs can be inserted within the current job log and appear continuously.
# Only update internal job fields in case they get referenced elsewhere.
progress_min = JobProgress.EXECUTE_MONITOR_LOOP
progress_max = JobProgress.EXECUTE_MONITOR_DONE
job.progress = progress_min
run_delay = wait_secs(run_step)
execution = check_wps_status(location=wps_status_path,
settings=settings,
sleep_secs=run_delay)
job_msg = (execution.statusMessage or "").strip()
job.response = execution.response
job.status = map_status(execution.getStatus())
job_status_msg = job_msg or "n/a"
job_percent = execution.percentCompleted
job.status_message = f"Job execution monitoring (progress: {job_percent}%, status: {job_status_msg})."
if execution.isComplete():
msg_progress = f" (status: {job_msg})" if job_msg else ""
if execution.isSucceded():
wps_package.retrieve_package_job_log(
execution, job, progress_min, progress_max)
job.status = map_status(Status.SUCCEEDED)
job.status_message = f"Job succeeded{msg_progress}."
job.progress = progress_max
job.save_log(logger=task_logger)
job_results = [
ows2json_output_data(output, process, settings)
for output in execution.processOutputs
]
job.results = make_results_relative(
job_results, settings)
else:
task_logger.debug("Job failed.")
wps_package.retrieve_package_job_log(
execution, job, progress_min, progress_max)
job.status_message = f"Job failed{msg_progress}."
job.progress = progress_max
job.save_log(errors=execution.errors,
logger=task_logger)
task_logger.debug(
"Mapping Job references with generated WPS locations.")
map_locations(job, settings)
job = store.update_job(job)
except Exception as exc:
num_retries += 1
task_logger.debug("Exception raised: %s", repr(exc))
job.status_message = f"Could not read status XML document for {job!s}. Trying again..."
job.save_log(errors=execution.errors, logger=task_logger)
job = store.update_job(job)
sleep(1)
else:
num_retries = 0
run_step += 1
finally:
task_terminated = False # reached only if WPS execution completed (worker not terminated beforehand)
job = store.update_job(job)
except Exception as exc:
# if 'execute_job' finishes quickly before even reaching the 'monitoring loop'
# consider WPS execution produced an error (therefore Celery worker not terminated)
task_terminated = False
LOGGER.exception("Failed running [%s]", job)
LOGGER.debug("Failed job [%s] raised an exception.", job, exc_info=exc)
# note: don't update the progress here to preserve last one that was set
job.status = map_status(Status.FAILED)
job.status_message = f"Failed to run {job!s}."
errors = f"{fully_qualified_name(exc)}: {exc!s}"
job.save_log(errors=errors, logger=task_logger)
job = store.update_job(job)
finally:
# if task worker terminated, local 'job' is out of date compared to remote/background runner last update
job = store.fetch_by_id(job.id)
if task_terminated and map_status(job.status) == Status.FAILED:
job.status = Status.DISMISSED
task_success = map_status(
job.status) not in JOB_STATUS_CATEGORIES[StatusCategory.FAILED]
collect_statistics(task_process, settings, job, rss_start)
if task_success:
job.progress = JobProgress.EXECUTE_MONITOR_END
job.status_message = f"Job {job.status}."
job.save_log(logger=task_logger)
if task_success:
job.progress = JobProgress.NOTIFY
send_job_complete_notification_email(job, task_logger, settings)
if job.status not in JOB_STATUS_CATEGORIES[StatusCategory.FINISHED]:
job.status = Status.SUCCEEDED
job.status_message = f"Job {job.status}."
job.mark_finished()
if task_success:
job.progress = JobProgress.DONE
job.save_log(logger=task_logger, message="Job task complete.")
job = store.update_job(job)
return job.status
def tearDown(self):
self.log("{}End of '{}': {}\n{}"
.format(self.logger_separator_tests, self.current_test_name(), now(), self.logger_separator_tests))
def tearDownClass(cls):
cls.clear_test_processes()
testing.tearDown()
cls.log("{}End of '{}': {}\n{}"
.format(cls.logger_separator_cases, cls.current_case_name(), now(), cls.logger_separator_cases))
