Merge pull request #25 from tcezard/EVA3438_reduce_log_level

EVA-3438 - Lower log level

bin/eva-sub-cli.py

@@ -1,4 +1,5 @@
 #!/usr/bin/env python
+import logging
 import os
 import sys
 from argparse import ArgumentParser
@@ -7,6 +8,7 @@
 
 from eva_sub_cli import main
 from eva_sub_cli.main import VALIDATE, SUBMIT, DOCKER, NATIVE
+from eva_sub_cli.utils import is_submission_dir_writable
 
 
 def validate_command_line_arguments(args, argparser):
@@ -27,6 +29,10 @@ def validate_command_line_arguments(args, argparser):
         argparser.print_usage()
         sys.exit(1)
 
+    if not is_submission_dir_writable(args.submission_dir):
+        print(f"'{args.submission_dir}' does not have write permissions or is not a directory.")
+        sys.exit(1)
+
 
 if __name__ == "__main__":
     argparser = ArgumentParser(description='EVA Submission CLI - validate and submit data to EVA')
@@ -66,8 +72,10 @@ def validate_command_line_arguments(args, argparser):
 
     args = argparser.parse_args()
 
+    validate_command_line_arguments(args, argparser)
+
     logging_config.add_stdout_handler()
+    logging_config.add_file_handler(os.path.join(args.submission_dir, 'eva_submission.log'), logging.DEBUG)
 
-    validate_command_line_arguments(args, argparser)
     # Pass on all the arguments
     main.orchestrate_process(**args.__dict__)

eva_sub_cli/__init__.py

@@ -15,3 +15,4 @@
 SUBMISSION_WS_VAR = 'SUBMISSION_WS_URL'
 ENA_WEBIN_ACCOUNT_VAR = 'ENA_WEBIN_ACCOUNT'
 ENA_WEBIN_PASSWORD_VAR = 'ENA_WEBIN_PASSWORD'
+

eva_sub_cli/submit.py

