From 4e4e1053e7e25baba0ddd2bf5810236dddc9b656 Mon Sep 17 00:00:00 2001 From: Sara Sjunnebo Date: Thu, 6 Nov 2025 09:32:15 +0100 Subject: [PATCH 1/4] Add script start timestamp as ID to all logging --- taca/log/__init__.py | 23 ++++++++++++++++++++--- 1 file changed, 20 insertions(+), 3 deletions(-) diff --git a/taca/log/__init__.py b/taca/log/__init__.py index 39328652..11046508 100644 --- a/taca/log/__init__.py +++ b/taca/log/__init__.py @@ -1,15 +1,31 @@ """TACA logging module for external scripts""" import logging +from datetime import datetime + +# session id is the timestamp when this module is imported (script start) +SESSION_ID = datetime.now().strftime("%y%m%d%H%M") + + +class SessionFilter(logging.Filter): + """Attach session_id (script start timestamp) to every LogRecord.""" + + def filter(self, record): + record.session_id = SESSION_ID + return True + # get root logger ROOT_LOG = logging.getLogger() ROOT_LOG.setLevel(logging.INFO) -# Console logger +# Console logger with session_id in format +formatter = logging.Formatter( + "%(asctime)s - %(session_id)s - %(name)s - %(levelname)s - %(message)s" +) stream_handler = logging.StreamHandler() -formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") stream_handler.setFormatter(formatter) +stream_handler.addFilter(SessionFilter()) ROOT_LOG.addHandler(stream_handler) LOG_LEVELS = { @@ -36,5 +52,6 @@ def init_logger_file(log_file, log_level="INFO"): file_handle = logging.FileHandler(log_file) file_handle.setLevel(log_level) file_handle.setFormatter(formatter) + file_handle.addFilter(SessionFilter()) ROOT_LOG.addHandler(file_handle) - ROOT_LOG.addHandler(stream_handler) + ROOT_LOG.addHandler(stream_handler) \ No newline at end of file From 918347d3dc8b0523f0a0b91d7e4ec738f2aeeb6d Mon Sep 17 00:00:00 2001 From: Sara Sjunnebo Date: Thu, 6 Nov 2025 10:04:52 +0100 Subject: [PATCH 2/4] Log when commands are started and finished --- taca/analysis/analysis.py | 4 ++++ taca/analysis/analysis_element.py | 6 +++++- taca/analysis/analysis_nanopore.py | 4 ++++ taca/backup/backup.py | 4 ++++ 4 files changed, 17 insertions(+), 1 deletion(-) diff --git a/taca/analysis/analysis.py b/taca/analysis/analysis.py index 9eb6f0cc..95407070 100755 --- a/taca/analysis/analysis.py +++ b/taca/analysis/analysis.py @@ -516,6 +516,7 @@ def _process(run): run.archive_run(CONFIG["storage"]["archive_dirs"][run.sequencer_type]) if run: + logger.info(f"Starting processing of run {run}") # Determine the run type runObj = get_runObj(run, software) if not runObj: @@ -524,7 +525,9 @@ def _process(run): ) else: _process(runObj) + logger.info(f"Finished processing run {run}") else: + logger.info("Starting processing of all runs in data directories") data_dirs = CONFIG.get("analysis").get("data_dirs") mail_recipients = CONFIG.get("mail", {}).get("recipients") for data_dir in data_dirs: @@ -573,3 +576,4 @@ def _process(run): ) misc.send_mail(subject, message, mail_recipients) pass + logger.info("Finished processing all runs in data directories") diff --git a/taca/analysis/analysis_element.py b/taca/analysis/analysis_element.py index 3323aa87..c46c0a77 100755 --- a/taca/analysis/analysis_element.py +++ b/taca/analysis/analysis_element.py @@ -178,8 +178,11 @@ def _process(run_to_process): return if given_run: + logger.info(f"Starting processing of run {given_run}") _process(given_run) + logger.info(f"Finished processing run {given_run}") else: + logger.info("Starting processing of all runs in data directories") data_dirs = CONFIG.get("element_analysis").get("data_dirs") for data_dir in data_dirs: # Run folder looks like DATE_*_*, the last section is the FC side (A/B) and ID (PID for teton runs) @@ -187,7 +190,7 @@ def _process(run_to_process): for run in runs: if "FlowcellPressureCheck" in run: # Skip the pressure check runs (Teton runs) - logger.info(f"Skipping {run}") # TODO: should these be synced? + logger.info(f"Skipping {run}") continue try: _process(run) @@ -205,3 +208,4 @@ def _process(run_to_process): f"There was an error processing the run {run}. Error: {e}" ) pass + logger.info("Finished processing all runs in data directories") diff --git a/taca/analysis/analysis_nanopore.py b/taca/analysis/analysis_nanopore.py index 5612a9b5..370f4e4b 100644 --- a/taca/analysis/analysis_nanopore.py +++ b/taca/analysis/analysis_nanopore.py @@ -119,10 +119,13 @@ def ont_transfer(run_abspath: str | None): """ if run_abspath: + logger.info(f"Starting processing of run {run_abspath}") process_run(ONT_run(run_abspath)) + logger.info(f"Finished processing run {run_abspath}") # If no run is specified, locate all runs else: + logger.info("Starting processing of all runs in data directories") data_dirs = CONFIG["nanopore_analysis"]["data_dirs"] ignore_dirs = CONFIG["nanopore_analysis"]["ignore_dirs"] @@ -137,6 +140,7 @@ def ont_transfer(run_abspath: str | None): logger.info(e) except Exception as e: send_error_mail(os.path.basename(run_dir), e) + logger.info("Finished processing all runs in data directories") class WaitForRun(Exception): diff --git a/taca/backup/backup.py b/taca/backup/backup.py index e9a2165f..3643b244 100644 --- a/taca/backup/backup.py +++ b/taca/backup/backup.py @@ -373,6 +373,7 @@ def _move_run_to_archived(self, run): @classmethod def encrypt_runs(cls, run, force): """Encrypt the runs that have been collected.""" + logger.info("Started taca backup encrypt") bk = cls(run) bk.collect_runs(ext=".tar") logger.info(f"In total, found {len(bk.runs)} run(s) to be encrypted") @@ -506,10 +507,12 @@ def encrypt_runs(cls, run, force): logger.info( f"Encryption of run {run.name} is successfully done, removing run folder tarball" ) + logger.info("Finished taca backup encrypt") @classmethod def pdc_put(cls, run): """Archive the collected runs to PDC.""" + logger.info("Started taca backup put_data") bk = cls(run) bk.collect_runs(ext=".tar.gpg", filter_by_ext=True) logger.info(f"In total, found {len(bk.runs)} run(s) to send PDC") @@ -577,3 +580,4 @@ def pdc_put(cls, run): bk._move_run_to_archived(run) continue logger.warning(f"Sending file {run.tar_encrypted} to PDC failed") + logger.info("Finished taca backup put_data") From ca757c2797d9361f02d0bc4e5eaafbf0d4da64ba Mon Sep 17 00:00:00 2001 From: Sara Sjunnebo Date: Thu, 6 Nov 2025 10:06:15 +0100 Subject: [PATCH 3/4] versioning --- VERSIONLOG.md | 4 ++++ taca/__init__.py | 2 +- 2 files changed, 5 insertions(+), 1 deletion(-) diff --git a/VERSIONLOG.md b/VERSIONLOG.md index ed19b80b..7e5b9989 100644 --- a/VERSIONLOG.md +++ b/VERSIONLOG.md @@ -1,5 +1,9 @@ # TACA Version Log +## 20251106.1 + +Improve logging + ## 20251015.1 Bugfix: Get all available samples in get_noindex_stats diff --git a/taca/__init__.py b/taca/__init__.py index e1d281bc..5b70295c 100644 --- a/taca/__init__.py +++ b/taca/__init__.py @@ -1,3 +1,3 @@ """Main TACA module""" -__version__ = "1.6.11" +__version__ = "1.6.12" From 0a29fd58e85e140f1bcd7c47dd886abc3cada33b Mon Sep 17 00:00:00 2001 From: Sara Sjunnebo Date: Thu, 6 Nov 2025 10:16:47 +0100 Subject: [PATCH 4/4] Newline for ruff --- taca/log/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/taca/log/__init__.py b/taca/log/__init__.py index 11046508..9e39ea5b 100644 --- a/taca/log/__init__.py +++ b/taca/log/__init__.py @@ -54,4 +54,4 @@ def init_logger_file(log_file, log_level="INFO"): file_handle.setFormatter(formatter) file_handle.addFilter(SessionFilter()) ROOT_LOG.addHandler(file_handle) - ROOT_LOG.addHandler(stream_handler) \ No newline at end of file + ROOT_LOG.addHandler(stream_handler)