From bda9e1090ded22add354221d3741bd190a7b1fd5 Mon Sep 17 00:00:00 2001 From: rettigl Date: Thu, 18 Jul 2024 23:52:39 +0200 Subject: [PATCH 01/11] replace prints by logging --- sed/core/config.py | 36 +++++++++++------- sed/core/processor.py | 85 ++++++++++++++++++++++--------------------- 2 files changed, 65 insertions(+), 56 deletions(-) diff --git a/sed/core/config.py b/sed/core/config.py index f359c426..8de69c1f 100644 --- a/sed/core/config.py +++ b/sed/core/config.py @@ -4,6 +4,7 @@ import copy import json +import logging import os import platform from importlib.util import find_spec @@ -12,10 +13,15 @@ import yaml from platformdirs import user_config_path +from sed.core.logging import setup_logging + package_dir = os.path.dirname(find_spec("sed").origin) USER_CONFIG_PATH = user_config_path(appname="sed", appauthor="OpenCOMPES", ensure_exists=True) +# Configure logging +logger = setup_logging(__name__) + def parse_config( config: dict | str = None, @@ -57,6 +63,11 @@ def parse_config( Returns: dict: Loaded and possibly completed config dictionary. """ + if verbose: + logger.handlers[0].setLevel(logging.INFO) + else: + logger.handlers[0].setLevel(logging.WARNING) + if config is None: config = {} @@ -64,8 +75,7 @@ def parse_config( config_dict = copy.deepcopy(config) else: config_dict = load_config(config) - if verbose: - print(f"Configuration loaded from: [{str(Path(config).resolve())}]") + logger.info(f"Configuration loaded from: [{str(Path(config).resolve())}]") folder_dict: dict = None if isinstance(folder_config, dict): @@ -75,8 +85,7 @@ def parse_config( folder_config = "./sed_config.yaml" if Path(folder_config).exists(): folder_dict = load_config(folder_config) - if verbose: - print(f"Folder config loaded from: [{str(Path(folder_config).resolve())}]") + logger.info(f"Folder config loaded from: [{str(Path(folder_config).resolve())}]") user_dict: dict = None if isinstance(user_config, dict): @@ -88,8 +97,7 @@ def parse_config( ) if Path(user_config).exists(): user_dict = load_config(user_config) - if verbose: - print(f"User config loaded from: [{str(Path(user_config).resolve())}]") + logger.info(f"User config loaded from: [{str(Path(user_config).resolve())}]") system_dict: dict = None if isinstance(system_config, dict): @@ -106,15 +114,13 @@ def parse_config( ) if Path(system_config).exists(): system_dict = load_config(system_config) - if verbose: - print(f"System config loaded from: [{str(Path(system_config).resolve())}]") + logger.info(f"System config loaded from: [{str(Path(system_config).resolve())}]") if isinstance(default_config, dict): default_dict = copy.deepcopy(default_config) else: default_dict = load_config(default_config) - if verbose: - print(f"Default config loaded from: [{str(Path(default_config).resolve())}]") + logger.info(f"Default config loaded from: [{str(Path(default_config).resolve())}]") if folder_dict is not None: config_dict = complete_dictionary( @@ -154,9 +160,9 @@ def load_config(config_path: str) -> dict: """ config_file = Path(config_path) if not config_file.is_file(): - raise FileNotFoundError( - f"could not find the configuration file: {config_file}", - ) + error_message = f"could not find the configuration file: {config_file}" + logger.error(error_message) + raise FileNotFoundError(error_message) if config_file.suffix == ".json": with open(config_file, encoding="utf-8") as stream: @@ -165,7 +171,9 @@ def load_config(config_path: str) -> dict: with open(config_file, encoding="utf-8") as stream: config_dict = yaml.safe_load(stream) else: - raise TypeError("config file must be of type json or yaml!") + error_message = "config file must be of type json or yaml!" + logger.error(error_message) + raise TypeError(error_message) return config_dict diff --git a/sed/core/processor.py b/sed/core/processor.py index 5644a1b3..3371a37d 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -27,6 +27,7 @@ from sed.core.dfops import add_time_stamped_data from sed.core.dfops import apply_filter from sed.core.dfops import apply_jitter +from sed.core.logging import setup_logging from sed.core.metadata import MetaHandler from sed.diagnostics import grid_histogram from sed.io import to_h5 @@ -39,6 +40,9 @@ N_CPU = psutil.cpu_count() +# Configure logging +logger = setup_logging(__name__) + class SedProcessor: """Processor class of sed. Contains wrapper functions defining a work flow for data @@ -672,7 +676,7 @@ def save_splinewarp( }, } save_config(config, filename, overwrite) - print(f'Saved momentum correction parameters to "{filename}".') + logger.info(f'Saved momentum correction parameters to "{filename}".') # 4. Pose corrections. Provide interactive interface for correcting # scaling, shift and rotation @@ -763,7 +767,7 @@ def save_transformations( }, } save_config(config, filename, overwrite) - print(f'Saved momentum transformation parameters to "{filename}".') + logger.info(f'Saved momentum transformation parameters to "{filename}".') # 5. Apply the momentum correction to the dataframe def apply_momentum_correction( @@ -795,7 +799,7 @@ def apply_momentum_correction( if self._dataframe is not None: if verbose: - print("Adding corrected X/Y columns to dataframe:") + logger.info("Adding corrected X/Y columns to dataframe:") df, metadata = self.mc.apply_corrections( df=self._dataframe, verbose=verbose, @@ -828,10 +832,10 @@ def apply_momentum_correction( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if self.verbose: - print(self._dataframe) + logger.info(self._dataframe) # Momentum calibration work flow # 1. Calculate momentum calibration @@ -916,7 +920,7 @@ def save_momentum_calibration( config = {"momentum": {"calibration": calibration}} save_config(config, filename, overwrite) - print(f"Saved momentum calibration parameters to {filename}") + logger.info(f"Saved momentum calibration parameters to {filename}") # 2. Apply correction and calibration to the dataframe def apply_momentum_calibration( @@ -946,8 +950,7 @@ def apply_momentum_calibration( y_column = self._config["dataframe"]["y_column"] if self._dataframe is not None: - if verbose: - print("Adding kx/ky columns to dataframe:") + logger.info("Adding kx/ky columns to dataframe:") df, metadata = self.mc.append_k_axis( df=self._dataframe, calibration=calibration, @@ -980,10 +983,10 @@ def apply_momentum_calibration( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if self.verbose: - print(self._dataframe) + logger.info(self._dataframe) # Energy correction workflow # 1. Adjust the energy correction parameters @@ -1018,9 +1021,7 @@ def adjust_energy_correction( **kwds: Keyword parameters passed to ``EnergyCalibrator.adjust_energy_correction()``. """ if self._pre_binned is None: - print( - "Pre-binned data not present, binning using defaults from config...", - ) + logger.warn("Pre-binned data not present, binning using defaults from config...") self._pre_binned = self.pre_binning() self.ec.adjust_energy_correction( @@ -1064,7 +1065,7 @@ def save_energy_correction( config = {"energy": {"correction": correction}} save_config(config, filename, overwrite) - print(f"Saved energy correction parameters to {filename}") + logger.info(f"Saved energy correction parameters to {filename}") # 2. Apply energy correction to dataframe def apply_energy_correction( @@ -1094,7 +1095,7 @@ def apply_energy_correction( if self._dataframe is not None: if verbose: - print("Applying energy correction to dataframe...") + logger.info("Applying energy correction to dataframe...") df, metadata = self.ec.apply_energy_correction( df=self._dataframe, correction=correction, @@ -1120,10 +1121,10 @@ def apply_energy_correction( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if verbose: - print(self._dataframe) + logger.info(self._dataframe) # Energy calibrator workflow # 1. Load and normalize data @@ -1266,7 +1267,7 @@ def find_bias_peaks( mode=mode, radius=radius, ) - print(self.ec.featranges) + logger.info(self.ec.featranges) try: self.ec.feature_extract(peak_window=peak_window) self.ec.view( @@ -1419,7 +1420,7 @@ def save_energy_calibration( config = {"energy": {"calibration": calibration}} save_config(config, filename, overwrite) - print(f'Saved energy calibration parameters to "{filename}".') + logger.info(f'Saved energy calibration parameters to "{filename}".') # 4. Apply energy calibration to the dataframe def append_energy_axis( @@ -1455,7 +1456,7 @@ def append_energy_axis( if self._dataframe is not None: if verbose: - print("Adding energy column to dataframe:") + logger.info("Adding energy column to dataframe:") df, metadata = self.ec.append_energy_axis( df=self._dataframe, calibration=calibration, @@ -1485,10 +1486,10 @@ def append_energy_axis( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if verbose: - print(self._dataframe) + logger.info(self._dataframe) def add_energy_offset( self, @@ -1533,7 +1534,7 @@ def add_energy_offset( ) if self.dataframe is not None: if verbose: - print("Adding energy offset to dataframe:") + logger.info("Adding energy offset to dataframe:") df, metadata = self.ec.add_offsets( df=self._dataframe, constant=constant, @@ -1568,9 +1569,9 @@ def add_energy_offset( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) elif verbose: - print(self._dataframe) + logger.info(self._dataframe) def save_energy_offset( self, @@ -1595,7 +1596,7 @@ def save_energy_offset( config = {"energy": {"offsets": self.ec.offsets}} save_config(config, filename, overwrite) - print(f'Saved energy offset parameters to "{filename}".') + logger.info(f'Saved energy offset parameters to "{filename}".') def append_tof_ns_axis( self, @@ -1623,7 +1624,7 @@ def append_tof_ns_axis( if self._dataframe is not None: if verbose: - print("Adding time-of-flight column in nanoseconds to dataframe:") + logger.info("Adding time-of-flight column in nanoseconds to dataframe.") # TODO assert order of execution through metadata df, metadata = self.ec.append_tof_ns_axis( @@ -1647,10 +1648,10 @@ def append_tof_ns_axis( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if verbose: - print(self._dataframe) + logger.info(self._dataframe) def align_dld_sectors( self, @@ -1677,7 +1678,7 @@ def align_dld_sectors( if self._dataframe is not None: if verbose: - print("Aligning 8s sectors of dataframe") + logger.info("Aligning 8s sectors of dataframe") # TODO assert order of execution through metadata df, metadata = self.ec.align_dld_sectors( @@ -1703,10 +1704,10 @@ def align_dld_sectors( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if verbose: - print(self._dataframe) + logger.info(self._dataframe) # Delay calibration function def calibrate_delay_axis( @@ -1740,7 +1741,7 @@ def calibrate_delay_axis( if self._dataframe is not None: if verbose: - print("Adding delay column to dataframe:") + logger.info("Adding delay column to dataframe:") if delay_range is None and datafile is None: if len(self.dc.calibration) == 0: @@ -1779,10 +1780,10 @@ def calibrate_delay_axis( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if self.verbose: - print(self._dataframe) + logger.info(self._dataframe) def save_delay_calibration( self, @@ -1864,7 +1865,7 @@ def add_delay_offset( if self.dataframe is not None: if verbose: - print("Adding delay offset to dataframe:") + logger.info("Adding delay offset to dataframe:") df, metadata = self.dc.add_offsets( df=self._dataframe, constant=constant, @@ -1900,10 +1901,10 @@ def add_delay_offset( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) + logger.info(self._dataframe.head(10)) else: if verbose: - print(self._dataframe) + logger.info(self._dataframe) def save_delay_offsets( self, @@ -1932,7 +1933,7 @@ def save_delay_offsets( }, } save_config(config, filename, overwrite) - print(f'Saved delay offset parameters to "{filename}".') + logger.info(f'Saved delay offset parameters to "{filename}".') def save_workflow_params( self, @@ -2012,6 +2013,7 @@ def add_jitter( metadata.append(col) # TODO: allow only appending if columns are not jittered yet self._attributes.add(metadata, "jittering", duplicate_policy="append") + logger.info(f"add_jitter: Added jitter to columns {cols}.") def add_time_stamped_data( self, @@ -2085,6 +2087,7 @@ def add_time_stamped_data( metadata.append(time_stamps) metadata.append(data) self._attributes.add(metadata, "time_stamped_data", duplicate_policy="append") + logger.info(f"add_time_stamped_data: Added time-stamped data as column {dest_column}.") def pre_binning( self, @@ -2264,9 +2267,7 @@ def compute( if normalize_to_acquisition_time: if isinstance(normalize_to_acquisition_time, str): axis = normalize_to_acquisition_time - print( - f"Calculate normalization histogram for axis '{axis}'...", - ) + logger.info(f"Calculate normalization histogram for axis '{axis}'...") self._normalization_histogram = self.get_normalization_histogram( axis=axis, df_partitions=df_partitions, From f824badc40e1811d2849c623e44c0646041debbc Mon Sep 17 00:00:00 2001 From: rettigl Date: Thu, 18 Jul 2024 23:53:13 +0200 Subject: [PATCH 02/11] fixes for new matplotlib --- sed/calibrator/momentum.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/sed/calibrator/momentum.py b/sed/calibrator/momentum.py index da70c55a..44f1def2 100644 --- a/sed/calibrator/momentum.py +++ b/sed/calibrator/momentum.py @@ -510,8 +510,8 @@ def update_point_pos( features[point_no][0] = point_x features[point_no][1] = point_y - markers[point_no].set_xdata(point_x) - markers[point_no].set_ydata(point_y) + markers[point_no].set_xdata([point_x]) + markers[point_no].set_ydata([point_y]) point_no_input = ipw.Dropdown( options=range(features.shape[0]), @@ -1509,10 +1509,10 @@ def update( k_distance: float, # noqa: ARG001 ): fig.canvas.draw_idle() - marker_a.set_xdata(point_a_x) - marker_a.set_ydata(point_a_y) - marker_b.set_xdata(point_b_x) - marker_b.set_ydata(point_b_y) + marker_a.set_xdata([point_a_x]) + marker_a.set_ydata([point_a_y]) + marker_b.set_xdata([point_b_x]) + marker_b.set_ydata([point_b_y]) point_a_input_x = ipw.IntText(point_a[0]) point_a_input_y = ipw.IntText(point_a[1]) From fbb0af27d304ff879dfc2a58309fb888e1754f22 Mon Sep 17 00:00:00 2001 From: rettigl Date: Sun, 11 Aug 2024 12:48:40 +0200 Subject: [PATCH 03/11] use base sed logger add call_logger to capture function calls in processor --- sed/core/config.py | 23 +++++++------ sed/core/logging.py | 75 ++++++++++++++++++++++++++++++------------ sed/core/processor.py | 31 ++++++++++++++++- sed/dataset/dataset.py | 5 +-- 4 files changed, 98 insertions(+), 36 deletions(-) diff --git a/sed/core/config.py b/sed/core/config.py index 8de69c1f..22e60fe5 100644 --- a/sed/core/config.py +++ b/sed/core/config.py @@ -4,7 +4,6 @@ import copy import json -import logging import os import platform from importlib.util import find_spec @@ -20,7 +19,7 @@ USER_CONFIG_PATH = user_config_path(appname="sed", appauthor="OpenCOMPES", ensure_exists=True) # Configure logging -logger = setup_logging(__name__) +logger = setup_logging("config") def parse_config( @@ -63,11 +62,6 @@ def parse_config( Returns: dict: Loaded and possibly completed config dictionary. """ - if verbose: - logger.handlers[0].setLevel(logging.INFO) - else: - logger.handlers[0].setLevel(logging.WARNING) - if config is None: config = {} @@ -75,7 +69,8 @@ def parse_config( config_dict = copy.deepcopy(config) else: config_dict = load_config(config) - logger.info(f"Configuration loaded from: [{str(Path(config).resolve())}]") + if verbose: + logger.info(f"Configuration loaded from: [{str(Path(config).resolve())}]") folder_dict: dict = None if isinstance(folder_config, dict): @@ -85,7 +80,8 @@ def parse_config( folder_config = "./sed_config.yaml" if Path(folder_config).exists(): folder_dict = load_config(folder_config) - logger.info(f"Folder config loaded from: [{str(Path(folder_config).resolve())}]") + if verbose: + logger.info(f"Folder config loaded from: [{str(Path(folder_config).resolve())}]") user_dict: dict = None if isinstance(user_config, dict): @@ -97,7 +93,8 @@ def parse_config( ) if Path(user_config).exists(): user_dict = load_config(user_config) - logger.info(f"User config loaded from: [{str(Path(user_config).resolve())}]") + if verbose: + logger.info(f"User config loaded from: [{str(Path(user_config).resolve())}]") system_dict: dict = None if isinstance(system_config, dict): @@ -114,13 +111,15 @@ def parse_config( ) if Path(system_config).exists(): system_dict = load_config(system_config) - logger.info(f"System config loaded from: [{str(Path(system_config).resolve())}]") + if verbose: + logger.info(f"System config loaded from: [{str(Path(system_config).resolve())}]") if isinstance(default_config, dict): default_dict = copy.deepcopy(default_config) else: default_dict = load_config(default_config) - logger.info(f"Default config loaded from: [{str(Path(default_config).resolve())}]") + if verbose: + logger.info(f"Default config loaded from: [{str(Path(default_config).resolve())}]") if folder_dict is not None: config_dict = complete_dictionary( diff --git a/sed/core/logging.py b/sed/core/logging.py index 8c4742a7..539f29b6 100644 --- a/sed/core/logging.py +++ b/sed/core/logging.py @@ -10,6 +10,8 @@ import os import sys from datetime import datetime +from functools import wraps +from typing import Callable # Default log directory DEFAULT_LOG_DIR = os.path.join(os.getcwd(), "logs") @@ -19,14 +21,17 @@ def setup_logging( name: str, - user_log_path: str = DEFAULT_LOG_DIR, + set_base_handler: bool = False, + user_log_path: str | None = None, ) -> logging.Logger: """ Configures and returns a logger with specified log levels for console and file handlers. Args: name (str): The name of the logger. - user_log_path (str): Path to the user-specific log directory. Defaults to DEFAULT_LOG_DIR. + base_name (str, optional): The name of the base logger. Defaults to "sed". + user_log_path (str, optional): Path to the user-specific log directory. + Defaults to DEFAULT_LOG_DIR. Returns: logging.Logger: The configured logger instance. @@ -34,11 +39,37 @@ def setup_logging( The logger will always write DEBUG level messages to a file located in the user's log directory, while the console log level can be adjusted based on the 'verbosity' parameter. """ - # Create logger - logger = logging.getLogger(name) + # Create base logger + base_logger = logging.getLogger("sed") + base_logger.setLevel(logging.DEBUG) # Set the minimum log level for the logger + if set_base_handler or not base_logger.hasHandlers(): + if base_logger.hasHandlers(): + base_logger.handlers.clear() + + # Determine log file path + if user_log_path is None: + user_log_path = DEFAULT_LOG_DIR + os.makedirs(user_log_path, exist_ok=True) + log_file = os.path.join(user_log_path, f"sed_{datetime.now().strftime('%Y-%m-%d')}.log") + + # Create file handler and set level to debug + file_handler = logging.FileHandler(log_file) + file_handler.setLevel(FILE_VERBOSITY) + + # Create formatter for file + file_formatter = logging.Formatter( + "%(asctime)s - %(name)s - %(levelname)s - %(message)s in %(filename)s:%(lineno)d", + ) + file_handler.setFormatter(file_formatter) + + # Add file handler to logger + base_logger.addHandler(file_handler) + + # create named logger + logger = base_logger.getChild(name) + if logger.hasHandlers(): logger.handlers.clear() - logger.setLevel(logging.INFO) # Set the minimum log level for the logger # Create console handler and set level console_handler = logging.StreamHandler(sys.stdout) @@ -51,24 +82,26 @@ def setup_logging( # Add console handler to logger logger.addHandler(console_handler) - # Determine log file path - os.makedirs(user_log_path, exist_ok=True) - log_file = os.path.join(user_log_path, f"sed_{datetime.now().strftime('%Y-%m-%d')}.log") + # Capture warnings with the logging system + logging.captureWarnings(True) - # Create file handler and set level to debug - file_handler = logging.FileHandler(log_file) - file_handler.setLevel(FILE_VERBOSITY) + return logger - # Create formatter for file - file_formatter = logging.Formatter( - "%(asctime)s - %(name)s - %(levelname)s - %(message)s in %(filename)s:%(lineno)d", - ) - file_handler.setFormatter(file_formatter) - # Add file handler to logger - logger.addHandler(file_handler) +def call_logger(logger: logging.Logger): + def log_call(func: Callable): + @wraps(func) + def new_func(*args, **kwargs): + saved_args = locals() + args_str = "" + for arg in saved_args["args"][1:]: + args_str += f"{arg}, " + for name, arg in saved_args["kwargs"].items(): + args_str += f"{name}={arg}, " + args_str = args_str.rstrip(", ") + logger.debug(f"Call {func.__name__}({args_str})") + return func(*args, **kwargs) - # Capture warnings with the logging system - logging.captureWarnings(True) + return new_func - return logger + return log_call diff --git a/sed/core/processor.py b/sed/core/processor.py index 3371a37d..29f52851 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -27,6 +27,7 @@ from sed.core.dfops import add_time_stamped_data from sed.core.dfops import apply_filter from sed.core.dfops import apply_jitter +from sed.core.logging import call_logger from sed.core.logging import setup_logging from sed.core.metadata import MetaHandler from sed.diagnostics import grid_histogram @@ -41,7 +42,7 @@ N_CPU = psutil.cpu_count() # Configure logging -logger = setup_logging(__name__) +logger = setup_logging("processor") class SedProcessor: @@ -67,6 +68,7 @@ class SedProcessor: **kwds: Keyword arguments passed to the reader. """ + @call_logger(logger) def __init__( self, metadata: dict = None, @@ -368,6 +370,7 @@ def cpy(self, path: str | list[str]) -> str | list[str]: return path + @call_logger(logger) def load( self, dataframe: pd.DataFrame | ddf.DataFrame = None, @@ -454,6 +457,7 @@ def load( duplicate_policy="merge", ) + @call_logger(logger) def filter_column( self, column: str, @@ -496,6 +500,7 @@ def filter_column( # Momentum calibration workflow # 1. Bin raw detector data for distortion correction + @call_logger(logger) def bin_and_load_momentum_calibration( self, df_partitions: int | Sequence[int] = 100, @@ -539,6 +544,7 @@ def bin_and_load_momentum_calibration( # 2. Generate the spline warp correction from momentum features. # Either autoselect features, or input features from view above. + @call_logger(logger) def define_features( self, features: np.ndarray = None, @@ -592,6 +598,7 @@ def define_features( # 3. Generate the spline warp correction from momentum features. # If no features have been selected before, use class defaults. + @call_logger(logger) def generate_splinewarp( self, use_center: bool = None, @@ -680,6 +687,7 @@ def save_splinewarp( # 4. Pose corrections. Provide interactive interface for correcting # scaling, shift and rotation + @call_logger(logger) def pose_adjustment( self, transformations: dict[str, Any] = None, @@ -737,6 +745,7 @@ def pose_adjustment( ) # 4a. Save pose adjustment parameters to config file. + @call_logger(logger) def save_transformations( self, filename: str = None, @@ -770,6 +779,7 @@ def save_transformations( logger.info(f'Saved momentum transformation parameters to "{filename}".') # 5. Apply the momentum correction to the dataframe + @call_logger(logger) def apply_momentum_correction( self, preview: bool = False, @@ -839,6 +849,7 @@ def apply_momentum_correction( # Momentum calibration work flow # 1. Calculate momentum calibration + @call_logger(logger) def calibrate_momentum_axes( self, point_a: np.ndarray | list[int] = None, @@ -923,6 +934,7 @@ def save_momentum_calibration( logger.info(f"Saved momentum calibration parameters to {filename}") # 2. Apply correction and calibration to the dataframe + @call_logger(logger) def apply_momentum_calibration( self, calibration: dict = None, @@ -990,6 +1002,7 @@ def apply_momentum_calibration( # Energy correction workflow # 1. Adjust the energy correction parameters + @call_logger(logger) def adjust_energy_correction( self, correction_type: str = None, @@ -1068,6 +1081,7 @@ def save_energy_correction( logger.info(f"Saved energy correction parameters to {filename}") # 2. Apply energy correction to dataframe + @call_logger(logger) def apply_energy_correction( self, correction: dict = None, @@ -1128,6 +1142,7 @@ def apply_energy_correction( # Energy calibrator workflow # 1. Load and normalize data + @call_logger(logger) def load_bias_series( self, binned_data: xr.DataArray | tuple[np.ndarray, np.ndarray, np.ndarray] = None, @@ -1221,6 +1236,7 @@ def load_bias_series( ) # 2. extract ranges and get peak positions + @call_logger(logger) def find_bias_peaks( self, ranges: list[tuple] | tuple, @@ -1294,6 +1310,7 @@ def find_bias_peaks( ) # 3. Fit the energy calibration relation + @call_logger(logger) def calibrate_energy_axis( self, ref_energy: float, @@ -1423,6 +1440,7 @@ def save_energy_calibration( logger.info(f'Saved energy calibration parameters to "{filename}".') # 4. Apply energy calibration to the dataframe + @call_logger(logger) def append_energy_axis( self, calibration: dict = None, @@ -1491,6 +1509,7 @@ def append_energy_axis( if verbose: logger.info(self._dataframe) + @call_logger(logger) def add_energy_offset( self, constant: float = None, @@ -1598,6 +1617,7 @@ def save_energy_offset( save_config(config, filename, overwrite) logger.info(f'Saved energy offset parameters to "{filename}".') + @call_logger(logger) def append_tof_ns_axis( self, preview: bool = False, @@ -1653,6 +1673,7 @@ def append_tof_ns_axis( if verbose: logger.info(self._dataframe) + @call_logger(logger) def align_dld_sectors( self, sector_delays: np.ndarray = None, @@ -1710,6 +1731,7 @@ def align_dld_sectors( logger.info(self._dataframe) # Delay calibration function + @call_logger(logger) def calibrate_delay_axis( self, delay_range: tuple[float, float] = None, @@ -1822,6 +1844,7 @@ def save_delay_calibration( } save_config(config, filename, overwrite) + @call_logger(logger) def add_delay_offset( self, constant: float = None, @@ -1963,6 +1986,7 @@ def save_workflow_params( except (ValueError, AttributeError, KeyError): pass + @call_logger(logger) def add_jitter( self, cols: list[str] = None, @@ -2015,6 +2039,7 @@ def add_jitter( self._attributes.add(metadata, "jittering", duplicate_policy="append") logger.info(f"add_jitter: Added jitter to columns {cols}.") + @call_logger(logger) def add_time_stamped_data( self, dest_column: str, @@ -2089,6 +2114,7 @@ def add_time_stamped_data( self._attributes.add(metadata, "time_stamped_data", duplicate_policy="append") logger.info(f"add_time_stamped_data: Added time-stamped data as column {dest_column}.") + @call_logger(logger) def pre_binning( self, df_partitions: int | Sequence[int] = 100, @@ -2136,6 +2162,7 @@ def pre_binning( **kwds, ) + @call_logger(logger) def compute( self, bins: int | dict | tuple | list[int] | list[np.ndarray] | list[tuple] = 100, @@ -2299,6 +2326,7 @@ def compute( return self._binned + @call_logger(logger) def get_normalization_histogram( self, axis: str = "delay", @@ -2463,6 +2491,7 @@ def view_event_histogram( **kwds, ) + @call_logger(logger) def save( self, faddr: str, diff --git a/sed/dataset/dataset.py b/sed/dataset/dataset.py index 9fb4a3d3..15bf8b4f 100644 --- a/sed/dataset/dataset.py +++ b/sed/dataset/dataset.py @@ -22,7 +22,7 @@ # Configure logging -logger = setup_logging(__name__) +logger = setup_logging("dataset") class DatasetsManager: @@ -51,7 +51,8 @@ def load_datasets_dict() -> dict: return parse_config( folder_config=DatasetsManager.json_path["folder"], - system_config=DatasetsManager.json_path["user"], + user_config=DatasetsManager.json_path["user"], + system_config={}, default_config=DatasetsManager.json_path["module"], verbose=False, ) From 469236d01ad281abfebf3d23c099361aef8c22a4 Mon Sep 17 00:00:00 2001 From: rettigl Date: Sun, 11 Aug 2024 13:03:35 +0200 Subject: [PATCH 04/11] add logging to mpes loader --- sed/loader/mpes/loader.py | 68 +++++++++++++++------------ tests/loader/mpes/test_mpes_loader.py | 23 +++++---- 2 files changed, 51 insertions(+), 40 deletions(-) diff --git a/sed/loader/mpes/loader.py b/sed/loader/mpes/loader.py index ea5ea7fc..42339ebf 100644 --- a/sed/loader/mpes/loader.py +++ b/sed/loader/mpes/loader.py @@ -23,8 +23,12 @@ import scipy.interpolate as sint from natsort import natsorted +from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader +# Configure logging +logger = setup_logging("mpes_loader") + def hdf5_to_dataframe( files: Sequence[str], @@ -74,17 +78,19 @@ def hdf5_to_dataframe( electron_channels.append(channel) column_names.append(name) else: - print( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found.", + logger.warning( + f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found. " "Skipping the channel.", ) elif channel["format"] != "per_file": - raise ValueError( - f"Invalid 'format':{channel['format']} for channel {name}.", - ) + error_msg = f"Invalid 'format':{channel['format']} for channel {name}." + logger.error(error_msg) + raise ValueError(error_msg) if not electron_channels: - raise ValueError("No valid 'per_electron' channels found.") + error_msg = "No valid 'per_electron' channels found." + logger.error(error_msg) + raise ValueError(error_msg) if time_stamps: column_names.append(time_stamp_alias) @@ -127,8 +133,8 @@ def hdf5_to_dataframe( dataframe = ddf.from_delayed(delayeds) else: - print( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found.", + logger.warning( + f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found. " "Skipping the channel.", ) @@ -184,17 +190,19 @@ def hdf5_to_timed_dataframe( electron_channels.append(channel) column_names.append(name) else: - print( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found.", + logger.warning( + f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found. " "Skipping the channel.", ) elif channel["format"] != "per_file": - raise ValueError( - f"Invalid 'format':{channel['format']} for channel {name}.", - ) + error_msg = f"Invalid 'format':{channel['format']} for channel {name}." + logger.error(error_msg) + raise ValueError(error_msg) if not electron_channels: - raise ValueError("No valid 'per_electron' channels found.") + error_msg = "No valid 'per_electron' channels found." + logger.error(error_msg) + raise ValueError(error_msg) if time_stamps: column_names.append(time_stamp_alias) @@ -237,8 +245,8 @@ def hdf5_to_timed_dataframe( dataframe = ddf.from_delayed(delayeds) else: - print( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found.", + logger.warning( + f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found. " "Skipping the channel.", ) @@ -799,9 +807,9 @@ def gather_metadata( if metadata is None: metadata = {} - print("Gathering metadata from different locations") + logger.info("Gathering metadata from different locations") # Read events in with ms time stamps - print("Collecting time stamps...") + logger.info("Collecting time stamps...") (ts_from, ts_to) = self.get_start_and_end_time() metadata["timing"] = { @@ -819,7 +827,7 @@ def gather_metadata( if "file" not in metadata: # If already present, the value is assumed to be a dictionary metadata["file"] = {} - print("Collecting file metadata...") + logger.info("Collecting file metadata...") with h5py.File(files[0], "r") as h5file: for key, value in h5file.attrs.items(): key = key.replace("VSet", "V") @@ -829,7 +837,7 @@ def gather_metadata( os.path.realpath(files[0]), ) - print("Collecting data from the EPICS archive...") + logger.info("Collecting data from the EPICS archive...") # Get metadata from Epics archive if not present already epics_channels = self._config["metadata"]["epics_pvs"] @@ -850,23 +858,23 @@ def gather_metadata( except IndexError: metadata["file"][f"{channel}"] = np.nan - print( + logger.info( f"Data for channel {channel} doesn't exist for time {start}", ) except HTTPError as exc: - print( + logger.warning( f"Incorrect URL for the archive channel {channel}. " "Make sure that the channel name and file start and end times are " "correct.", ) - print("Error code: ", exc) + logger.warning(f"Error code: {exc}") except URLError as exc: - print( + logger.warning( f"Cannot access the archive URL for channel {channel}. " f"Make sure that you are within the FHI network." f"Skipping over channels {channels_missing}.", ) - print("Error code: ", exc) + logger.warning(f"Error code: {exc}") break # Determine the correct aperture_config @@ -901,7 +909,7 @@ def gather_metadata( metadata["instrument"]["analyzer"]["fa_shape"] = key break else: - print("Field aperture size not found.") + logger.warning("Field aperture size not found.") # get contrast aperture shape and size if self._config["metadata"]["ca_in_channel"] in metadata["file"]: @@ -917,7 +925,7 @@ def gather_metadata( metadata["instrument"]["analyzer"]["ca_shape"] = key break else: - print("Contrast aperture size not found.") + logger.warning("Contrast aperture size not found.") # Storing the lens modes corresponding to lens voltages. # Use lens voltages present in first lens_mode entry. @@ -938,7 +946,7 @@ def gather_metadata( metadata["instrument"]["analyzer"]["lens_mode"] = mode break else: - print( + logger.warning( "Lens mode for given lens voltages not found. " "Storing lens mode from the user, if provided.", ) @@ -953,13 +961,13 @@ def gather_metadata( metadata["instrument"]["analyzer"]["projection"] = "reciprocal" metadata["instrument"]["analyzer"]["scheme"] = "spatial dispersive" except IndexError: - print( + logger.warning( "Lens mode must have the form, '6kV_kmodem4.0_20VTOF_v3.sav'. " "Can't determine projection. " "Storing projection from the user, if provided.", ) except KeyError: - print( + logger.warning( "Lens mode not found. Can't determine projection. " "Storing projection from the user, if provided.", ) diff --git a/tests/loader/mpes/test_mpes_loader.py b/tests/loader/mpes/test_mpes_loader.py index 9d4513a0..936efe44 100644 --- a/tests/loader/mpes/test_mpes_loader.py +++ b/tests/loader/mpes/test_mpes_loader.py @@ -1,6 +1,7 @@ """Tests specific for Mpes loader""" from __future__ import annotations +import logging import os from copy import deepcopy from importlib.util import find_spec @@ -22,31 +23,33 @@ ) -def test_channel_not_found_warning(capsys) -> None: +def test_channel_not_found_warning(caplog) -> None: """Test if the mpes loader gives the correct warning if a channel cannot be found.""" ml = MpesLoader(config=config) - ml.read_dataframe(folders=test_data_dir) - captured = capsys.readouterr() - assert captured.out == "" + with caplog.at_level(logging.WARNING): + ml.read_dataframe(folders=test_data_dir) + assert not caplog.messages # modify per_file channel config_ = deepcopy(config) config_["dataframe"]["channels"]["sampleBias"]["dataset_key"] = "invalid" ml = MpesLoader(config=config_) - ml.read_dataframe(folders=test_data_dir) - captured = capsys.readouterr() - assert 'Entry "invalid" for channel "sampleBias" not found.' in captured.out + caplog.clear() + with caplog.at_level(logging.WARNING): + ml.read_dataframe(folders=test_data_dir) + assert 'Entry "invalid" for channel "sampleBias" not found.' in caplog.messages[0] # modify per_electron channel config_ = deepcopy(config) config_["dataframe"]["channels"]["X"]["dataset_key"] = "invalid" ml = MpesLoader(config=config_) - ml.read_dataframe(folders=test_data_dir) - captured = capsys.readouterr() - assert 'Entry "invalid" for channel "X" not found.' in captured.out + caplog.clear() + with caplog.at_level(logging.WARNING): + ml.read_dataframe(folders=test_data_dir) + assert 'Entry "invalid" for channel "X" not found.' in caplog.messages[0] def test_invalid_channel_format_raises() -> None: From 37feca19afbb12426f037af0737f90ac793c91cd Mon Sep 17 00:00:00 2001 From: rettigl Date: Mon, 12 Aug 2024 21:02:55 +0200 Subject: [PATCH 05/11] add verbosity to loader interface --- sed/loader/base/loader.py | 7 ++++--- sed/loader/flash/loader.py | 22 ++++++++++++++++++++-- sed/loader/generic/loader.py | 3 ++- sed/loader/loader_interface.py | 4 +++- sed/loader/mpes/loader.py | 13 +++++++++++-- sed/loader/sxp/loader.py | 20 ++++++++++++++++++-- 6 files changed, 58 insertions(+), 11 deletions(-) diff --git a/sed/loader/base/loader.py b/sed/loader/base/loader.py index 4a9962d3..0f898e09 100644 --- a/sed/loader/base/loader.py +++ b/sed/loader/base/loader.py @@ -24,11 +24,10 @@ class BaseLoader(ABC): Args: config (dict, optional): Config dictionary. Defaults to None. - meta_handler (MetaHandler, optional): MetaHandler object. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ - # pylint: disable=too-few-public-methods - __name__ = "BaseLoader" supported_file_types: list[str] = [] @@ -36,12 +35,14 @@ class BaseLoader(ABC): def __init__( self, config: dict = None, + verbose: bool = True, ): self._config = config if config is not None else {} self.files: list[str] = [] self.runs: list[str] = [] self.metadata: dict[Any, Any] = {} + self.verbose = verbose @abstractmethod def read_dataframe( diff --git a/sed/loader/flash/loader.py b/sed/loader/flash/loader.py index 1e9752eb..b44b3b82 100644 --- a/sed/loader/flash/loader.py +++ b/sed/loader/flash/loader.py @@ -12,36 +12,54 @@ import re import time from collections.abc import Sequence +from logging import INFO +from logging import WARNING from pathlib import Path import dask.dataframe as dd from natsort import natsorted +from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader from sed.loader.flash.buffer_handler import BufferHandler from sed.loader.flash.instruments import wespe_convert from sed.loader.flash.metadata import MetadataRetriever +# Configure logging +logger = setup_logging("flash_loader") + class FlashLoader(BaseLoader): """ The class generates multiindexed multidimensional pandas dataframes from the new FLASH dataformat resolved by both macro and microbunches alongside electrons. Only the read_dataframe (inherited and implemented) method is accessed by other modules. + + Args: + config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ __name__ = "flash" supported_file_types = ["h5"] - def __init__(self, config: dict) -> None: + def __init__(self, config: dict, verbose: bool = True) -> None: """ Initializes the FlashLoader. Args: config (dict): Configuration dictionary. + verbose (bool, optional): Option to print out diagnostic information. """ - super().__init__(config=config) + super().__init__(config=config, verbose=verbose) + + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) + self.instrument: str = self._config["core"].get("instrument", "hextof") # default is hextof self.raw_dir: str = None self.processed_dir: str = None diff --git a/sed/loader/generic/loader.py b/sed/loader/generic/loader.py index 0444af0f..a7112a3e 100644 --- a/sed/loader/generic/loader.py +++ b/sed/loader/generic/loader.py @@ -19,7 +19,8 @@ class GenericLoader(BaseLoader): Args: config (dict, optional): Config dictionary. Defaults to None. - meta_handler (MetaHandler, optional): MetaHandler object. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ __name__ = "generic" diff --git a/sed/loader/loader_interface.py b/sed/loader/loader_interface.py index 6a636861..51d7d0e0 100644 --- a/sed/loader/loader_interface.py +++ b/sed/loader/loader_interface.py @@ -12,12 +12,14 @@ def get_loader( loader_name: str, config: dict = None, + verbose: bool = True, ) -> BaseLoader: """Helper function to get the loader object from it's given name. Args: loader_name (str): Name of the loader config (dict, optional): Configuration dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. Raises: ValueError: Raised if the loader cannot be found. @@ -41,7 +43,7 @@ def get_loader( spec = importlib.util.spec_from_file_location("loader.py", path) module = importlib.util.module_from_spec(spec) spec.loader.exec_module(module) - return module.LOADER(config=config) + return module.LOADER(config=config, verbose=verbose) def get_names_of_all_loaders() -> list[str]: diff --git a/sed/loader/mpes/loader.py b/sed/loader/mpes/loader.py index 42339ebf..22df8a0a 100644 --- a/sed/loader/mpes/loader.py +++ b/sed/loader/mpes/loader.py @@ -10,6 +10,8 @@ import json import os from collections.abc import Sequence +from logging import INFO +from logging import WARNING from typing import Any from urllib.error import HTTPError from urllib.error import URLError @@ -565,7 +567,8 @@ class MpesLoader(BaseLoader): Args: config (dict, optional): Config dictionary. Defaults to None. - meta_handler (MetaHandler, optional): MetaHandler object. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ __name__ = "mpes" @@ -575,8 +578,14 @@ class MpesLoader(BaseLoader): def __init__( self, config: dict = None, + verbose: bool = True, ): - super().__init__(config=config) + super().__init__(config=config, verbose=verbose) + + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) self.read_timestamps = self._config.get("dataframe", {}).get( "read_timestamps", diff --git a/sed/loader/sxp/loader.py b/sed/loader/sxp/loader.py index 10213594..e18a64f9 100644 --- a/sed/loader/sxp/loader.py +++ b/sed/loader/sxp/loader.py @@ -14,6 +14,8 @@ import time from collections.abc import Sequence from functools import reduce +from logging import INFO +from logging import WARNING from pathlib import Path import dask.dataframe as dd @@ -28,24 +30,38 @@ from pandas import Series from sed.core import dfops +from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader from sed.loader.utils import parse_h5_keys from sed.loader.utils import split_dld_time_from_sector_id +# Configure logging +logger = setup_logging("sxp_loader") + class SXPLoader(BaseLoader): """ The class generates multiindexed multidimensional pandas dataframes from the new SXP dataformat resolved by both macro and microbunches alongside electrons. Only the read_dataframe (inherited and implemented) method is accessed by other modules. + + Args: + config (dict): Config dictionary. + verbose (bool, optional): Option to print out diagnostic information. """ __name__ = "sxp" supported_file_types = ["h5"] - def __init__(self, config: dict) -> None: - super().__init__(config=config) + def __init__(self, config: dict, verbose: bool = True) -> None: + super().__init__(config=config, verbose=verbose) + + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) + self.multi_index = ["trainId", "pulseId", "electronId"] self.index_per_electron: MultiIndex = None self.index_per_pulse: MultiIndex = None From 2fbae5d7c6d20bc83f6b6e6d180b0cc5ac92d61c Mon Sep 17 00:00:00 2001 From: rettigl Date: Mon, 12 Aug 2024 21:07:35 +0200 Subject: [PATCH 06/11] add logging to delay calibrator --- sed/calibrator/delay.py | 63 +++++++++++++++++++++++++---------------- sed/core/processor.py | 42 ++++++++++++++++----------- 2 files changed, 64 insertions(+), 41 deletions(-) diff --git a/sed/calibrator/delay.py b/sed/calibrator/delay.py index 666acbb7..d259bb60 100644 --- a/sed/calibrator/delay.py +++ b/sed/calibrator/delay.py @@ -5,6 +5,8 @@ from collections.abc import Sequence from copy import deepcopy from datetime import datetime +from logging import INFO +from logging import WARNING from typing import Any import dask.dataframe @@ -13,6 +15,10 @@ import pandas as pd from sed.core import dfops +from sed.core.logging import setup_logging + +# Configure logging +logger = setup_logging("delay") class DelayCalibrator: @@ -22,22 +28,33 @@ class DelayCalibrator: Args: config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ def __init__( self, config: dict = None, + verbose: bool = True, ) -> None: """Initialization of the DelayCalibrator class passes the config. Args: config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ if config is not None: self._config = config else: self._config = {} + self.verbose = verbose + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) + self.adc_column: str = self._config["dataframe"].get("adc_column", None) self.delay_column: str = self._config["dataframe"]["delay_column"] self.corrected_delay_column = self._config["dataframe"].get( @@ -61,7 +78,7 @@ def append_delay_axis( p1_key: str = None, p2_key: str = None, t0_key: str = None, - verbose: bool = True, + suppress_output: bool = False, ) -> tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: """Calculate and append the delay axis to the events dataframe, by converting values from an analog-digital-converter (ADC). @@ -92,8 +109,7 @@ def append_delay_axis( Defaults to config["delay"]["p2_key"] t0_key (str, optional): hdf5 key for t0 value (mm). Defaults to config["delay"]["t0_key"] - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. + suppress_output (bool, optional): Option to suppress log output. Defaults to False. Raises: ValueError: Raised if delay parameters are not found in the file. @@ -126,11 +142,11 @@ def append_delay_axis( calibration["delay_range_mm"] = delay_range_mm else: # report usage of loaded parameters - if "creation_date" in calibration and verbose: + if "creation_date" in calibration and not suppress_output: datestring = datetime.fromtimestamp(calibration["creation_date"]).strftime( "%m/%d/%Y, %H:%M:%S", ) - print(f"Using delay calibration parameters generated on {datestring}") + logger.info(f"Using delay calibration parameters generated on {datestring}") if adc_column is None: adc_column = self.adc_column @@ -166,8 +182,8 @@ def append_delay_axis( calibration["datafile"] = datafile calibration["delay_range_mm"] = (ret[0], ret[1]) calibration["time0"] = ret[2] - if verbose: - print(f"Extract delay range from file '{datafile}'.") + if not suppress_output: + logger.info(f"Extract delay range from file '{datafile}'.") else: raise NotImplementedError( "Not enough parameters for delay calibration.", @@ -179,8 +195,8 @@ def append_delay_axis( calibration["time0"], ), ) - if verbose: - print(f"Converted delay_range (ps) = {calibration['delay_range']}") + if not suppress_output: + logger.info(f"Converted delay_range (ps) = {calibration['delay_range']}") calibration["creation_date"] = datetime.now().timestamp() if "delay_range" in calibration.keys(): @@ -190,8 +206,8 @@ def append_delay_axis( calibration["adc_range"][1] - calibration["adc_range"][0] ) self.calibration = deepcopy(calibration) - if verbose: - print( + if not suppress_output: + logger.info( "Append delay axis using delay_range = " f"[{calibration['delay_range'][0]}, {calibration['delay_range'][1]}]" " and adc_range = " @@ -214,7 +230,7 @@ def add_offsets( preserve_mean: bool | Sequence[bool] = False, reductions: str | Sequence[str] = None, delay_column: str = None, - verbose: bool = True, + suppress_output: bool = False, ) -> tuple[dask.dataframe.DataFrame, dict]: """Apply an offset to the delay column based on a constant or other columns. @@ -234,8 +250,7 @@ def add_offsets( If None, the shift is applied per-dataframe-row. Defaults to None. Currently only "mean" is supported. delay_column (str, optional): Name of the column containing the delay values. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. + suppress_output (bool, optional): Option to suppress log output. Defaults to False. Returns: tuple[dask.dataframe.DataFrame, dict]: Dataframe with the shifted delay axis and @@ -299,11 +314,11 @@ def add_offsets( if flip_delay_axis: offsets["flip_delay_axis"] = flip_delay_axis - elif "creation_date" in offsets and verbose: + elif "creation_date" in offsets and not suppress_output: datestring = datetime.fromtimestamp(offsets["creation_date"]).strftime( "%m/%d/%Y, %H:%M:%S", ) - print(f"Using delay offset parameters generated on {datestring}") + logger.info(f"Using delay offset parameters generated on {datestring}") if len(offsets) > 0: # unpack dictionary @@ -311,14 +326,14 @@ def add_offsets( weights = [] preserve_mean = [] reductions = [] - if verbose: - print("Delay offset parameters:") + if not suppress_output: + logger.info("Delay offset parameters:") for k, v in offsets.items(): if k == "creation_date": continue if k == "constant": constant = v - if verbose: + if not suppress_output: print(f" Constant: {constant} ") elif k == "flip_delay_axis": fda = str(v) @@ -330,8 +345,8 @@ def add_offsets( raise ValueError( f"Invalid value for flip_delay_axis in config: {flip_delay_axis}.", ) - if verbose: - print(f" Flip delay axis: {flip_delay_axis} ") + if not suppress_output: + logger.info(f" Flip delay axis: {flip_delay_axis} ") else: columns.append(k) try: @@ -343,9 +358,9 @@ def add_offsets( preserve_mean.append(pm) red = v.get("reduction", None) reductions.append(red) - if verbose: - print( - f" Column[{k}]: Weight={weight}, Preserve Mean: {pm}, ", + if not suppress_output: + logger.info( + f" Column[{k}]: Weight={weight}, Preserve Mean: {pm}, " f"Reductions: {red}.", ) diff --git a/sed/core/processor.py b/sed/core/processor.py index 29f52851..6af1cd06 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -6,6 +6,8 @@ import pathlib from collections.abc import Sequence from datetime import datetime +from logging import INFO +from logging import WARNING from typing import Any from typing import cast @@ -64,7 +66,7 @@ class SedProcessor: collect_metadata (bool): Option to collect metadata from files. Defaults to False. verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"] or False. + Defaults to config["core"]["verbose"] or True. **kwds: Keyword arguments passed to the reader. """ @@ -99,7 +101,7 @@ def __init__( collect_metadata (bool, optional): Option to collect metadata from files. Defaults to False. verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"] or False. + Defaults to config["core"]["verbose"] or True. **kwds: Keyword arguments passed to parse_config and to the reader. """ # split off config keywords @@ -113,11 +115,16 @@ def __init__( if num_cores >= N_CPU: num_cores = N_CPU - 1 self._config["core"]["num_cores"] = num_cores + logger.debug(f"Use {num_cores} cores for processing.") if verbose is None: - self.verbose = self._config["core"].get("verbose", False) + self.verbose = self._config["core"].get("verbose", True) else: self.verbose = verbose + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) self._dataframe: pd.DataFrame | ddf.DataFrame = None self._timed_dataframe: pd.DataFrame | ddf.DataFrame = None @@ -134,22 +141,28 @@ def __init__( self.loader = get_loader( loader_name=loader_name, config=self._config, + verbose=verbose, ) + logger.debug(f"Use loader: {loader_name}") self.ec = EnergyCalibrator( loader=get_loader( loader_name=loader_name, config=self._config, + verbose=verbose, ), config=self._config, + verbose=self.verbose, ) self.mc = MomentumCorrector( config=self._config, + verbose=self.verbose, ) self.dc = DelayCalibrator( config=self._config, + verbose=self.verbose, ) self.use_copy_tool = self._config.get("core", {}).get( @@ -164,6 +177,11 @@ def __init__( num_cores=self._config["core"]["num_cores"], **self._config["core"].get("copy_tool_kwds", {}), ) + logger.debug( + f"Initialized copy tool: Copy file from " + f"'{self._config['core']['copy_tool_source']}' " + f"to '{self._config['core']['copy_tool_dest']}'.", + ) except KeyError: self.use_copy_tool = False @@ -1737,7 +1755,6 @@ def calibrate_delay_axis( delay_range: tuple[float, float] = None, datafile: str = None, preview: bool = False, - verbose: bool = None, **kwds, ): """Append delay column to dataframe. Either provide delay ranges, or read @@ -1750,20 +1767,14 @@ def calibrate_delay_axis( Defaults to None. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword args passed to ``DelayCalibrator.append_delay_axis``. """ - if verbose is None: - verbose = self.verbose - adc_column = self._config["dataframe"]["adc_column"] if adc_column not in self._dataframe.columns: raise ValueError(f"ADC column {adc_column} not found in dataframe, cannot calibrate!") if self._dataframe is not None: - if verbose: - logger.info("Adding delay column to dataframe:") + logger.info("Adding delay column to dataframe:") if delay_range is None and datafile is None: if len(self.dc.calibration) == 0: @@ -1778,7 +1789,6 @@ def calibrate_delay_axis( self._dataframe, delay_range=delay_range, datafile=datafile, - verbose=verbose, **kwds, ) if self._timed_dataframe is not None and adc_column in self._timed_dataframe.columns: @@ -1786,7 +1796,7 @@ def calibrate_delay_axis( self._timed_dataframe, delay_range=delay_range, datafile=datafile, - verbose=False, + suppress_output=True, **kwds, ) @@ -1804,8 +1814,7 @@ def calibrate_delay_axis( if preview: logger.info(self._dataframe.head(10)) else: - if self.verbose: - logger.info(self._dataframe) + logger.debug(self._dataframe) def save_delay_calibration( self, @@ -1898,7 +1907,6 @@ def add_delay_offset( weights=weights, reductions=reductions, preserve_mean=preserve_mean, - verbose=verbose, ) if self._timed_dataframe is not None and delay_column in self._timed_dataframe.columns: tdf, _ = self.dc.add_offsets( @@ -1910,7 +1918,7 @@ def add_delay_offset( weights=weights, reductions=reductions, preserve_mean=preserve_mean, - verbose=False, + suppress_output=True, ) self._attributes.add( From 329265852186c5aaeeb2f2a7d313c3a0cfe41e9d Mon Sep 17 00:00:00 2001 From: rettigl Date: Tue, 13 Aug 2024 22:41:44 +0200 Subject: [PATCH 07/11] use logging in momentum calibrator --- sed/calibrator/momentum.py | 113 +++++++++++++++++++++---------------- sed/core/processor.py | 41 ++------------ 2 files changed, 71 insertions(+), 83 deletions(-) diff --git a/sed/calibrator/momentum.py b/sed/calibrator/momentum.py index 44f1def2..572a08fa 100644 --- a/sed/calibrator/momentum.py +++ b/sed/calibrator/momentum.py @@ -6,6 +6,8 @@ import itertools as it from copy import deepcopy from datetime import datetime +from logging import INFO +from logging import WARNING from typing import Any import bokeh.palettes as bp @@ -32,6 +34,11 @@ from symmetrize import sym from symmetrize import tps +from sed.core.logging import setup_logging + +# Configure logging +logger = setup_logging("momentum") + class MomentumCorrector: """ @@ -44,6 +51,8 @@ class MomentumCorrector: provided as np.ndarray. Defaults to None. rotsym (int, optional): Rotational symmetry of the data. Defaults to 6. config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ def __init__( @@ -52,6 +61,7 @@ def __init__( bin_ranges: list[tuple] = None, rotsym: int = 6, config: dict = None, + verbose: bool = True, ): """Constructor of the MomentumCorrector class. @@ -62,12 +72,20 @@ def __init__( if provided as np.ndarray. Defaults to None. rotsym (int, optional): Rotational symmetry of the data. Defaults to 6. config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ if config is None: config = {} self._config = config + self.verbose = verbose + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) + self.image: np.ndarray = None self.img_ndim: int = None self.slice: np.ndarray = None @@ -308,6 +326,8 @@ def select_slice( if self.slice is not None: self.slice_corrected = self.slice_transformed = self.slice + logger.debug(f"Selected energy slice {selector} for momentum correction.") + elif self.img_ndim == 2: raise ValueError("Input image dimension is already 2!") @@ -594,7 +614,6 @@ def spline_warp_estimate( fixed_center: bool = True, interp_order: int = 1, ascale: float | list | tuple | np.ndarray = None, - verbose: bool = True, **kwds, ) -> np.ndarray: """Estimate the spline deformation field using thin plate spline registration. @@ -618,8 +637,6 @@ def spline_warp_estimate( points to be located along the principal axes (X/Y points of the Brillouin zone). Otherwise, an array with ``rotsym`` elements is expected, containing relative scales for each feature. Defaults to an array of equal scales. - verbose (bool, optional): Option to report the used landmarks for correction. - Defaults to True. **kwds: keyword arguments: - **landmarks**: (list/array): Landmark positions (row, column) used @@ -647,7 +664,6 @@ def spline_warp_estimate( if self.pouter is not None: self.pouter_ord = po.pointset_order(self.pouter) self.correction["creation_date"] = datetime.now().timestamp() - self.correction["creation_date"] = datetime.now().timestamp() else: try: features = np.asarray( @@ -661,22 +677,20 @@ def spline_warp_estimate( if ascale is not None: ascale = np.asarray(ascale) - if verbose: - if "creation_date" in self.correction: - datestring = datetime.fromtimestamp( - self.correction["creation_date"], - ).strftime( - "%m/%d/%Y, %H:%M:%S", - ) - print( - "No landmarks defined, using momentum correction parameters " - f"generated on {datestring}", - ) - else: - print( - "No landmarks defined, using momentum correction parameters " - "from config.", - ) + if "creation_date" in self.correction: + datestring = datetime.fromtimestamp( + self.correction["creation_date"], + ).strftime + ("%m/%d/%Y, %H:%M:%S",) + logger.info( + "No landmarks defined, using momentum correction parameters " + f"generated on {datestring}", + ) + else: + logger.info( + "No landmarks defined, using momentum correction parameters " + "from config.", + ) except KeyError as exc: raise ValueError( "No valid landmarks defined, and no landmarks found in configuration!", @@ -786,11 +800,13 @@ def spline_warp_estimate( if self.slice is not None: self.slice_corrected = corrected_image - if verbose: - print("Calculated thin spline correction based on the following landmarks:") - print(f"pouter: {self.pouter}") - if use_center: - print(f"pcent: {self.pcent}") + log_str = ( + "Calculated thin spline correction based on the following landmarks:\n" + f"pouter_ord: {self.pouter_ord}" + ) + if use_center: + log_str += f"\npcent: {self.pcent}" + logger.info(log_str) return corrected_image @@ -1042,7 +1058,6 @@ def pose_adjustment( transformations: dict[str, Any] = None, apply: bool = False, reset: bool = True, - verbose: bool = True, **kwds, ): """Interactive panel to adjust transformations that are applied to the image. @@ -1057,8 +1072,6 @@ def pose_adjustment( Defaults to False. reset (bool, optional): Option to reset the correction before transformation. Defaults to True. - verbose (bool, optional): - Option to report the performed transformations. Defaults to True. **kwds: Keyword parameters defining defaults for the transformations: - **scale** (float): Initial value of the scaling slider. @@ -1105,11 +1118,11 @@ def pose_adjustment( f"pose_adjustment() got unexpected keyword arguments {kwds.keys()}.", ) - elif "creation_date" in transformations and verbose: + elif "creation_date" in transformations: datestring = datetime.fromtimestamp(transformations["creation_date"]).strftime( "%m/%d/%Y, %H:%M:%S", ) - print(f"Using transformation parameters generated on {datestring}") + logger.info(f"Using transformation parameters generated on {datestring}") def update(scale: float, xtrans: float, ytrans: float, angle: float): transformed_image = source_image @@ -1196,9 +1209,7 @@ def apply_func(apply: bool): # noqa: ARG001 yscale=transformations["scale"], keep=True, ) - if verbose: - with results_box: - print(f"Applied scaling with scale={transformations['scale']}.") + logger.info(f"Applied scaling with scale={transformations['scale']}.") if transformations.get("xtrans", 0) != 0 or transformations.get("ytrans", 0) != 0: self.coordinate_transform( transform_type="translation", @@ -1206,12 +1217,10 @@ def apply_func(apply: bool): # noqa: ARG001 ytrans=transformations.get("ytrans", 0), keep=True, ) - if verbose: - with results_box: - print( - f"Applied translation with (xtrans={transformations.get('xtrans', 0)},", - f"ytrans={transformations.get('ytrans', 0)}).", - ) + logger.info( + f"Applied translation with (xtrans={transformations.get('xtrans', 0)}, " + f"ytrans={transformations.get('ytrans', 0)}).", + ) if transformations.get("angle", 0) != 0: self.coordinate_transform( transform_type="rotation", @@ -1219,9 +1228,7 @@ def apply_func(apply: bool): # noqa: ARG001 center=center, keep=True, ) - if verbose: - with results_box: - print(f"Applied rotation with angle={transformations['angle']}.") + logger.info(f"Applied rotation with angle={transformations['angle']}.") display(results_box) @@ -1237,10 +1244,10 @@ def apply_func(apply: bool): # noqa: ARG001 transformations["creation_date"] = datetime.now().timestamp() self.transformations = transformations - if verbose: + if self.verbose: plt.figure() subs = 20 - plt.title("Deformation field") + plt.title("Final Deformation field") plt.scatter( self.rdeform_field[::subs, ::subs].ravel(), self.cdeform_field[::subs, ::subs].ravel(), @@ -1659,6 +1666,12 @@ def calibrate( pixel_distance = norm(point_a - point_b) # Calculate the pixel to momentum conversion factor xratio = yratio = k_distance / pixel_distance + logger.debug( + f"Momentum calibration performed using the following parameters:\n" + f"point_a={point_a}\n" + f"point_b={point_b}\n" + f"k_distance={k_distance}", + ) else: assert k_coord_a is not None @@ -1669,6 +1682,13 @@ def calibrate( # Calculate the column- and row-wise conversion factor xratio = (kxa - kxb) / (point_a[0] - point_b[0]) yratio = (kya - kyb) / (point_a[1] - point_b[1]) + logger.debug( + f"Momentum calibration performed using the following parameters:\n" + f"point_a={point_a}\n" + f"point_b={point_b}\n" + f"k_coord_a={k_coord_a}\n" + f"k_coord_b={k_coord_b}", + ) k_row = rowdist * xratio + k_coord_b[0] k_col = coldist * yratio + k_coord_b[1] @@ -1705,7 +1725,6 @@ def apply_corrections( y_column: str = None, new_x_column: str = None, new_y_column: str = None, - verbose: bool = True, ) -> tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: """Calculate and replace the X and Y values with their distortion-corrected version. @@ -1723,8 +1742,6 @@ def apply_corrections( new_y_column (str, optional): Label of the 'Y' column after momentum distortion correction. Defaults to config["momentum"]["corrected_y_column"]. - verbose (bool, optional): Option to report the used landmarks for correction. - Defaults to True. Returns: tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: Dataframe with @@ -1745,7 +1762,7 @@ def apply_corrections( if self.correction or self.transformations: if self.correction: # Generate spline warp from class features or config - self.spline_warp_estimate(verbose=verbose) + self.spline_warp_estimate() if self.transformations: # Apply config pose adjustments self.pose_adjustment() diff --git a/sed/core/processor.py b/sed/core/processor.py index 6af1cd06..0aeda86d 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -620,7 +620,6 @@ def define_features( def generate_splinewarp( self, use_center: bool = None, - verbose: bool = None, **kwds, ): """3. Step of the distortion correction workflow: Generate the correction @@ -629,16 +628,12 @@ def generate_splinewarp( Args: use_center (bool, optional): Option to use the position of the center point in the correction. Default is read from config, or set to True. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword arguments for MomentumCorrector.spline_warp_estimate(). """ - if verbose is None: - verbose = self.verbose - self.mc.spline_warp_estimate(use_center=use_center, verbose=verbose, **kwds) + self.mc.spline_warp_estimate(use_center=use_center, **kwds) - if self.mc.slice is not None and verbose: + if self.mc.slice is not None and self.verbose: print("Original slice with reference features") self.mc.view(annotated=True, backend="bokeh", crosshair=True) @@ -712,7 +707,6 @@ def pose_adjustment( apply: bool = False, use_correction: bool = True, reset: bool = True, - verbose: bool = None, **kwds, ): """3. step of the distortion correction workflow: Generate an interactive panel @@ -729,8 +723,6 @@ def pose_adjustment( or not. Defaults to True. reset (bool, optional): Option to reset the correction before transformation. Defaults to True. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword parameters defining defaults for the transformations: - **scale** (float): Initial value of the scaling slider. @@ -738,9 +730,6 @@ def pose_adjustment( - **ytrans** (float): Initial value of the ytrans slider. - **angle** (float): Initial value of the angle slider. """ - if verbose is None: - verbose = self.verbose - # Generate homography as default if no distortion correction has been applied if self.mc.slice_corrected is None: if self.mc.slice is None: @@ -752,13 +741,12 @@ def pose_adjustment( if self.mc.cdeform_field is None or self.mc.rdeform_field is None: # Generate distortion correction from config values - self.mc.spline_warp_estimate(verbose=verbose) + self.mc.spline_warp_estimate() self.mc.pose_adjustment( transformations=transformations, apply=apply, reset=reset, - verbose=verbose, **kwds, ) @@ -801,7 +789,6 @@ def save_transformations( def apply_momentum_correction( self, preview: bool = False, - verbose: bool = None, **kwds, ): """Applies the distortion correction and pose adjustment (optional) @@ -810,8 +797,6 @@ def apply_momentum_correction( Args: preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword parameters for ``MomentumCorrector.apply_correction``: - **rdeform_field** (np.ndarray, optional): Row deformation field. @@ -819,18 +804,13 @@ def apply_momentum_correction( - **inv_dfield** (np.ndarray, optional): Inverse deformation field. """ - if verbose is None: - verbose = self.verbose - x_column = self._config["dataframe"]["x_column"] y_column = self._config["dataframe"]["y_column"] if self._dataframe is not None: - if verbose: - logger.info("Adding corrected X/Y columns to dataframe:") + logger.info("Adding corrected X/Y columns to dataframe:") df, metadata = self.mc.apply_corrections( df=self._dataframe, - verbose=verbose, **kwds, ) if ( @@ -840,7 +820,6 @@ def apply_momentum_correction( ): tdf, _ = self.mc.apply_corrections( self._timed_dataframe, - verbose=False, **kwds, ) @@ -862,8 +841,7 @@ def apply_momentum_correction( if preview: logger.info(self._dataframe.head(10)) else: - if self.verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) # Momentum calibration work flow # 1. Calculate momentum calibration @@ -957,7 +935,6 @@ def apply_momentum_calibration( self, calibration: dict = None, preview: bool = False, - verbose: bool = None, **kwds, ): """2. step of the momentum calibration work flow: Apply the momentum @@ -969,13 +946,8 @@ def apply_momentum_calibration( use. Defaults to None. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword args passed to ``MomentumCalibrator.append_k_axis``. """ - if verbose is None: - verbose = self.verbose - x_column = self._config["dataframe"]["x_column"] y_column = self._config["dataframe"]["y_column"] @@ -1015,8 +987,7 @@ def apply_momentum_calibration( if preview: logger.info(self._dataframe.head(10)) else: - if self.verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) # Energy correction workflow # 1. Adjust the energy correction parameters From e3af246803fea24c46cf0e0b608789ee2fadce27 Mon Sep 17 00:00:00 2001 From: rettigl Date: Wed, 14 Aug 2024 00:15:10 +0200 Subject: [PATCH 08/11] use logging in energy calibrator, and further fixes --- sed/calibrator/delay.py | 21 ++-- sed/calibrator/energy.py | 118 +++++++++++------- sed/core/processor.py | 115 ++++++----------- sed/loader/mpes/loader.py | 11 -- ...for_example_time-resolved_ARPES_data.ipynb | 1 - 5 files changed, 121 insertions(+), 145 deletions(-) diff --git a/sed/calibrator/delay.py b/sed/calibrator/delay.py index d259bb60..c4d8f797 100644 --- a/sed/calibrator/delay.py +++ b/sed/calibrator/delay.py @@ -326,15 +326,13 @@ def add_offsets( weights = [] preserve_mean = [] reductions = [] - if not suppress_output: - logger.info("Delay offset parameters:") + log_str = "Delay offset parameters:" for k, v in offsets.items(): if k == "creation_date": continue if k == "constant": constant = v - if not suppress_output: - print(f" Constant: {constant} ") + log_str += f"\n Constant: {constant}" elif k == "flip_delay_axis": fda = str(v) if fda.lower() in ["true", "1"]: @@ -345,8 +343,7 @@ def add_offsets( raise ValueError( f"Invalid value for flip_delay_axis in config: {flip_delay_axis}.", ) - if not suppress_output: - logger.info(f" Flip delay axis: {flip_delay_axis} ") + log_str += f"\n Flip delay axis: {flip_delay_axis}" else: columns.append(k) try: @@ -358,11 +355,13 @@ def add_offsets( preserve_mean.append(pm) red = v.get("reduction", None) reductions.append(red) - if not suppress_output: - logger.info( - f" Column[{k}]: Weight={weight}, Preserve Mean: {pm}, " - f"Reductions: {red}.", - ) + log_str += ( + f"\n Column[{k}]: Weight={weight}, Preserve Mean: {pm}, " + f"Reductions: {red}." + ) + + if not suppress_output: + logger.info(log_str) if len(columns) > 0: df = dfops.offset_by_other_columns( diff --git a/sed/calibrator/energy.py b/sed/calibrator/energy.py index 62e5a4ff..ca7c2f10 100644 --- a/sed/calibrator/energy.py +++ b/sed/calibrator/energy.py @@ -8,6 +8,8 @@ from copy import deepcopy from datetime import datetime from functools import partial +from logging import INFO +from logging import WARNING from typing import Any from typing import cast from typing import Literal @@ -28,15 +30,19 @@ from IPython.display import display from lmfit import Minimizer from lmfit import Parameters -from lmfit.printfuncs import report_fit +from lmfit.printfuncs import fit_report from numpy.linalg import lstsq from scipy.signal import savgol_filter from scipy.sparse.linalg import lsqr from sed.binning import bin_dataframe from sed.core import dfops +from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader +# Configure logging +logger = setup_logging("delay") + class EnergyCalibrator: """Electron binding energy calibration workflow. @@ -53,6 +59,8 @@ class EnergyCalibrator: tof (np.ndarray, optional): TOF-values for the data traces. Defaults to None. config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ def __init__( @@ -62,6 +70,7 @@ def __init__( traces: np.ndarray = None, tof: np.ndarray = None, config: dict = None, + verbose: bool = True, ): """For the initialization of the EnergyCalibrator class an instance of a loader is required. The data can be loaded using the optional arguments, @@ -75,7 +84,20 @@ def __init__( tof (np.ndarray, optional): TOF-values for the data traces. Defaults to None. config (dict, optional): Config dictionary. Defaults to None. + verbose (bool, optional): Option to print out diagnostic information. + Defaults to True. """ + if config is None: + config = {} + + self._config = config + + self.verbose = verbose + if self.verbose: + logger.handlers[0].setLevel(INFO) + else: + logger.handlers[0].setLevel(WARNING) + self.loader = loader self.biases: np.ndarray = None self.traces: np.ndarray = None @@ -85,11 +107,6 @@ def __init__( if traces is not None and tof is not None and biases is not None: self.load_data(biases=biases, traces=traces, tof=tof) - if config is None: - config = {} - - self._config = config - self.featranges: list[tuple] = [] # Value ranges for feature detection self.peaks: np.ndarray = np.asarray([]) self.calibration: dict[str, Any] = self._config["energy"].get("calibration", {}) @@ -276,6 +293,7 @@ def normalize(self, smooth: bool = False, span: int = 7, order: int = 1): span=span, order=order, ) + logger.debug("Normalized energy calibration traces.") def adjust_ranges( self, @@ -393,7 +411,9 @@ def apply_func(apply: bool): # noqa: ARG001 traces=self.traces_normed, **kwds, ) + logger.info(f"Use feature ranges: {self.featranges}.") self.feature_extract(peak_window=7) + logger.info(f"Extracted energy features: {self.peaks}.") ranges_slider.close() refid_slider.close() apply_button.close() @@ -499,7 +519,6 @@ def calibrate( landmarks: np.ndarray = None, biases: np.ndarray = None, t: np.ndarray = None, - verbose: bool = True, **kwds, ) -> dict: """Calculate the functional mapping between time-of-flight and the energy @@ -523,8 +542,6 @@ def calibrate( calibration. Defaults to self.peaks. biases (np.ndarray, optional): Bias values. Defaults to self.biases. t (np.ndarray, optional): TOF values. Defaults to self.tof. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. **kwds: keyword arguments. See available keywords for ``poly_energy_calibration()`` and ``fit_energy_calibration()`` @@ -564,7 +581,6 @@ def calibrate( ref_energy=ref_energy, t=t, energy_scale=energy_scale, - verbose=verbose, **kwds, ) elif method in ("lstsq", "lsqr"): @@ -584,7 +600,7 @@ def calibrate( self.calibration["creation_date"] = datetime.now().timestamp() return self.calibration - def view( # pylint: disable=dangerous-default-value + def view( self, traces: np.ndarray, segs: list[tuple] = None, @@ -634,7 +650,7 @@ def view( # pylint: disable=dangerous-default-value sign = 1 if energy_scale == "kinetic" else -1 if backend == "matplotlib": - figsize = kwds.pop("figsize", (12, 4)) + figsize = kwds.pop("figsize", (6, 4)) fig_plt, ax = plt.subplots(figsize=figsize) for itr, trace in enumerate(traces): if align: @@ -762,7 +778,7 @@ def append_energy_axis( energy_column: str = None, calibration: dict = None, bias_voltage: float = None, - verbose: bool = True, + suppress_output: bool = False, **kwds, ) -> tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: """Calculate and append the energy axis to the events dataframe. @@ -780,8 +796,8 @@ def append_energy_axis( bias_voltage (float, optional): Sample bias voltage of the scan data. If omitted, the bias voltage is being read from the dataframe. If it is not found there, a warning is printed and the calibrated data might have an offset. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. + verbose (bool, optional): Option to suppress output of diagnostic information. + Defaults to False. **kwds: additional keyword arguments for the energy conversion. They are added to the calibration dictionary. @@ -814,11 +830,11 @@ def append_energy_axis( calibration[key] = value calibration["creation_date"] = datetime.now().timestamp() - elif "creation_date" in calibration and verbose: + elif "creation_date" in calibration and not suppress_output: datestring = datetime.fromtimestamp(calibration["creation_date"]).strftime( "%m/%d/%Y, %H:%M:%S", ) - print(f"Using energy calibration parameters generated on {datestring}") + logger.info(f"Using energy calibration parameters generated on {datestring}") # try to determine calibration type if not provided if "calib_type" not in calibration: @@ -870,10 +886,20 @@ def append_energy_axis( else: raise NotImplementedError + if not suppress_output: + report_dict = { + "calib_type": calibration["calib_type"], + "fit_function": calibration["fit_function"], + "coefficients": calibration["coefficients"], + } + logger.debug(f"Used energy calibration parameters: {report_dict}.") + # apply bias offset scale_sign: Literal[-1, 1] = -1 if calibration["energy_scale"] == "binding" else 1 if bias_voltage is not None: df[energy_column] = df[energy_column] + scale_sign * bias_voltage + if not suppress_output: + logger.debug(f"Shifted energy column by constant bias value: {bias_voltage}.") elif self._config["dataframe"]["bias_column"] in df.columns: df = dfops.offset_by_other_columns( df=df, @@ -881,8 +907,15 @@ def append_energy_axis( offset_columns=self._config["dataframe"]["bias_column"], weights=scale_sign, ) + if not suppress_output: + logger.debug( + "Shifted energy column by bias column: " + f"{self._config['dataframe']['bias_column']}.", + ) else: - print("Sample bias data not found or provided. Calibrated energy might be incorrect.") + logger.warning( + "Sample bias data not found or provided. Calibrated energy might be incorrect.", + ) metadata = self.gather_calibration_metadata(calibration) @@ -1324,7 +1357,7 @@ def apply_energy_correction( correction_type: str = None, amplitude: float = None, correction: dict = None, - verbose: bool = True, + suppress_output: bool = False, **kwds, ) -> tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: """Apply correction to the time-of-flight (TOF) axis of single-event data. @@ -1350,8 +1383,8 @@ def apply_energy_correction( correction (dict, optional): Correction dictionary containing parameters for the correction. Defaults to self.correction or config["energy"]["correction"]. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. + suppress_output (bool, optional): Option to suppress output of diagnostic information. + Defaults to False. **kwds: Additional parameters to use for the correction: - **x_column** (str): Name of the x column. @@ -1394,16 +1427,19 @@ def apply_energy_correction( correction["creation_date"] = datetime.now().timestamp() - elif "creation_date" in correction and verbose: + elif "creation_date" in correction and not suppress_output: datestring = datetime.fromtimestamp(correction["creation_date"]).strftime( "%m/%d/%Y, %H:%M:%S", ) - print(f"Using energy correction parameters generated on {datestring}") + logger.info(f"Using energy correction parameters generated on {datestring}") missing_keys = {"correction_type", "center", "amplitude"} - set(correction.keys()) if missing_keys: raise ValueError(f"Required correction parameters '{missing_keys}' missing!") + if not suppress_output: + logger.debug(f"Correction parameters:\n{correction}") + df[new_tof_column] = df[tof_column] + correction_function( x=df[x_column], y=df[y_column], @@ -1489,7 +1525,7 @@ def add_offsets( preserve_mean: bool | Sequence[bool] = False, reductions: str | Sequence[str] = None, energy_column: str = None, - verbose: bool = True, + suppress_output: bool = False, ) -> tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: """Apply an offset to the energy column by the values of the provided columns. @@ -1512,8 +1548,8 @@ def add_offsets( If None, the shift is applied per-dataframe-row. Defaults to None. Currently only "mean" is supported. energy_column (str, optional): Name of the column containing the energy values. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. + suppress_output (bool, optional): Option to suppress output of diagnostic information. + Defaults to False. Returns: tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: Dataframe with the new columns @@ -1584,11 +1620,11 @@ def add_offsets( elif constant is not None: raise TypeError(f"Invalid type for constant: {type(constant)}") - elif "creation_date" in offsets and verbose: + elif "creation_date" in offsets and not suppress_output: datestring = datetime.fromtimestamp(offsets["creation_date"]).strftime( "%m/%d/%Y, %H:%M:%S", ) - print(f"Using energy offset parameters generated on {datestring}") + logger.info(f"Using energy offset parameters generated on {datestring}") if len(offsets) > 0: # unpack dictionary @@ -1597,16 +1633,14 @@ def add_offsets( weights = [] preserve_mean = [] reductions = [] - if verbose: - print("Energy offset parameters:") + log_str = "Energy offset parameters:" for k, v in offsets.items(): if k == "creation_date": continue if k == "constant": # flip sign if binding energy scale constant = v * scale_sign - if verbose: - print(f" Constant: {constant} ") + log_str += f"\n Constant: {constant}" else: columns.append(k) try: @@ -1628,11 +1662,13 @@ def add_offsets( if str(red).lower() in ["none", "null"]: red = None reductions.append(red) - if verbose: - print( - f" Column[{k}]: Weight={weight}, Preserve Mean: {pm}, ", - f"Reductions: {red}.", - ) + log_str += ( + f"\n Column[{k}]: Weight={weight}, Preserve Mean: {pm}, " + f"Reductions: {red}." + ) + + if not suppress_output: + logger.info(log_str) if len(columns) > 0: df = dfops.offset_by_other_columns( @@ -1940,7 +1976,7 @@ def peaksearch( try: pkmaxs.append(maxs[0, :]) except IndexError: # No peak found for this range - print(f"No peak detected in range {rng}.") + logger.error(f"No peak detected in range {rng}.") raise if plot: @@ -2111,7 +2147,6 @@ def fit_energy_calibration( ref_energy: float, t: list[float] | np.ndarray = None, energy_scale: str = "kinetic", - verbose: bool = True, **kwds, ) -> dict: """Energy calibration by nonlinear least squares fitting of spectral landmarks on @@ -2133,8 +2168,6 @@ def fit_energy_calibration( - **'kinetic'**: increasing energy with decreasing TOF. - **'binding'**: increasing energy with increasing TOF. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to True. **kwds: keyword arguments: - **t0** (float): constrains and initial values for the fit parameter t0, @@ -2201,8 +2234,7 @@ def residual(pars, time, data, binwidth, binning, energy_scale): fcn_args=(pos, vals, binwidth, binning, energy_scale), ) result = fit.leastsq() - if verbose: - report_fit(result) + logger.info(fit_report(result)) # Construct the calibrating function pfunc = partial( diff --git a/sed/core/processor.py b/sed/core/processor.py index 0aeda86d..47a8f204 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -1075,7 +1075,6 @@ def apply_energy_correction( self, correction: dict = None, preview: bool = False, - verbose: bool = None, **kwds, ): """2. step of the energy correction workflow: Apply the energy correction @@ -1086,30 +1085,23 @@ def apply_energy_correction( parameters. Defaults to config["energy"]["calibration"]. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword args passed to ``EnergyCalibrator.apply_energy_correction()``. """ - if verbose is None: - verbose = self.verbose - tof_column = self._config["dataframe"]["tof_column"] if self._dataframe is not None: - if verbose: - logger.info("Applying energy correction to dataframe...") + logger.info("Applying energy correction to dataframe...") df, metadata = self.ec.apply_energy_correction( df=self._dataframe, correction=correction, - verbose=verbose, **kwds, ) if self._timed_dataframe is not None and tof_column in self._timed_dataframe.columns: tdf, _ = self.ec.apply_energy_correction( df=self._timed_dataframe, correction=correction, - verbose=False, + suppress_output=True, **kwds, ) @@ -1126,8 +1118,7 @@ def apply_energy_correction( if preview: logger.info(self._dataframe.head(10)) else: - if verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) # Energy calibrator workflow # 1. Load and normalize data @@ -1195,6 +1186,7 @@ def load_bias_series( "If binned_data is provided as tuple, it needs to contain " "(tof, biases, traces)!", ) from exc + logger.debug(f"Energy calibration data loaded from binned data. Bias values={biases}.") self.ec.load_data(biases=biases, traces=traces, tof=tof) elif data_files is not None: @@ -1206,6 +1198,10 @@ def load_bias_series( biases=biases, bias_key=bias_key, ) + logger.debug( + f"Energy calibration data binned from files {data_files} data. " + f"Bias values={biases}.", + ) else: raise ValueError("Either binned_data or data_files needs to be provided!") @@ -1272,9 +1268,10 @@ def find_bias_peaks( mode=mode, radius=radius, ) - logger.info(self.ec.featranges) + logger.info(f"Use feature ranges: {self.ec.featranges}.") try: self.ec.feature_extract(peak_window=peak_window) + logger.info(f"Extracted energy features: {self.ec.peaks}.") self.ec.view( traces=self.ec.traces_normed, segs=self.ec.featranges, @@ -1283,7 +1280,7 @@ def find_bias_peaks( backend="bokeh", ) except IndexError: - print("Could not determine all peaks!") + logger.error("Could not determine all peaks!") raise else: # New adjustment tool @@ -1305,7 +1302,6 @@ def calibrate_energy_axis( ref_energy: float, method: str = None, energy_scale: str = None, - verbose: bool = None, **kwds, ): """3. Step of the energy calibration workflow: Calculate the calibration @@ -1327,13 +1323,8 @@ def calibrate_energy_axis( - **'binding'**: increasing energy with increasing TOF. Defaults to config["energy"]["energy_scale"] - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds**: Keyword parameters passed to ``EnergyCalibrator.calibrate()``. """ - if verbose is None: - verbose = self.verbose - if method is None: method = self._config["energy"]["calibration_method"] @@ -1344,25 +1335,28 @@ def calibrate_energy_axis( ref_energy=ref_energy, method=method, energy_scale=energy_scale, - verbose=verbose, **kwds, ) - if verbose: - print("Quality of Calibration:") + if self.verbose: self.ec.view( traces=self.ec.traces_normed, xaxis=self.ec.calibration["axis"], align=True, energy_scale=energy_scale, - backend="bokeh", + backend="matplotlib", + title="Quality of Calibration", ) - print("E/TOF relationship:") + plt.xlabel("Energy (eV)") + plt.ylabel("Intensity") + plt.tight_layout() + plt.show() if energy_scale == "kinetic": self.ec.view( traces=self.ec.calibration["axis"][None, :] + self.ec.biases[0], xaxis=self.ec.tof, backend="matplotlib", show_legend=False, + title="E/TOF relationship", ) plt.scatter( self.ec.peaks[:, 0], @@ -1370,12 +1364,14 @@ def calibrate_energy_axis( s=50, c="k", ) + plt.tight_layout() elif energy_scale == "binding": self.ec.view( traces=self.ec.calibration["axis"][None, :] - self.ec.biases[0], xaxis=self.ec.tof, backend="matplotlib", show_legend=False, + title="E/TOF relationship", ) plt.scatter( self.ec.peaks[:, 0], @@ -1388,8 +1384,9 @@ def calibrate_energy_axis( 'energy_scale needs to be either "binding" or "kinetic"', f", got {energy_scale}.", ) - plt.xlabel("Time-of-flight", fontsize=15) - plt.ylabel("Energy (eV)", fontsize=15) + plt.xlabel("Time-of-flight") + plt.ylabel("Energy (eV)") + plt.tight_layout() plt.show() # 3a. Save energy calibration parameters to config file. @@ -1435,7 +1432,6 @@ def append_energy_axis( calibration: dict = None, bias_voltage: float = None, preview: bool = False, - verbose: bool = None, **kwds, ): """4. step of the energy calibration workflow: Apply the calibration function @@ -1451,24 +1447,17 @@ def append_energy_axis( the bias voltage is being read from the dataframe. If it is not found there, a warning is printed and the calibrated data might have an offset. preview (bool): Option to preview the first elements of the data frame. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: Keyword args passed to ``EnergyCalibrator.append_energy_axis()``. """ - if verbose is None: - verbose = self.verbose - tof_column = self._config["dataframe"]["tof_column"] if self._dataframe is not None: - if verbose: - logger.info("Adding energy column to dataframe:") + logger.info("Adding energy column to dataframe:") df, metadata = self.ec.append_energy_axis( df=self._dataframe, calibration=calibration, bias_voltage=bias_voltage, - verbose=verbose, **kwds, ) if self._timed_dataframe is not None and tof_column in self._timed_dataframe.columns: @@ -1476,7 +1465,7 @@ def append_energy_axis( df=self._timed_dataframe, calibration=calibration, bias_voltage=bias_voltage, - verbose=False, + suppress_output=True, **kwds, ) @@ -1495,8 +1484,7 @@ def append_energy_axis( if preview: logger.info(self._dataframe.head(10)) else: - if verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) @call_logger(logger) def add_energy_offset( @@ -1507,7 +1495,6 @@ def add_energy_offset( reductions: str | Sequence[str] = None, preserve_mean: bool | Sequence[bool] = None, preview: bool = False, - verbose: bool = None, ) -> None: """Shift the energy axis of the dataframe by a given amount. @@ -1525,15 +1512,10 @@ def add_energy_offset( column before applying the shift. Defaults to False. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. Raises: ValueError: If the energy column is not in the dataframe. """ - if verbose is None: - verbose = self.verbose - energy_column = self._config["dataframe"]["energy_column"] if energy_column not in self._dataframe.columns: raise ValueError( @@ -1541,8 +1523,7 @@ def add_energy_offset( "Run `append_energy_axis()` first.", ) if self.dataframe is not None: - if verbose: - logger.info("Adding energy offset to dataframe:") + logger.info("Adding energy offset to dataframe:") df, metadata = self.ec.add_offsets( df=self._dataframe, constant=constant, @@ -1551,7 +1532,6 @@ def add_energy_offset( weights=weights, reductions=reductions, preserve_mean=preserve_mean, - verbose=verbose, ) if self._timed_dataframe is not None and energy_column in self._timed_dataframe.columns: tdf, _ = self.ec.add_offsets( @@ -1562,6 +1542,7 @@ def add_energy_offset( weights=weights, reductions=reductions, preserve_mean=preserve_mean, + suppress_output=True, ) self._attributes.add( @@ -1578,7 +1559,7 @@ def add_energy_offset( raise ValueError("No dataframe loaded!") if preview: logger.info(self._dataframe.head(10)) - elif verbose: + else: logger.info(self._dataframe) def save_energy_offset( @@ -1610,7 +1591,6 @@ def save_energy_offset( def append_tof_ns_axis( self, preview: bool = False, - verbose: bool = None, **kwds, ): """Convert time-of-flight channel steps to nanoseconds. @@ -1621,19 +1601,13 @@ def append_tof_ns_axis( Defaults to config["dataframe"]["tof_ns_column"]. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: additional arguments are passed to ``EnergyCalibrator.append_tof_ns_axis()``. """ - if verbose is None: - verbose = self.verbose - tof_column = self._config["dataframe"]["tof_column"] if self._dataframe is not None: - if verbose: - logger.info("Adding time-of-flight column in nanoseconds to dataframe.") + logger.info("Adding time-of-flight column in nanoseconds to dataframe.") # TODO assert order of execution through metadata df, metadata = self.ec.append_tof_ns_axis( @@ -1659,15 +1633,13 @@ def append_tof_ns_axis( if preview: logger.info(self._dataframe.head(10)) else: - if verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) @call_logger(logger) def align_dld_sectors( self, sector_delays: np.ndarray = None, preview: bool = False, - verbose: bool = None, **kwds, ): """Align the 8s sectors of the HEXTOF endstation. @@ -1677,18 +1649,12 @@ def align_dld_sectors( config["dataframe"]["sector_delays"]. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. **kwds: additional arguments are passed to ``EnergyCalibrator.align_dld_sectors()``. """ - if verbose is None: - verbose = self.verbose - tof_column = self._config["dataframe"]["tof_column"] if self._dataframe is not None: - if verbose: - logger.info("Aligning 8s sectors of dataframe") + logger.info("Aligning 8s sectors of dataframe") # TODO assert order of execution through metadata df, metadata = self.ec.align_dld_sectors( @@ -1716,8 +1682,7 @@ def align_dld_sectors( if preview: logger.info(self._dataframe.head(10)) else: - if verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) # Delay calibration function @call_logger(logger) @@ -1834,7 +1799,6 @@ def add_delay_offset( reductions: str | Sequence[str] = None, preserve_mean: bool | Sequence[bool] = False, preview: bool = False, - verbose: bool = None, ) -> None: """Shift the delay axis of the dataframe by a constant or other columns. @@ -1853,22 +1817,16 @@ def add_delay_offset( column before applying the shift. Defaults to False. preview (bool, optional): Option to preview the first elements of the data frame. Defaults to False. - verbose (bool, optional): Option to print out diagnostic information. - Defaults to config["core"]["verbose"]. Raises: ValueError: If the delay column is not in the dataframe. """ - if verbose is None: - verbose = self.verbose - delay_column = self._config["dataframe"]["delay_column"] if delay_column not in self._dataframe.columns: raise ValueError(f"Delay column {delay_column} not found in dataframe! ") if self.dataframe is not None: - if verbose: - logger.info("Adding delay offset to dataframe:") + logger.info("Adding delay offset to dataframe:") df, metadata = self.dc.add_offsets( df=self._dataframe, constant=constant, @@ -1905,8 +1863,7 @@ def add_delay_offset( if preview: logger.info(self._dataframe.head(10)) else: - if verbose: - logger.info(self._dataframe) + logger.info(self._dataframe) def save_delay_offsets( self, diff --git a/sed/loader/mpes/loader.py b/sed/loader/mpes/loader.py index 22df8a0a..df4d0323 100644 --- a/sed/loader/mpes/loader.py +++ b/sed/loader/mpes/loader.py @@ -191,11 +191,6 @@ def hdf5_to_timed_dataframe( if channel["dataset_key"] in test_proc: electron_channels.append(channel) column_names.append(name) - else: - logger.warning( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found. " - "Skipping the channel.", - ) elif channel["format"] != "per_file": error_msg = f"Invalid 'format':{channel['format']} for channel {name}." logger.error(error_msg) @@ -246,12 +241,6 @@ def hdf5_to_timed_dataframe( ] dataframe = ddf.from_delayed(delayeds) - else: - logger.warning( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found. " - "Skipping the channel.", - ) - return dataframe diff --git a/tutorial/2_conversion_pipeline_for_example_time-resolved_ARPES_data.ipynb b/tutorial/2_conversion_pipeline_for_example_time-resolved_ARPES_data.ipynb index 34c448e1..82798d55 100644 --- a/tutorial/2_conversion_pipeline_for_example_time-resolved_ARPES_data.ipynb +++ b/tutorial/2_conversion_pipeline_for_example_time-resolved_ARPES_data.ipynb @@ -481,7 +481,6 @@ " d={'value':1.0,'min': .7, 'max':1.2, 'vary':True},\n", " t0={'value':8e-7, 'min': 1e-7, 'max': 1e-6, 'vary':True},\n", " E0={'value': 0., 'min': -100, 'max': 0, 'vary': True},\n", - " verbose=True,\n", ")" ] }, From 2a69836b962bb84eacca8444e4f44ba40fb4eeba Mon Sep 17 00:00:00 2001 From: rettigl Date: Wed, 14 Aug 2024 00:47:05 +0200 Subject: [PATCH 09/11] some further fixes --- sed/calibrator/momentum.py | 14 ++++++++++++-- sed/core/processor.py | 1 + tutorial/4_hextof_workflow.ipynb | 1 - 3 files changed, 13 insertions(+), 3 deletions(-) diff --git a/sed/calibrator/momentum.py b/sed/calibrator/momentum.py index 572a08fa..bae3bf65 100644 --- a/sed/calibrator/momentum.py +++ b/sed/calibrator/momentum.py @@ -680,8 +680,9 @@ def spline_warp_estimate( if "creation_date" in self.correction: datestring = datetime.fromtimestamp( self.correction["creation_date"], - ).strftime - ("%m/%d/%Y, %H:%M:%S",) + ).strftime( + "%m/%d/%Y, %H:%M:%S", + ) logger.info( "No landmarks defined, using momentum correction parameters " f"generated on {datestring}", @@ -1873,6 +1874,7 @@ def append_k_axis( new_x_column: str = None, new_y_column: str = None, calibration: dict = None, + suppress_output: bool = False, **kwds, ) -> tuple[pd.DataFrame | dask.dataframe.DataFrame, dict]: """Calculate and append the k axis coordinates (kx, ky) to the events dataframe. @@ -1892,6 +1894,8 @@ def append_k_axis( momentum calibration. Defaults to config["momentum"]["ky_column"]. calibration (dict, optional): Dictionary containing calibration parameters. Defaults to 'self.calibration' or config["momentum"]["calibration"]. + suppress_output (bool, optional): Option to suppress output of diagnostic information. + Defaults to False. **kwds: Keyword parameters for momentum calibration. Parameters are added to the calibration dictionary. @@ -1938,6 +1942,12 @@ def append_k_axis( if len(kwds) > 0: raise TypeError(f"append_k_axis() got unexpected keyword arguments {kwds.keys()}.") + if "creation_date" in calibration and not suppress_output: + datestring = datetime.fromtimestamp(calibration["creation_date"]).strftime( + "%m/%d/%Y, %H:%M:%S", + ) + logger.info(f"Using momentum calibration parameters generated on {datestring}") + try: (df[new_x_column], df[new_y_column]) = detector_coordinates_2_k_coordinates( r_det=df[x_column], diff --git a/sed/core/processor.py b/sed/core/processor.py index 47a8f204..247e13f4 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -966,6 +966,7 @@ def apply_momentum_calibration( tdf, _ = self.mc.append_k_axis( df=self._timed_dataframe, calibration=calibration, + suppress_output=True, **kwds, ) diff --git a/tutorial/4_hextof_workflow.ipynb b/tutorial/4_hextof_workflow.ipynb index 743a7e15..c9b36c04 100644 --- a/tutorial/4_hextof_workflow.ipynb +++ b/tutorial/4_hextof_workflow.ipynb @@ -503,7 +503,6 @@ " d={'value':1.0,'min': .2, 'max':1.0, 'vary':False},\n", " t0={'value':5e-7, 'min': 1e-7, 'max': 1e-6, 'vary':True},\n", " E0={'value': 0., 'min': -100, 'max': 100, 'vary': True},\n", - " verbose=True,\n", ")" ] }, From 79a181d5551eb20f77b4f7e5a0cdecf0d0f1eaaf Mon Sep 17 00:00:00 2001 From: rettigl Date: Thu, 19 Sep 2024 22:45:33 +0200 Subject: [PATCH 10/11] add function to set verbosity, and use in each class --- sed/calibrator/delay.py | 8 ++------ sed/calibrator/energy.py | 8 ++------ sed/calibrator/momentum.py | 8 ++------ sed/core/logging.py | 17 ++++++++++++++++- sed/core/processor.py | 8 ++------ sed/loader/flash/loader.py | 8 ++------ sed/loader/mpes/loader.py | 8 ++------ sed/loader/sxp/loader.py | 8 ++------ 8 files changed, 30 insertions(+), 43 deletions(-) diff --git a/sed/calibrator/delay.py b/sed/calibrator/delay.py index c4d8f797..d465a462 100644 --- a/sed/calibrator/delay.py +++ b/sed/calibrator/delay.py @@ -5,8 +5,6 @@ from collections.abc import Sequence from copy import deepcopy from datetime import datetime -from logging import INFO -from logging import WARNING from typing import Any import dask.dataframe @@ -15,6 +13,7 @@ import pandas as pd from sed.core import dfops +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging # Configure logging @@ -50,10 +49,7 @@ def __init__( self._config = {} self.verbose = verbose - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self.adc_column: str = self._config["dataframe"].get("adc_column", None) self.delay_column: str = self._config["dataframe"]["delay_column"] diff --git a/sed/calibrator/energy.py b/sed/calibrator/energy.py index ca7c2f10..1e50d745 100644 --- a/sed/calibrator/energy.py +++ b/sed/calibrator/energy.py @@ -8,8 +8,6 @@ from copy import deepcopy from datetime import datetime from functools import partial -from logging import INFO -from logging import WARNING from typing import Any from typing import cast from typing import Literal @@ -37,6 +35,7 @@ from sed.binning import bin_dataframe from sed.core import dfops +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader @@ -93,10 +92,7 @@ def __init__( self._config = config self.verbose = verbose - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self.loader = loader self.biases: np.ndarray = None diff --git a/sed/calibrator/momentum.py b/sed/calibrator/momentum.py index bae3bf65..ac26f0e7 100644 --- a/sed/calibrator/momentum.py +++ b/sed/calibrator/momentum.py @@ -6,8 +6,6 @@ import itertools as it from copy import deepcopy from datetime import datetime -from logging import INFO -from logging import WARNING from typing import Any import bokeh.palettes as bp @@ -34,6 +32,7 @@ from symmetrize import sym from symmetrize import tps +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging # Configure logging @@ -81,10 +80,7 @@ def __init__( self._config = config self.verbose = verbose - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self.image: np.ndarray = None self.img_ndim: int = None diff --git a/sed/core/logging.py b/sed/core/logging.py index 539f29b6..ad019dc8 100644 --- a/sed/core/logging.py +++ b/sed/core/logging.py @@ -29,7 +29,8 @@ def setup_logging( Args: name (str): The name of the logger. - base_name (str, optional): The name of the base logger. Defaults to "sed". + set_base_handler (bool, optional): Option to re-initialize the base handler logging to the + logfile. Defaults to False. user_log_path (str, optional): Path to the user-specific log directory. Defaults to DEFAULT_LOG_DIR. @@ -88,6 +89,20 @@ def setup_logging( return logger +def set_verbosity(logger: logging.Logger, verbose: bool) -> None: + """Sets log level for the given logger's default handler. + + Args: + logger (logging.Logger): The logger on which to set the log level. + verbose (bool): Sets loglevel to INFO if True, to WARNING otherwise. + """ + handler = logger.handlers[0] + if verbose: + handler.setLevel(logging.INFO) + else: + handler.setLevel(logging.WARNING) + + def call_logger(logger: logging.Logger): def log_call(func: Callable): @wraps(func) diff --git a/sed/core/processor.py b/sed/core/processor.py index 247e13f4..ea3ac37e 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -6,8 +6,6 @@ import pathlib from collections.abc import Sequence from datetime import datetime -from logging import INFO -from logging import WARNING from typing import Any from typing import cast @@ -30,6 +28,7 @@ from sed.core.dfops import apply_filter from sed.core.dfops import apply_jitter from sed.core.logging import call_logger +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging from sed.core.metadata import MetaHandler from sed.diagnostics import grid_histogram @@ -121,10 +120,7 @@ def __init__( self.verbose = self._config["core"].get("verbose", True) else: self.verbose = verbose - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self._dataframe: pd.DataFrame | ddf.DataFrame = None self._timed_dataframe: pd.DataFrame | ddf.DataFrame = None diff --git a/sed/loader/flash/loader.py b/sed/loader/flash/loader.py index b44b3b82..b17621fd 100644 --- a/sed/loader/flash/loader.py +++ b/sed/loader/flash/loader.py @@ -12,13 +12,12 @@ import re import time from collections.abc import Sequence -from logging import INFO -from logging import WARNING from pathlib import Path import dask.dataframe as dd from natsort import natsorted +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader from sed.loader.flash.buffer_handler import BufferHandler @@ -55,10 +54,7 @@ def __init__(self, config: dict, verbose: bool = True) -> None: """ super().__init__(config=config, verbose=verbose) - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self.instrument: str = self._config["core"].get("instrument", "hextof") # default is hextof self.raw_dir: str = None diff --git a/sed/loader/mpes/loader.py b/sed/loader/mpes/loader.py index df4d0323..c130308a 100644 --- a/sed/loader/mpes/loader.py +++ b/sed/loader/mpes/loader.py @@ -10,8 +10,6 @@ import json import os from collections.abc import Sequence -from logging import INFO -from logging import WARNING from typing import Any from urllib.error import HTTPError from urllib.error import URLError @@ -25,6 +23,7 @@ import scipy.interpolate as sint from natsort import natsorted +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader @@ -571,10 +570,7 @@ def __init__( ): super().__init__(config=config, verbose=verbose) - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self.read_timestamps = self._config.get("dataframe", {}).get( "read_timestamps", diff --git a/sed/loader/sxp/loader.py b/sed/loader/sxp/loader.py index e18a64f9..1c6d625e 100644 --- a/sed/loader/sxp/loader.py +++ b/sed/loader/sxp/loader.py @@ -14,8 +14,6 @@ import time from collections.abc import Sequence from functools import reduce -from logging import INFO -from logging import WARNING from pathlib import Path import dask.dataframe as dd @@ -30,6 +28,7 @@ from pandas import Series from sed.core import dfops +from sed.core.logging import set_verbosity from sed.core.logging import setup_logging from sed.loader.base.loader import BaseLoader from sed.loader.utils import parse_h5_keys @@ -57,10 +56,7 @@ class SXPLoader(BaseLoader): def __init__(self, config: dict, verbose: bool = True) -> None: super().__init__(config=config, verbose=verbose) - if self.verbose: - logger.handlers[0].setLevel(INFO) - else: - logger.handlers[0].setLevel(WARNING) + set_verbosity(logger, self.verbose) self.multi_index = ["trainId", "pulseId", "electronId"] self.index_per_electron: MultiIndex = None From 8716dc06c8b1efbe61fc24181d0fc70344c055fc Mon Sep 17 00:00:00 2001 From: rettigl Date: Thu, 19 Sep 2024 23:00:18 +0200 Subject: [PATCH 11/11] Make verbose a private property, and add getter and setters for it, to propagate verbosity --- sed/calibrator/delay.py | 23 ++++++++++++++++++++-- sed/calibrator/energy.py | 23 ++++++++++++++++++++-- sed/calibrator/momentum.py | 25 +++++++++++++++++++++--- sed/core/processor.py | 39 ++++++++++++++++++++++++++++++-------- sed/loader/base/loader.py | 20 ++++++++++++++++++- sed/loader/flash/loader.py | 21 +++++++++++++++++++- sed/loader/mpes/loader.py | 21 +++++++++++++++++++- sed/loader/sxp/loader.py | 21 +++++++++++++++++++- 8 files changed, 174 insertions(+), 19 deletions(-) diff --git a/sed/calibrator/delay.py b/sed/calibrator/delay.py index d465a462..000fe9cf 100644 --- a/sed/calibrator/delay.py +++ b/sed/calibrator/delay.py @@ -48,8 +48,8 @@ def __init__( else: self._config = {} - self.verbose = verbose - set_verbosity(logger, self.verbose) + self._verbose = verbose + set_verbosity(logger, self._verbose) self.adc_column: str = self._config["dataframe"].get("adc_column", None) self.delay_column: str = self._config["dataframe"]["delay_column"] @@ -60,6 +60,25 @@ def __init__( self.calibration: dict[str, Any] = self._config["delay"].get("calibration", {}) self.offsets: dict[str, Any] = self._config["delay"].get("offsets", {}) + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + def append_delay_axis( self, df: pd.DataFrame | dask.dataframe.DataFrame, diff --git a/sed/calibrator/energy.py b/sed/calibrator/energy.py index 1e50d745..e3e7d1ca 100644 --- a/sed/calibrator/energy.py +++ b/sed/calibrator/energy.py @@ -91,8 +91,8 @@ def __init__( self._config = config - self.verbose = verbose - set_verbosity(logger, self.verbose) + self._verbose = verbose + set_verbosity(logger, self._verbose) self.loader = loader self.biases: np.ndarray = None @@ -125,6 +125,25 @@ def __init__( self.offsets: dict[str, Any] = self._config["energy"].get("offsets", {}) self.correction: dict[str, Any] = self._config["energy"].get("correction", {}) + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + @property def ntraces(self) -> int: """Property returning the number of traces. diff --git a/sed/calibrator/momentum.py b/sed/calibrator/momentum.py index ac26f0e7..fed52473 100644 --- a/sed/calibrator/momentum.py +++ b/sed/calibrator/momentum.py @@ -79,8 +79,8 @@ def __init__( self._config = config - self.verbose = verbose - set_verbosity(logger, self.verbose) + self._verbose = verbose + set_verbosity(logger, self._verbose) self.image: np.ndarray = None self.img_ndim: int = None @@ -132,6 +132,25 @@ def __init__( self._state: int = 0 + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + @property def features(self) -> dict: """Dictionary of detected features for the symmetrization process. @@ -1241,7 +1260,7 @@ def apply_func(apply: bool): # noqa: ARG001 transformations["creation_date"] = datetime.now().timestamp() self.transformations = transformations - if self.verbose: + if self._verbose: plt.figure() subs = 20 plt.title("Final Deformation field") diff --git a/sed/core/processor.py b/sed/core/processor.py index ea3ac37e..e931d0a9 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -117,10 +117,10 @@ def __init__( logger.debug(f"Use {num_cores} cores for processing.") if verbose is None: - self.verbose = self._config["core"].get("verbose", True) + self._verbose = self._config["core"].get("verbose", True) else: - self.verbose = verbose - set_verbosity(logger, self.verbose) + self._verbose = verbose + set_verbosity(logger, self._verbose) self._dataframe: pd.DataFrame | ddf.DataFrame = None self._timed_dataframe: pd.DataFrame | ddf.DataFrame = None @@ -148,17 +148,17 @@ def __init__( verbose=verbose, ), config=self._config, - verbose=self.verbose, + verbose=self._verbose, ) self.mc = MomentumCorrector( config=self._config, - verbose=self.verbose, + verbose=self._verbose, ) self.dc = DelayCalibrator( config=self._config, - verbose=self.verbose, + verbose=self._verbose, ) self.use_copy_tool = self._config.get("core", {}).get( @@ -227,6 +227,29 @@ def _repr_html_(self): # """Provides an overview panel with plots of different data attributes.""" # self.view_event_histogram(dfpid=2, backend="matplotlib") + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + self.mc.verbose = verbose + self.ec.verbose = verbose + self.dc.verbose = verbose + self.loader.verbose = verbose + @property def dataframe(self) -> pd.DataFrame | ddf.DataFrame: """Accessor to the underlying dataframe. @@ -629,7 +652,7 @@ def generate_splinewarp( self.mc.spline_warp_estimate(use_center=use_center, **kwds) - if self.mc.slice is not None and self.verbose: + if self.mc.slice is not None and self._verbose: print("Original slice with reference features") self.mc.view(annotated=True, backend="bokeh", crosshair=True) @@ -1334,7 +1357,7 @@ def calibrate_energy_axis( energy_scale=energy_scale, **kwds, ) - if self.verbose: + if self._verbose: self.ec.view( traces=self.ec.traces_normed, xaxis=self.ec.calibration["axis"], diff --git a/sed/loader/base/loader.py b/sed/loader/base/loader.py index 0f898e09..d2848d23 100644 --- a/sed/loader/base/loader.py +++ b/sed/loader/base/loader.py @@ -42,7 +42,25 @@ def __init__( self.files: list[str] = [] self.runs: list[str] = [] self.metadata: dict[Any, Any] = {} - self.verbose = verbose + self._verbose = verbose + + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose @abstractmethod def read_dataframe( diff --git a/sed/loader/flash/loader.py b/sed/loader/flash/loader.py index b17621fd..9b3524bc 100644 --- a/sed/loader/flash/loader.py +++ b/sed/loader/flash/loader.py @@ -54,12 +54,31 @@ def __init__(self, config: dict, verbose: bool = True) -> None: """ super().__init__(config=config, verbose=verbose) - set_verbosity(logger, self.verbose) + set_verbosity(logger, self._verbose) self.instrument: str = self._config["core"].get("instrument", "hextof") # default is hextof self.raw_dir: str = None self.processed_dir: str = None + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + def _initialize_dirs(self) -> None: """ Initializes the directories on Maxwell based on configuration. If paths is provided in diff --git a/sed/loader/mpes/loader.py b/sed/loader/mpes/loader.py index c130308a..ebc9a08c 100644 --- a/sed/loader/mpes/loader.py +++ b/sed/loader/mpes/loader.py @@ -570,13 +570,32 @@ def __init__( ): super().__init__(config=config, verbose=verbose) - set_verbosity(logger, self.verbose) + set_verbosity(logger, self._verbose) self.read_timestamps = self._config.get("dataframe", {}).get( "read_timestamps", False, ) + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + def read_dataframe( self, files: str | Sequence[str] = None, diff --git a/sed/loader/sxp/loader.py b/sed/loader/sxp/loader.py index 1c6d625e..a77e8ed6 100644 --- a/sed/loader/sxp/loader.py +++ b/sed/loader/sxp/loader.py @@ -56,7 +56,7 @@ class SXPLoader(BaseLoader): def __init__(self, config: dict, verbose: bool = True) -> None: super().__init__(config=config, verbose=verbose) - set_verbosity(logger, self.verbose) + set_verbosity(logger, self._verbose) self.multi_index = ["trainId", "pulseId", "electronId"] self.index_per_electron: MultiIndex = None @@ -66,6 +66,25 @@ def __init__(self, config: dict, verbose: bool = True) -> None: self.raw_dir: str = None self.processed_dir: str = None + @property + def verbose(self) -> bool: + """Accessor to the verbosity flag. + + Returns: + bool: Verbosity flag. + """ + return self._verbose + + @verbose.setter + def verbose(self, verbose: bool): + """Setter for the verbosity. + + Args: + verbose (bool): Option to turn on verbose output. Sets loglevel to INFO. + """ + self._verbose = verbose + set_verbosity(logger, self._verbose) + def _initialize_dirs(self): """ Initializes the paths based on the configuration.