@@ -61,7 +61,6 @@ def update_config_with_submission_id_and_upload_url(self, submission_id, upload_
         self.sub_config.set(SUB_CLI_CONFIG_KEY_SUBMISSION_ID, value=submission_id)
         self.sub_config.set(SUB_CLI_CONFIG_KEY_SUBMISSION_UPLOAD_URL, value=upload_url)
 
-
     def _upload_submission(self):
         if READY_FOR_SUBMISSION_TO_EVA not in self.sub_config or not self.sub_config[READY_FOR_SUBMISSION_TO_EVA]:
             raise Exception(f'There are still validation errors that needs to be addressed. '
@@ -76,42 +75,44 @@ def _upload_submission(self):
     @retry(tries=5, delay=10, backoff=5)
     def _upload_file(self, submission_upload_url, input_file):
         base_name = os.path.basename(input_file)
-        self.info(f'Transfer {base_name} to EVA FTP')
+        self.debug(f'Transfer {base_name} to EVA FTP')
         r = requests.put(urljoin(submission_upload_url, base_name), data=open(input_file, 'rb'))
         r.raise_for_status()
-        self.info(f'Upload of {base_name} completed')
+        self.debug(f'Upload of {base_name} completed')
 
-    def verify_submission_dir(self, submission_dir):
-        if not os.path.exists(submission_dir):
-            os.makedirs(submission_dir)
-        if not os.access(submission_dir, os.W_OK):
-            raise Exception(f"The directory '{submission_dir}' does not have write permissions.")
+    def _initiate_submission(self):
+        response = requests.post(self.submission_initiate_url,
+                                 headers={'Accept': 'application/hal+json',
+                                          'Authorization': 'Bearer ' + self.auth.token})
+        response.raise_for_status()
+        response_json = response.json()
+        self.debug(f'Submission ID {response_json["submissionId"]} received!!')
+        # update config with submission id and upload url
+        self.update_config_with_submission_id_and_upload_url(response_json["submissionId"], response_json["uploadUrl"])
+
+    def _complete_submission(self):
+        response = requests.put(
+            self.submission_uploaded_url.format(submissionId=self.sub_config.get(SUB_CLI_CONFIG_KEY_SUBMISSION_ID)),
+            headers={'Accept': 'application/hal+json', 'Authorization': 'Bearer ' + self.auth.token}
+        )
+        response.raise_for_status()
+        self.debug("Submission ID {} Complete".format(self.sub_config.get(SUB_CLI_CONFIG_KEY_SUBMISSION_ID)))
+        # update config with completion of the submission
+        self.sub_config.set(SUB_CLI_CONFIG_KEY_COMPLETE, value=True)
 
     def submit(self, resume=False):
         if READY_FOR_SUBMISSION_TO_EVA not in self.sub_config or not self.sub_config[READY_FOR_SUBMISSION_TO_EVA]:
             raise Exception(f'There are still validation errors that need to be addressed. '
                             f'Please review, address and re-validate before submitting.')
         if not (resume or self.sub_config.get(SUB_CLI_CONFIG_KEY_SUBMISSION_UPLOAD_URL)):
-            self.verify_submission_dir(self.submission_dir)
-            response = requests.post(self.submission_initiate_url,
-                                     headers={'Accept': 'application/hal+json',
-                                              'Authorization': 'Bearer ' + self.auth.token})
-            response.raise_for_status()
-            response_json = response.json()
-            self.info(f'Submission ID {response_json["submissionId"]} received!!')
-            # update config with submission id and upload url
-            self.update_config_with_submission_id_and_upload_url(response_json["submissionId"], response_json["uploadUrl"])
+            self.info(f'Initiate submission')
+            self._initiate_submission()
 
         # upload submission
+        self.info(f'Upload data')
         self._upload_submission()
 
         # Complete the submission
-        response = requests.put(
-            self.submission_uploaded_url.format(submissionId=self.sub_config.get(SUB_CLI_CONFIG_KEY_SUBMISSION_ID)),
-            headers={'Accept': 'application/hal+json', 'Authorization': 'Bearer ' + self.auth.token}
-        )
-        response.raise_for_status()
-        self.info("Submission ID {} Complete".format(self.sub_config.get(SUB_CLI_CONFIG_KEY_SUBMISSION_ID)))
-        # update config with completion of the submission
-        self.sub_config.set(SUB_CLI_CONFIG_KEY_COMPLETE, value=True)
+        self.info(f'Complete submission')
+        self._complete_submission()
 

eva_sub_cli/utils.py

@@ -0,0 +1,11 @@
+import os
+
+
+def is_submission_dir_writable(submission_dir):
+    if not os.path.exists(submission_dir):
+        os.makedirs(submission_dir)
+    if not os.path.isdir(submission_dir):
+        return False
+    if not os.access(submission_dir, os.W_OK):
+        return False
+    return True

eva_sub_cli/validators/docker_validator.py

@@ -5,7 +5,6 @@
 import subprocess
 import time
 
-from ebi_eva_common_pyutils.command_utils import run_command_with_output
 from ebi_eva_common_pyutils.logger import logging_config
 
 from eva_sub_cli.validators.validator import Validator, VALIDATION_OUTPUT_DIR
@@ -60,7 +59,7 @@ def run_docker_validator(self):
 
         try:
             # remove all existing files from container
-            run_command_with_output(
+            self._run_quiet_command(
                 "Remove existing files from validation directory in container",
                 f"{self.docker_path} exec {self.container_name} rm -rf work {container_validation_dir}"
             )
@@ -71,9 +70,9 @@ def run_docker_validator(self):
             docker_cmd = self.get_docker_validation_cmd()
             # start validation
             # FIXME: If nextflow fails in the docker exec still exit with error code 0
-            run_command_with_output("Run Validation using Nextflow", docker_cmd)
+            self._run_quiet_command("Run Validation using Nextflow", docker_cmd)
             # copy validation result to user host
-            run_command_with_output(
+            self._run_quiet_command(
                 "Copy validation output from container to host",
                 f"{self.docker_path} cp {self.container_name}:{container_validation_dir}/{container_validation_output_dir} {self.output_dir}"
             )
@@ -82,7 +81,7 @@ def run_docker_validator(self):
 
     def verify_docker_is_installed(self):
         try:
-            run_command_with_output(
+            self._run_quiet_command(
                 "check docker is installed and available on the path",
                 f"{self.docker_path} --version"
             )
@@ -91,7 +90,7 @@ def verify_docker_is_installed(self):
             raise RuntimeError(f"Please make sure docker ({self.docker_path}) is installed and available on the path")
 
     def verify_container_is_running(self):
-        container_run_cmd_output = run_command_with_output("check if container is running", f"{self.docker_path} ps", return_process_output=True)
+        container_run_cmd_output = self._run_quiet_command("check if container is running", f"{self.docker_path} ps", return_process_output=True)
         if container_run_cmd_output is not None and self.container_name in container_run_cmd_output:
             logger.info(f"Container ({self.container_name}) is running")
             return True
@@ -100,7 +99,7 @@ def verify_container_is_running(self):
             return False
 
     def verify_container_is_stopped(self):
-        container_stop_cmd_output = run_command_with_output(
+        container_stop_cmd_output = self._run_quiet_command(
             "check if container is stopped", f"{self.docker_path} ps -a",  return_process_output=True
         )
         if container_stop_cmd_output is not None and self.container_name in container_stop_cmd_output:
@@ -113,15 +112,15 @@ def verify_container_is_stopped(self):
     def try_restarting_container(self):
         logger.info(f"Trying to restart container {self.container_name}")
         try:
-            run_command_with_output("Try restarting container", f"{self.docker_path} start {self.container_name}")
+            self._run_quiet_command("Try restarting container", f"{self.docker_path} start {self.container_name}")
             if not self.verify_container_is_running():
                 raise RuntimeError(f"Container ({self.container_name}) could not be restarted")
         except subprocess.CalledProcessError as ex:
             logger.error(ex)
             raise RuntimeError(f"Container ({self.container_name}) could not be restarted")
 
     def verify_image_available_locally(self):
-        container_images_cmd_ouptut = run_command_with_output(
+        container_images_cmd_ouptut = self._run_quiet_command(
             "Check if validator image is present",
             f"{self.docker_path} images",
             return_process_output=True
@@ -136,7 +135,7 @@ def verify_image_available_locally(self):
     def run_container(self):
         logger.info(f"Trying to run container {self.container_name}")
         try:
-            run_command_with_output(
+            self._run_quiet_command(
                 "Try running container",
                 f"{self.docker_path} run -it --rm -d --name {self.container_name} {container_image}:{container_tag}"
             )
@@ -150,15 +149,15 @@ def run_container(self):
 
     def stop_running_container(self):
         if not self.verify_container_is_stopped():
-            run_command_with_output(
+            self._run_quiet_command(
                 "Stop the running container",
                 f"{self.docker_path} stop {self.container_name}"
             )
 
     def download_container_image(self):
         logger.info(f"Pulling container ({container_image}) image")
         try:
-            run_command_with_output("pull container image", f"{self.docker_path} pull {container_image}:{container_tag}")
+            self._run_quiet_command("pull container image", f"{self.docker_path} pull {container_image}:{container_tag}")
         except subprocess.CalledProcessError as ex:
             logger.error(ex)
             raise RuntimeError(f"Cannot pull container ({container_image}) image")
@@ -180,12 +179,12 @@ def verify_docker_env(self):
 
     def copy_files_to_container(self):
         def _copy(file_description, file_path):
-            run_command_with_output(
+            self._run_quiet_command(
                 f"Create directory structure for copying {file_description} into container",
                 (f"{self.docker_path} exec {self.container_name} "
                  f"mkdir -p {container_validation_dir}/{os.path.dirname(file_path)}")
             )
-            run_command_with_output(
+            self._run_quiet_command(
                 f"Copy {file_description} to container",
                 (f"{self.docker_path} cp {file_path} "
                  f"{self.container_name}:{container_validation_dir}/{file_path}")

eva_sub_cli/validators/native_validator.py

@@ -1,7 +1,6 @@
 import os
 import subprocess
 
-from ebi_eva_common_pyutils.command_utils import run_command_with_output
 from ebi_eva_common_pyutils.logger import logging_config
 
 from eva_sub_cli.validators.validator import Validator
@@ -27,7 +26,7 @@ def run_validator(self):
         self.verify_executables_installed()
         try:
             command = self.get_validation_cmd()
-            run_command_with_output("Run Validation using Nextflow", command)
+            self._run_quiet_command("Run Validation using Nextflow", command)
         except subprocess.CalledProcessError as ex:
             logger.error(ex)
 
@@ -53,7 +52,7 @@ def verify_executables_installed(self):
                            ('vcf-assembly-checker', self.assembly_checker_path),
                            ('biovalidator', self.biovalidator_path)]:
             try:
-                run_command_with_output(
+                self._run_quiet_command(
                     f"Check {name} is installed and available on the path",
                     f"{path} --version"
                 )

eva_sub_cli/validators/validator.py

@@ -2,16 +2,18 @@
 import csv
 import datetime
 import glob
+import logging
 import os
 import re
 from functools import lru_cache, cached_property
 
 import yaml
+from ebi_eva_common_pyutils.command_utils import run_command_with_output
 from ebi_eva_common_pyutils.config import WritableConfig
 
 from eva_sub_cli import ETC_DIR, SUB_CLI_CONFIG_FILE, __version__
 from eva_sub_cli.report import generate_html_report
-from ebi_eva_common_pyutils.logger import logging_config
+from ebi_eva_common_pyutils.logger import logging_config, AppLogger
 
 VALIDATION_OUTPUT_DIR = "validation_output"
 VALIDATION_RESULTS = 'validation_results'
@@ -28,7 +30,7 @@ def resolve_single_file_path(file_path):
         return files[0]
 
 
-class Validator:
+class Validator(AppLogger):
 
     def __init__(self, mapping_file, output_dir, metadata_json=None, metadata_xlsx=None,
                  submission_config: WritableConfig = None):
@@ -54,7 +56,10 @@ def __enter__(self):
     def __exit__(self, exc_type, exc_val, exc_tb):
         self.sub_config.backup()
         self.sub_config.write()
-
+    @staticmethod
+    def _run_quiet_command(command_description, command, **kwargs):
+        return run_command_with_output(command_description, command, stdout_log_level=logging.DEBUG,
+                                       stderr_log_level=logging.DEBUG, **kwargs)
     def _find_vcf_and_fasta_files(self):
         vcf_files = []
         fasta_files = []
@@ -66,7 +71,9 @@ def _find_vcf_and_fasta_files(self):
         return vcf_files, fasta_files
 
     def validate_and_report(self):
+        self.info('Start validation')
         self.validate()
+        self.info('Create report')
         self.report()
 
     def validate(self):
@@ -104,7 +111,8 @@ def check_if_file_missing(self):
                 if not os.path.exists(row['fasta']):
                     files_missing = True
                     missing_files_list.append(row['fasta'])
-                if not os.path.exists(row['report']):
+                # Assembly report is optional but should exist if it is set.
+                if row.get('report') and not os.path.exists(row['report']):
                     files_missing = True
                     missing_files_list.append(row['report'])
         return files_missing, missing_files_list

requirements.txt

@@ -4,4 +4,4 @@ minify_html==0.11.1
 openpyxl
 requests
 jsonschema
-ebi_eva_common_pyutils==0.6.1
+ebi_eva_common_pyutils==0.6.3

tests/test_main.py

@@ -38,6 +38,7 @@ def test_orchestrate_validate(self):
                 self.mapping_file, self.test_sub_dir, self.metadata_json, self.metadata_xlsx,
                 submission_config=m_config.return_value
             )
+
             with m_docker_validator() as validator:
                 validator.validate_and_report.assert_called_once_with()
 

tests/test_submit.py

@@ -7,6 +7,7 @@
 from ebi_eva_common_pyutils.config import WritableConfig
 
 from eva_sub_cli import SUB_CLI_CONFIG_FILE
+from eva_sub_cli.utils import is_submission_dir_writable
 from eva_sub_cli.validators.validator import READY_FOR_SUBMISSION_TO_EVA
 from eva_sub_cli.submit import StudySubmitter, SUB_CLI_CONFIG_KEY_SUBMISSION_ID, SUB_CLI_CONFIG_KEY_SUBMISSION_UPLOAD_URL
 
@@ -43,7 +44,6 @@ def test_submit(self):
         with patch('eva_sub_cli.submit.requests.post', return_value=mock_initiate_response) as mock_post, \
                 patch('eva_sub_cli.submit.requests.put', return_value=mock_uploaded_response) as mock_put, \
                 patch.object(StudySubmitter, '_upload_submission'), \
-                patch.object(StudySubmitter, 'verify_submission_dir'), \
                 patch.object(self.submitter, 'submission_dir', self.test_sub_dir):
 
             self.submitter.sub_config.set(READY_FOR_SUBMISSION_TO_EVA, value=True)
@@ -68,7 +68,7 @@ def test_submit_with_config(self):
         mock_uploaded_response = MagicMock()
         mock_uploaded_response.status_code = 200
 
-        self.submitter.verify_submission_dir(self.test_sub_dir)
+        assert is_submission_dir_writable(self.test_sub_dir)
         sub_config = WritableConfig(self.config_file, version='version1.0')
         sub_config.set(READY_FOR_SUBMISSION_TO_EVA, value=True)
         sub_config.write()
@@ -88,12 +88,8 @@ def test_submit_with_config(self):
             assert sub_config_data[SUB_CLI_CONFIG_KEY_SUBMISSION_ID] == "mock_submission_id"
             assert sub_config_data[SUB_CLI_CONFIG_KEY_SUBMISSION_UPLOAD_URL] == "directory to use for upload"
 
-    def test_verify_submission_dir(self):
-        self.submitter.verify_submission_dir(self.test_sub_dir)
-        assert os.path.exists(self.test_sub_dir)
-
     def test_sub_config_file_creation(self):
-        self.submitter.verify_submission_dir(self.test_sub_dir)
+        assert is_submission_dir_writable(self.test_sub_dir)
         self.submitter.sub_config.set('test_key', value='test_value')
         self.submitter.sub_config.write()
 
@@ -102,9 +98,9 @@ def test_sub_config_file_creation(self):
 
     def test_sub_config_passed_as_param(self):
         with patch('eva_sub_cli.submit.get_auth', return_value=Mock(token=self.token)):
+            assert is_submission_dir_writable(self.test_sub_dir)
             sub_config = WritableConfig(self.config_file)
             with StudySubmitter(self.test_sub_dir, vcf_files=None, metadata_file=None, submission_config=sub_config) as submitter:
-                submitter.verify_submission_dir(self.test_sub_dir)
                 submitter.sub_config.set('test_key', value='test_value')
 
             assert os.path.exists(self.config_file)