From 0ef13bd9a51f66397c37833894c58540c72f4e3b Mon Sep 17 00:00:00 2001 From: Richard Harris Date: Mon, 13 Nov 2023 14:47:06 +0000 Subject: [PATCH] Rh/logging config leak --- .gitlab-ci.yml | 26 ++++++++++++++++ CHANGELOG.md | 9 +++++- docs/docs/install.rst | 4 +-- docs/requirements.txt | 2 +- python/pod5/pyproject.toml | 2 +- python/pod5/src/pod5/tools/pod5_filter.py | 4 +-- python/pod5/src/pod5/tools/pod5_merge.py | 28 ++++++++++------- python/pod5/src/pod5/tools/pod5_subset.py | 3 +- python/pod5/src/pod5/tools/utils.py | 38 +++++++++++++---------- 9 files changed, 79 insertions(+), 37 deletions(-) diff --git a/.gitlab-ci.yml b/.gitlab-ci.yml index 13a12fb..1cb612b 100644 --- a/.gitlab-ci.yml +++ b/.gitlab-ci.yml @@ -134,6 +134,32 @@ tag_version_check: exit 1; fi +api_lib_version_check: + stage: .pre + needs: + - "prepare_version" + image: ${CI_REGISTRY}/minknow/images/build-x86_64-gcc9:latest + script: + - cat _version.py + - NO_DEV_VERSION=$(grep "__version__" _version.py | awk '{print $5}' | tr -d "'" | cut -d'+' -f1 | sed 's/\([0-9]\+\.[0-9]\+\.[0-9]\+\).*$/\1/') + - echo $NO_DEV_VERSION + - cat python/pod5/pyproject.toml + - echo "If this jobs fails then we have forgotten to match the api and lib version in the api python/pod5/pyproject.toml" + - grep "lib_pod5\s*==\s*$NO_DEV_VERSION" python/pod5/pyproject.toml + +docs_version_check: + stage: .pre + needs: + - "prepare_version" + image: ${CI_REGISTRY}/minknow/images/build-x86_64-gcc9:latest + script: + - cat _version.py + - NO_DEV_VERSION=$(grep "__version__" _version.py | awk '{print $5}' | tr -d "'" | cut -d'+' -f1 | sed 's/\([0-9]\+\.[0-9]\+\.[0-9]\+\).*$/\1/') + - echo $NO_DEV_VERSION + - cat docs/requirements.txt + - echo "If this jobs fails then we have forgotten to update the pod5 version in the docs/requirements.txt" + - grep "pod5\s*==\s*$NO_DEV_VERSION" docs/requirements.txt + pre-commit checks: image: ${CI_REGISTRY}/traque/ont-docker-base/ont-base-python:3.10 stage: .pre diff --git a/CHANGELOG.md b/CHANGELOG.md index d5256dd..cdf3a88 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,7 +7,14 @@ All notable changes, updates, and fixes to pod5 will be documented here The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/) and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). -## Unreleased + +## [0.3.1] 2023-11-10 + +### Fixed + +- Logging no longer calls `basicConfig` which may unintentionally edit users logging configuration + +## [0.3.0] 2023-11-07 ### Changed diff --git a/docs/docs/install.rst b/docs/docs/install.rst index 8bc62de..d2b0f11 100644 --- a/docs/docs/install.rst +++ b/docs/docs/install.rst @@ -28,7 +28,7 @@ Developing with Conan For this development process you will need `conan `_ installed. You can install ``conan<2`` using ``pip`` or your platforms' package manager (e.g. ``brew``) -You will also need the python ``setuptools_scm`` package to manage pod5 versioning: +You will also need the python ``setuptools_scm==7.1.0`` package to manage pod5 versioning: .. code-block:: console @@ -47,7 +47,7 @@ You will also need the python ``setuptools_scm`` package to manage pod5 versioni .. code-block:: console # Creates _version.py and cmake/POD5Version.cmake which are ignored by git - $ pip install setuptools_scm + $ pip install setuptools_scm==7.1.0 $ python -m setuptools_scm $ python -m pod5_make_version diff --git a/docs/requirements.txt b/docs/requirements.txt index a7f4e7c..bdde7d1 100644 --- a/docs/requirements.txt +++ b/docs/requirements.txt @@ -2,4 +2,4 @@ sphinx-rtd-theme sphinx==v5.3.0 myst-parser # Paths are relative to project root for ReadTheDocs and docs/Makefile -pod5==0.3.0 +pod5==0.3.1 diff --git a/python/pod5/pyproject.toml b/python/pod5/pyproject.toml index 6ca4589..53f556a 100644 --- a/python/pod5/pyproject.toml +++ b/python/pod5/pyproject.toml @@ -22,7 +22,7 @@ classifiers=[ ] dependencies = [ - "lib_pod5 == 0.2.9", + "lib_pod5 == 0.3.1", "iso8601", 'importlib-metadata; python_version<"3.8"', "more_itertools", diff --git a/python/pod5/src/pod5/tools/pod5_filter.py b/python/pod5/src/pod5/tools/pod5_filter.py index 0d4e8c2..940bed8 100644 --- a/python/pod5/src/pod5/tools/pod5_filter.py +++ b/python/pod5/src/pod5/tools/pod5_filter.py @@ -100,7 +100,7 @@ def filter_reads(dest: Path, sources: pl.DataFrame, duplicate_ok: bool) -> None: while repacker.currently_open_file_reader_count >= active_limit: pbar.update(repacker.reads_completed - pbar.n) - sleep(0.05) + sleep(0.2) with p5.Reader(src) as reader: repacker.add_selected_reads_to_output(output, reader, read_ids) @@ -109,7 +109,7 @@ def filter_reads(dest: Path, sources: pl.DataFrame, duplicate_ok: bool) -> None: repacker.set_output_finished(output) while repacker.currently_open_file_reader_count > 0: pbar.update(repacker.reads_completed - pbar.n) - sleep(0.05) + sleep(0.1) repacker.finish() pbar.close() diff --git a/python/pod5/src/pod5/tools/pod5_merge.py b/python/pod5/src/pod5/tools/pod5_merge.py index 075f6c8..a836fe0 100644 --- a/python/pod5/src/pod5/tools/pod5_merge.py +++ b/python/pod5/src/pod5/tools/pod5_merge.py @@ -52,6 +52,7 @@ def merge_pod5( ) print(f"Merging reads from {len(_inputs)} files") + logger.debug(f"Merging reads from {len(_inputs)} files into {output.absolute()}") # Open the output file writer with p5.Writer(output.absolute()) as writer: @@ -62,31 +63,36 @@ def merge_pod5( pbar = tqdm( total=len(_inputs), desc="Merging", - unit="Files", + unit="File", leave=True, position=0, **PBAR_DEFAULTS, ) active_limit = max(readers, 1) + logger.debug(f"{active_limit=}") + opened_readers = 0 active = 0 - while _inputs or active > 0: pbar.update(opened_readers - active - pbar.n) active = repacker.currently_open_file_reader_count - if active < active_limit: - if _inputs: - with p5.Reader(_inputs.pop()) as reader: - opened_readers += 1 - repacker.add_all_reads_to_output(repacker_output, reader) - continue - else: - repacker.set_output_finished(repacker_output) + if _inputs and (active < active_limit): + next_input = _inputs.pop() + logger.debug(f"submitting: {next_input=}") + with p5.Reader(next_input) as reader: + opened_readers += 1 + repacker.add_all_reads_to_output(repacker_output, reader) continue - sleep(0.05) + if not _inputs: + logger.debug("no inputs remaining - finishing") + repacker.set_output_finished(repacker_output) + break + + sleep(0.2) + logger.debug(f"{len(_inputs)=}, {active=}, {active>0=}") repacker.finish() del repacker diff --git a/python/pod5/src/pod5/tools/pod5_subset.py b/python/pod5/src/pod5/tools/pod5_subset.py index d19222c..6673204 100644 --- a/python/pod5/src/pod5/tools/pod5_subset.py +++ b/python/pod5/src/pod5/tools/pod5_subset.py @@ -525,7 +525,6 @@ def subset_reads( unit="Reads", leave=False, position=process, - delay=2, **PBAR_DEFAULTS, ) @@ -538,7 +537,7 @@ def subset_reads( for source, reads in sources.group_by(PL_SRC_FNAME): while repacker.currently_open_file_reader_count >= active_limit: pbar.update(repacker.reads_completed - pbar.n) - sleep(0.05) + sleep(0.2) read_ids = reads.get_column(PL_READ_ID).unique().to_list() logger.debug(f"Subsetting: {source} - n_reads: {len(read_ids)}") diff --git a/python/pod5/src/pod5/tools/utils.py b/python/pod5/src/pod5/tools/utils.py index 926fbfa..41b552c 100644 --- a/python/pod5/src/pod5/tools/utils.py +++ b/python/pod5/src/pod5/tools/utils.py @@ -24,44 +24,48 @@ def init_logging(): if not is_pod5_debug(): logger = logging.getLogger("pod5") logger.addHandler(logging.NullHandler()) + return logger + + datetime_now = datetime.datetime.now().strftime("%Y-%m-%d--%H-%M-%S") + if mp.current_process().name == "MainProcess": + pid = "main" else: - datetime_now = datetime.datetime.now().strftime("%Y-%m-%d--%H-%M-%S") - if mp.current_process().name == "MainProcess": - pid = "main" - else: - pid = f"p-{os.getpid()}" - logging.basicConfig( - level=logging.DEBUG, - filename=f"{datetime_now}-{pid}-pod5.log", - format="%(asctime)s %(levelname)s %(message)s", - ) - logger = logging.getLogger("pod5") + pid = f"p-{os.getpid()}" + + logger = logging.getLogger("pod5") + logger.setLevel(logging.DEBUG) + file_handler = logging.FileHandler(filename=f"{datetime_now}-{pid}-pod5.log") + file_handler.setFormatter( + logging.Formatter("%(asctime)s %(levelname)s %(message)s") + ) + file_handler.setLevel(logging.DEBUG) + logger.addHandler(file_handler) return logger def logged(log_return: bool = False, log_args: bool = False, log_time: bool = False): """Logging parameterised decorator""" - log_fn = logging.debug def decorator(func): @functools.wraps(func) def wrapper(*args, **kwargs): + logger = logging.getLogger("pod5") uid = f"{str(uuid.uuid4())[:2]}:'{func.__name__}'" if log_args: - log_fn("{0}:{1}, {2}".format(uid, args, kwargs)) + logger.debug("{0}:{1}, {2}".format(uid, args, kwargs)) else: - log_fn("{0}".format(uid)) + logger.debug("{0}".format(uid)) try: started = perf_counter() ret = func(*args, **kwargs) except Exception as exc: - log_fn("{0}:Exception:{1}".format(uid, exc)) + logger.debug("{0}:Exception:{1}".format(uid, exc)) raise exc if log_time: duration_s = perf_counter() - started - log_fn("{0}:Done:{1:.3f}s".format(uid, duration_s)) + logger.debug("{0}:Done:{1:.3f}s".format(uid, duration_s)) if log_return: - log_fn("{0}:Returned:{1}".format(uid, ret)) + logger.debug("{0}:Returned:{1}".format(uid, ret)) return ret return wrapper