diff --git a/docs/source/index.rst b/docs/source/index.rst index 7d16d8d..b0199a5 100644 --- a/docs/source/index.rst +++ b/docs/source/index.rst @@ -14,6 +14,7 @@ PyTheranostics is a comprehensive Python library for nuclear medicine image proc intro/overview intro/installation + intro/logging tutorials/getting_started/basic_usage .. toctree:: diff --git a/docs/source/intro/logging.rst b/docs/source/intro/logging.rst new file mode 100644 index 0000000..d943d37 --- /dev/null +++ b/docs/source/intro/logging.rst @@ -0,0 +1,262 @@ +.. _logging_guide: + +Logging and Verbosity Control +============================== + +PyTheranostics uses Python's standard ``logging`` module to provide configurable output verbosity. This allows you to control how much information is displayed during processing, making it suitable for both interactive notebook use and automated pipelines. + +Overview +-------- + +The logging system provides four severity levels: + +.. list-table:: + :widths: 15 30 55 + :header-rows: 1 + + * - Level + - When to Use + - What You'll See + * - ``DEBUG`` + - Troubleshooting and development + - Every step: individual timepoint loading, mask resampling operations, registration iterations + * - ``INFO`` + - Normal production use + - Important milestones: "Loaded 5 CT timepoints", "Applied mappings", file save operations + * - ``WARNING`` + - Default (quiet mode) + - Only important notices: mask overwrites, data quality issues, deprecated features + * - ``ERROR`` + - Critical issues only + - Fatal errors that prevent processing + +Quick Start +----------- + +Set Logging Level in Notebooks +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +Add this at the top of your notebook to control verbosity: + +.. code-block:: python + + import logging + + # Quiet mode (recommended for notebooks) - only warnings and errors + logging.basicConfig(level=logging.WARNING, format='%(levelname)s: %(message)s') + + # Normal mode - see important milestones + logging.basicConfig(level=logging.INFO, format='%(levelname)s: %(message)s') + + # Verbose mode - see every step (for debugging) + logging.basicConfig(level=logging.DEBUG, format='%(levelname)s: %(message)s') + +.. note:: + Call ``basicConfig()`` **before** importing PyTheranostics modules for the settings to take effect. + +Example: Clean Notebook Output +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + import logging + logging.basicConfig(level=logging.WARNING) # Quiet mode + + from pytheranostics.imaging_ds.cycle_loader import create_studies_with_masks + + # This will now run quietly, only showing warnings/errors + longCT, longSPECT, inj, mappings = create_studies_with_masks( + storage_root="./data", + patient_id="PATIENT001", + cycle_no=1, + calibration_factor=106.0, + auto_map=True + ) + +Example: Debugging with Verbose Output +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + import logging + logging.basicConfig(level=logging.DEBUG, format='%(name)s - %(levelname)s: %(message)s') + + from pytheranostics.imaging_ds.cycle_loader import create_studies_with_masks + + # This will show detailed progress: + # - Loading timepoint 0 from CT_TP1... + # - ✓ Timepoint 0 loaded + # - Resampling Masks: Liver ... + # - etc. + longCT, longSPECT, inj, mappings = create_studies_with_masks(...) + +Affected Modules +---------------- + +The following modules use the logging system: + +Imaging & Data Loading +~~~~~~~~~~~~~~~~~~~~~~~ + +* ``pytheranostics.imaging_ds.longitudinal_study`` + + - Logs timepoint loading progress (parallel and sequential) + - Reports mask addition and overwrites + - Shows registration iterations and Jaccard indices + - Confirms file save operations + +* ``pytheranostics.imaging_ds.mapping_summary`` + + - Reports mapping statistics per timepoint + - Shows applied mappings when verbose mode enabled + - Confirms JSON export of mapping details + +* ``pytheranostics.imaging_tools.tools`` + + - Reports DICOM metadata extraction (injected activity, patient weight) + - Warns about orientation matrix corrections + - Shows mask resampling and registration progress + +Common Use Cases +---------------- + +Case 1: Interactive Notebook (Recommended) +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +For clean notebook output, use WARNING level: + +.. code-block:: python + + import logging + logging.basicConfig(level=logging.WARNING, format='%(message)s') + +This gives you a clean interface while still alerting you to important issues like: + +* Mask overwrites +* Missing DICOM metadata +* Data quality warnings + +Case 2: Production Pipeline +~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +For automated workflows, use INFO level with more context: + +.. code-block:: python + + import logging + logging.basicConfig( + level=logging.INFO, + format='%(asctime)s - %(name)s - %(levelname)s: %(message)s', + filename='processing.log' + ) + +This logs important milestones to a file for audit trails. + +Case 3: Debugging Issues +~~~~~~~~~~~~~~~~~~~~~~~~~ + +When troubleshooting, enable DEBUG with full context: + +.. code-block:: python + + import logging + logging.basicConfig( + level=logging.DEBUG, + format='%(asctime)s - %(name)s:%(lineno)d - %(levelname)s: %(message)s' + ) + +This shows every operation with timestamps and source locations. + +Advanced Configuration +---------------------- + +Module-Specific Levels +~~~~~~~~~~~~~~~~~~~~~~~ + +You can set different log levels for different modules: + +.. code-block:: python + + import logging + + # Global default: WARNING + logging.basicConfig(level=logging.WARNING) + + # But show INFO for longitudinal study operations + logging.getLogger('pytheranostics.imaging_ds.longitudinal_study').setLevel(logging.INFO) + + # And DEBUG for mapping summary + logging.getLogger('pytheranostics.imaging_ds.mapping_summary').setLevel(logging.DEBUG) + +Custom Formatters +~~~~~~~~~~~~~~~~~ + +Customize the output format: + +.. code-block:: python + + import logging + + # Simple format for notebooks + logging.basicConfig(level=logging.INFO, format='%(levelname)s: %(message)s') + + # Detailed format for log files + logging.basicConfig( + level=logging.INFO, + format='%(asctime)s | %(name)-40s | %(levelname)-8s | %(message)s', + datefmt='%Y-%m-%d %H:%M:%S' + ) + +Troubleshooting +--------------- + +"Logging settings not taking effect" +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +**Problem**: You set the logging level but still see too much or too little output. + +**Solution**: Make sure to call ``logging.basicConfig()`` **before** importing any PyTheranostics modules: + +.. code-block:: python + + # ✓ CORRECT ORDER + import logging + logging.basicConfig(level=logging.WARNING) + from pytheranostics.imaging_ds import LongitudinalStudy # Now uses WARNING level + + # ✗ WRONG ORDER + from pytheranostics.imaging_ds import LongitudinalStudy # Uses default level + import logging + logging.basicConfig(level=logging.WARNING) # Too late! + +"Multiple log messages appearing" +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +**Problem**: Each message appears multiple times or from different loggers. + +**Solution**: This happens when ``basicConfig()`` is called multiple times. In Jupyter notebooks, restart the kernel and configure logging once at the start: + +.. code-block:: python + + # In your first notebook cell: + import logging + + # Only call this once per kernel session + if not logging.getLogger().hasHandlers(): + logging.basicConfig(level=logging.INFO, format='%(message)s') + +Migration from Previous Versions +--------------------------------- + +If you're upgrading from a version that used ``print()`` statements, no code changes are required. The transition is automatic: + +* All previous ``print()`` output is now logged at INFO or WARNING level +* To restore previous behavior (seeing all messages), use ``logging.INFO`` +* To reduce output in notebooks, use ``logging.WARNING`` + +See Also +-------- + +* :ref:`overview` - General introduction to PyTheranostics +* :ref:`installation` - Installation instructions +* `Python Logging Documentation `_ - Official Python logging guide diff --git a/pytheranostics/data/configuration_templates/voi_mappings_config.json b/pytheranostics/data/configuration_templates/voi_mappings_config.json index 870cf53..5af3592 100644 --- a/pytheranostics/data/configuration_templates/voi_mappings_config.json +++ b/pytheranostics/data/configuration_templates/voi_mappings_config.json @@ -1,5 +1,38 @@ { - "_instructions": "Map VOI names between different naming conventions and configure visualization colors. Edit this file to customize organ name mappings and plot appearance.", + "_instructions": "Configure VOI/organ naming conventions, mappings, and visualization settings.", + + "valid_organ_names": { + "_description": "List of valid organ/VOI names for validation. These default names are compatible with OLINDA dosimetry calculations. Users can add custom organs as needed for their workflows.", + "names": [ + "Kidney_Left", + "Kidney_Right", + "Liver", + "Spleen", + "Bladder", + "SubmandibularGland_Left", + "SubmandibularGland_Right", + "ParotidGland_Left", + "ParotidGland_Right", + "BoneMarrow", + "Skeleton", + "WholeBody", + "RemainderOfBody", + "TotalTumorBurden" + ] + }, + + "canonical_mappings": { + "_description": "Best-effort ROI name normalization for auto_map mode. Maps abbreviated/common names to canonical organ names. Used when auto_map=True is set in create_studies_with_masks.", + "mappings": { + "Kidney_L": "Kidney_Left", + "Kidney_R": "Kidney_Right", + "Parotid_L": "ParotidGland_Left", + "Parotid_R": "ParotidGland_Right", + "Submandibular_L": "SubmandibularGland_Left", + "Submandibular_R": "SubmandibularGland_Right", + "WBCT": "WholeBody" + } + }, "ct_mappings": { "organ_name_in_ct": "standardized_name" @@ -10,6 +43,13 @@ }, "plot_colors": { - "_description": "Configure colors for organ contours in MIP plots. Add entries with organ names or keywords as keys (case-insensitive substring matching) and matplotlib color names or hex codes as values. Leave empty {} to use matplotlib's default color cycle. Example: 'kidney': 'lime', 'liver': '#FFD700', 'tumor': 'red'" + "_description": "Color mapping for organ contours in MIP plots. Keys can be organ names or keywords (case-insensitive substring match). Any matplotlib color name or hex code is valid.", + "kidney": "lime", + "parotid": "red", + "submandibular": "red", + "lesion": "magenta", + "liver": "yellow", + "spleen": "cyan", + "tumor": "magenta" } } diff --git a/pytheranostics/imaging_ds/longitudinal_study.py b/pytheranostics/imaging_ds/longitudinal_study.py index a64499b..e5cfbdb 100644 --- a/pytheranostics/imaging_ds/longitudinal_study.py +++ b/pytheranostics/imaging_ds/longitudinal_study.py @@ -1,6 +1,7 @@ """Module for longitudinal medical imaging studies.""" import json +import logging import os import re from concurrent.futures import ThreadPoolExecutor, as_completed @@ -20,6 +21,8 @@ ) from pytheranostics.registration.phantom_to_ct import PhantomToCTBoneReg +logger = logging.getLogger(__name__) + class LongitudinalStudy: """Longitudinal Study Data Class. @@ -205,12 +208,16 @@ def from_dicom( if parallel and len(dicom_dirs) > 1: # Parallel loading for multiple timepoints - print(f"Loading {len(dicom_dirs)} {modality} timepoints in parallel...") + logger.info( + f"Loading {len(dicom_dirs)} {modality} timepoints in parallel..." + ) # Helper function for parallel execution def load_single_timepoint(args): time_id, dicom_dir = args - print(f" Loading timepoint {time_id} from {Path(dicom_dir).name}...") + logger.debug( + f" Loading timepoint {time_id} from {Path(dicom_dir).name}..." + ) return time_id, load_from_dicom_dir( dir=dicom_dir, modality=modality, @@ -230,11 +237,13 @@ def load_single_timepoint(args): time_id, (image, meta) = future.result() images[time_id] = image metadata[time_id] = meta - print(f" ✓ Timepoint {time_id} loaded") + logger.debug(f" ✓ Timepoint {time_id} loaded") else: # Sequential loading for time_id, dicom_dir in enumerate(dicom_dirs): - print(f"Loading timepoint {time_id} from {Path(dicom_dir).name}...") + logger.info( + f"Loading timepoint {time_id} from {Path(dicom_dir).name}..." + ) image, meta = load_from_dicom_dir( dir=dicom_dir, modality=modality, @@ -691,8 +700,8 @@ def add_masks_to_time_point( ) if mask_target in self.masks[time_id]: - print( - f"Warning: {mask_target} found at Time = {time_id}. It will be over-written!" + logger.warning( + f"{mask_target} found at Time = {time_id}. It will be over-written!" ) # Masks are in the right orientation and spacing, however there could be discrepancies @@ -756,8 +765,8 @@ def add_raw_masks_to_time_point( SimpleITK.GetArrayFromImage(mask_itk), axes=(1, 2, 0) ) if mask_name in self.masks[time_id]: - print( - f"Warning: {mask_name} found at Time = {time_id}. It will be over-written!" + logger.warning( + f"{mask_name} found at Time = {time_id}. It will be over-written!" ) self.masks[time_id][mask_name] = mask_array.astype(numpy.bool_) @@ -865,7 +874,7 @@ def add_bone_marrow_mask_from_phantom( phantom_skeleton_path (Path): Path to phantom Skeleton .nii file. phantom_bone_marrow_path (Path): Path to phantom Bone Marrow .nii file. """ - print( + logger.info( "Running Personalized Bone Marrow generation from XCAT Phantom. This feature is unstable. Please review the generated BoneMarrow masks." ) @@ -882,11 +891,11 @@ def add_bone_marrow_mask_from_phantom( best_index = {time_id: 0 for time_id in self.images.keys()} for i in range(num_iterations): - print(f"Registration :: Iteration {i+1}") + logger.info(f"Registration :: Iteration {i+1}") # Loop through each time point: for time_id, ct in self.images.items(): # Register Skeleton - print( + logger.debug( f" >> Registering Phantom Skeleton to CT at time point {time_id} ..." ) RegManager = PhantomToCTBoneReg( @@ -921,14 +930,14 @@ def add_bone_marrow_mask_from_phantom( best_index[time_id] = jaccard # Calculate Index - print( + logger.debug( f" >>> Jaccard Index between Skeleton and Segmented Bone Marrow: {jaccard: 1.2f}" ) # Final Results: - print(" >>> Final Jaccard Indices:") + logger.info(" >>> Final Jaccard Indices:") for time_id in self.masks.keys(): - print(f" >>> Time point {time_id}: {best_index[time_id]}") + logger.info(f" >>> Time point {time_id}: {best_index[time_id]}") return None @@ -960,7 +969,7 @@ def save_image_to_nii_at( time_id (int): The time ID representing the time point to be saved. out_path (Path): The path to the folder where images will be written. """ - print(f"Writing Image ({name}) into nifty file.") + logger.info(f"Writing Image ({name}) into nifty file.") SimpleITK.WriteImage( image=SimpleITK.Cast(self.images[time_id], SimpleITK.sitkInt32), fileName=out_path / f"Image_{time_id}{name}.nii.gz", @@ -977,7 +986,7 @@ def save_image_to_mhd_at( time_id (int): The time ID representing the time point to be saved. out_path (Path): The path to the folder where images will be written. """ - print(f"Writing Image ({name}) into mhd file.") + logger.info(f"Writing Image ({name}) into mhd file.") SimpleITK.WriteImage( image=SimpleITK.Cast(self.images[time_id], SimpleITK.sitkInt32), fileName=os.path.join(out_path, f"{name}.mhd"), @@ -1015,7 +1024,7 @@ def save_masks_to_nii_at( ref_image=self.images[time_id], ) - print(f"Writing Masks ({mask_names}) into nifty file.") + logger.info(f"Writing Masks ({mask_names}) into nifty file.") SimpleITK.WriteImage( image=mask_image, fileName=out_path / f"Masks_{time_id}.nii.gz" diff --git a/pytheranostics/imaging_ds/mapping_summary.py b/pytheranostics/imaging_ds/mapping_summary.py index c990026..edc0980 100644 --- a/pytheranostics/imaging_ds/mapping_summary.py +++ b/pytheranostics/imaging_ds/mapping_summary.py @@ -7,9 +7,12 @@ from __future__ import annotations import json +import logging from pathlib import Path from typing import Dict, Iterable, List, Tuple +logger = logging.getLogger(__name__) + def _split_modalities( mapping: Dict[str, str], @@ -76,14 +79,14 @@ def summarize_used_mappings( unmapped_ct_n = len(parts.get("unmapped_ct", [])) unmapped_sp_n = len(parts.get("unmapped_spect", [])) msg += f" | Unmapped: CT {unmapped_ct_n}, SPECT {unmapped_sp_n}" - print(msg) + logger.info(msg) if verbose: def _print_pairs(label: str, pairs: Iterable[Tuple[str, str]]) -> None: shown = 0 for k, v in pairs: - print(f" {label}: {k} -> {v}") + logger.info(f" {label}: {k} -> {v}") shown += 1 if shown >= sample_limit: break @@ -95,10 +98,10 @@ def _print_pairs(label: str, pairs: Iterable[Tuple[str, str]]) -> None: if include_unmapped: if parts.get("unmapped_ct"): sample_ct = parts["unmapped_ct"][:sample_limit] - print(f" Unmapped CT (identity): {sample_ct}") + logger.info(f" Unmapped CT (identity): {sample_ct}") if parts.get("unmapped_spect"): sample_sp = parts["unmapped_spect"][:sample_limit] - print(f" Unmapped SPECT (identity): {sample_sp}") + logger.info(f" Unmapped SPECT (identity): {sample_sp}") if save_json_path is not None: out = { @@ -119,4 +122,4 @@ def _print_pairs(label: str, pairs: Iterable[Tuple[str, str]]) -> None: save_path = Path(save_json_path) with save_path.open("w") as f: json.dump(out, f, indent=2) - print(f"Saved detailed mapping summary to {save_path}") + logger.info(f"Saved detailed mapping summary to {save_path}") diff --git a/pytheranostics/imaging_tools/tools.py b/pytheranostics/imaging_tools/tools.py index 0cb3538..5f43e14 100644 --- a/pytheranostics/imaging_tools/tools.py +++ b/pytheranostics/imaging_tools/tools.py @@ -3,6 +3,7 @@ from __future__ import annotations import glob +import logging from pathlib import Path from typing import TYPE_CHECKING, Dict, List, Optional, Tuple @@ -23,6 +24,8 @@ transform_ct_mask_to_spect, ) +logger = logging.getLogger(__name__) + # TODO: Move under dicomtools, and have two sets: one generic (the current dicomtools.py) and on specific for pyTheranostic functions (containing # the code below) @@ -91,22 +94,22 @@ def load_metadata(dir: str, modality: str) -> ImagingMetadata: injected_activity > 20000 ): # Activity likely in Bq instead of MBq injected_activity /= 1e6 - print( + logger.info( f"Injected activity found in DICOM Header: {injected_activity:2.1f} MBq. Please verify." ) except AttributeError: # Sequence exists but RadionuclideTotalDose attribute is missing - print( + logger.warning( "RadiopharmaceuticalInformationSequence found but RadionuclideTotalDose is missing." ) else: # Sequence exists but is empty - this may indicate a data quality issue - print( - "Warning: RadiopharmaceuticalInformationSequence is empty. This may indicate a data quality issue." + logger.warning( + "RadiopharmaceuticalInformationSequence is empty. This may indicate a data quality issue." ) if injected_activity is None: - print("Using default injected activity: 7400 MBq") + logger.info("Using default injected activity: 7400 MBq") injected_activity = 7400.0 # Global attributes. Should be the same in all slices! @@ -394,7 +397,9 @@ def load_from_dicom_dir( ) except AttributeError: - print("No calibration factor provided, Data might not be in BQ/ML ...") + logger.warning( + "No calibration factor provided, Data might not be in BQ/ML ..." + ) # Load Meta Data using pydicom. meta = load_metadata(dir=dir, modality=modality) @@ -403,7 +408,7 @@ def load_from_dicom_dir( image = force_orthogonality(image=image) # Display Origin and Orientation. - print( + logger.debug( f"Modality: {modality} -> Origin: {image.GetOrigin()}; Direction: {image.GetDirection()}" ) @@ -452,10 +457,12 @@ def force_orthogonality(image: SimpleITK.Image) -> SimpleITK.Image: Image with orthogonal orientation vectors. """ if not are_vectors_orthogonal(image.GetDirection()): - print("Patient Orientation Vectors are NOT orthogonal. Forcing...") + logger.warning("Patient Orientation Vectors are NOT orthogonal. Forcing...") prev_origin = image.GetDirection() new_origin = [round(vec_element) for vec_element in prev_origin] - print(f">> Original Orientation: {prev_origin}, New Orientation: {new_origin} ") + logger.debug( + f">> Original Orientation: {prev_origin}, New Orientation: {new_origin} " + ) image.SetDirection(new_origin) else: prev_origin = image.GetDirection() @@ -586,7 +593,7 @@ def load_and_resample_RT_to_target( resampled_masks: Dict[str, SimpleITK.Image] = {} for mask_name, mask_image in ref_masks.items(): - print(f"Resampling Masks: {mask_name} ...") + logger.debug(f"Resampling Masks: {mask_name} ...") resampled_masks[mask_name] = resample_mask_to_target( mask_img=mask_image, target_img=target_img ) @@ -627,7 +634,7 @@ def load_and_register_RT_to_target( resampled_masks: Dict[str, SimpleITK.Image] = {} for mask_name, mask_image in ref_masks.items(): - print(f"Registering Masks: {mask_name} ...") + logger.debug(f"Registering Masks: {mask_name} ...") resampled_masks[mask_name] = transform_ct_mask_to_spect( mask=mask_image, spect=target_img, transform=transform )