diff --git a/sed/calibrator/delay.py b/sed/calibrator/delay.py index 666acbb7..000fe9cf 100644 --- a/sed/calibrator/delay.py +++ b/sed/calibrator/delay.py @@ -13,6 +13,11 @@ 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 +logger = setup_logging("delay") class DelayCalibrator: @@ -22,22 +27,30 @@ 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 + 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"] self.corrected_delay_column = self._config["dataframe"].get( @@ -47,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, @@ -61,7 +93,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 +124,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 +157,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 +197,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 +210,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 +221,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 +245,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 +265,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 +329,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,15 +341,13 @@ def add_offsets( weights = [] preserve_mean = [] reductions = [] - if verbose: - print("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 verbose: - print(f" Constant: {constant} ") + log_str += f"\n Constant: {constant}" elif k == "flip_delay_axis": fda = str(v) if fda.lower() in ["true", "1"]: @@ -330,8 +358,7 @@ 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} ") + log_str += f"\n Flip delay axis: {flip_delay_axis}" else: columns.append(k) try: @@ -343,11 +370,13 @@ 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}, ", - 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..e3e7d1ca 100644 --- a/sed/calibrator/energy.py +++ b/sed/calibrator/energy.py @@ -28,15 +28,20 @@ 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 set_verbosity +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 +58,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 +69,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 +83,17 @@ 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 + set_verbosity(logger, self._verbose) + self.loader = loader self.biases: np.ndarray = None self.traces: np.ndarray = None @@ -85,11 +103,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", {}) @@ -112,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. @@ -276,6 +308,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 +426,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 +534,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 +557,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 +596,6 @@ def calibrate( ref_energy=ref_energy, t=t, energy_scale=energy_scale, - verbose=verbose, **kwds, ) elif method in ("lstsq", "lsqr"): @@ -584,7 +615,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 +665,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 +793,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 +811,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 +845,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 +901,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 +922,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 +1372,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 +1398,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 +1442,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 +1540,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 +1563,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 +1635,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 +1648,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 +1677,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 +1991,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 +2162,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 +2183,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 +2249,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/calibrator/momentum.py b/sed/calibrator/momentum.py index da70c55a..fed52473 100644 --- a/sed/calibrator/momentum.py +++ b/sed/calibrator/momentum.py @@ -32,6 +32,12 @@ from symmetrize import sym from symmetrize import tps +from sed.core.logging import set_verbosity +from sed.core.logging import setup_logging + +# Configure logging +logger = setup_logging("momentum") + class MomentumCorrector: """ @@ -44,6 +50,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 +60,7 @@ def __init__( bin_ranges: list[tuple] = None, rotsym: int = 6, config: dict = None, + verbose: bool = True, ): """Constructor of the MomentumCorrector class. @@ -62,12 +71,17 @@ 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 + set_verbosity(logger, self._verbose) + self.image: np.ndarray = None self.img_ndim: int = None self.slice: np.ndarray = None @@ -118,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. @@ -308,6 +341,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!") @@ -510,8 +545,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]), @@ -594,7 +629,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 +652,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 +679,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 +692,21 @@ 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 +816,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 +1074,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 +1088,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 +1134,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 +1225,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 +1233,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 +1244,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 +1260,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(), @@ -1509,10 +1532,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]) @@ -1659,6 +1682,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 +1698,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 +1741,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 +1758,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 +1778,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() @@ -1856,6 +1889,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. @@ -1875,6 +1909,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. @@ -1921,6 +1957,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/config.py b/sed/core/config.py index f359c426..22e60fe5 100644 --- a/sed/core/config.py +++ b/sed/core/config.py @@ -12,10 +12,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("config") + def parse_config( config: dict | str = None, @@ -65,7 +70,7 @@ def parse_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): @@ -76,7 +81,7 @@ def parse_config( 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): @@ -89,7 +94,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): @@ -107,14 +112,14 @@ 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 +159,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 +170,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/logging.py b/sed/core/logging.py index 8c4742a7..ad019dc8 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,18 @@ 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. + 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. Returns: logging.Logger: The configured logger instance. @@ -34,11 +40,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 +83,40 @@ 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") - - # 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 - logger.addHandler(file_handler) - # Capture warnings with the logging system logging.captureWarnings(True) 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) + 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) + + return new_func + + return log_call diff --git a/sed/core/processor.py b/sed/core/processor.py index 5644a1b3..e931d0a9 100644 --- a/sed/core/processor.py +++ b/sed/core/processor.py @@ -27,6 +27,9 @@ 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 set_verbosity +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 +42,9 @@ N_CPU = psutil.cpu_count() +# Configure logging +logger = setup_logging("processor") + class SedProcessor: """Processor class of sed. Contains wrapper functions defining a work flow for data @@ -59,10 +65,11 @@ 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. """ + @call_logger(logger) def __init__( self, metadata: dict = None, @@ -93,7 +100,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 @@ -107,11 +114,13 @@ 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 + self._verbose = verbose + set_verbosity(logger, self._verbose) self._dataframe: pd.DataFrame | ddf.DataFrame = None self._timed_dataframe: pd.DataFrame | ddf.DataFrame = None @@ -128,22 +137,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( @@ -158,6 +173,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 @@ -207,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. @@ -364,6 +407,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, @@ -450,6 +494,7 @@ def load( duplicate_policy="merge", ) + @call_logger(logger) def filter_column( self, column: str, @@ -492,6 +537,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, @@ -535,6 +581,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, @@ -588,10 +635,10 @@ 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, - verbose: bool = None, **kwds, ): """3. Step of the distortion correction workflow: Generate the correction @@ -600,16 +647,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) @@ -672,17 +715,17 @@ 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 + @call_logger(logger) def pose_adjustment( self, transformations: dict[str, Any] = None, 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 @@ -699,8 +742,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. @@ -708,9 +749,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: @@ -722,17 +760,17 @@ 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, ) # 4a. Save pose adjustment parameters to config file. + @call_logger(logger) def save_transformations( self, filename: str = None, @@ -763,13 +801,13 @@ 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 + @call_logger(logger) def apply_momentum_correction( self, preview: bool = False, - verbose: bool = None, **kwds, ): """Applies the distortion correction and pose adjustment (optional) @@ -778,8 +816,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. @@ -787,18 +823,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: - 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, **kwds, ) if ( @@ -808,7 +839,6 @@ def apply_momentum_correction( ): tdf, _ = self.mc.apply_corrections( self._timed_dataframe, - verbose=False, **kwds, ) @@ -828,13 +858,13 @@ 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 + @call_logger(logger) def calibrate_momentum_axes( self, point_a: np.ndarray | list[int] = None, @@ -916,14 +946,14 @@ 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 + @call_logger(logger) 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 @@ -935,19 +965,13 @@ 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"] 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, @@ -961,6 +985,7 @@ def apply_momentum_calibration( tdf, _ = self.mc.append_k_axis( df=self._timed_dataframe, calibration=calibration, + suppress_output=True, **kwds, ) @@ -980,13 +1005,13 @@ 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 + @call_logger(logger) def adjust_energy_correction( self, correction_type: str = None, @@ -1018,9 +1043,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,14 +1087,14 @@ 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 + @call_logger(logger) 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 @@ -1082,30 +1105,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: - 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, - 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, ) @@ -1120,13 +1136,13 @@ 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 + @call_logger(logger) def load_bias_series( self, binned_data: xr.DataArray | tuple[np.ndarray, np.ndarray, np.ndarray] = None, @@ -1190,6 +1206,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: @@ -1201,6 +1218,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!") @@ -1220,6 +1241,7 @@ def load_bias_series( ) # 2. extract ranges and get peak positions + @call_logger(logger) def find_bias_peaks( self, ranges: list[tuple] | tuple, @@ -1266,9 +1288,10 @@ def find_bias_peaks( mode=mode, radius=radius, ) - print(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, @@ -1277,7 +1300,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 @@ -1293,12 +1316,12 @@ def find_bias_peaks( ) # 3. Fit the energy calibration relation + @call_logger(logger) def calibrate_energy_axis( self, ref_energy: float, method: str = None, energy_scale: str = None, - verbose: bool = None, **kwds, ): """3. Step of the energy calibration workflow: Calculate the calibration @@ -1320,13 +1343,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"] @@ -1337,25 +1355,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], @@ -1363,12 +1384,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], @@ -1381,8 +1404,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. @@ -1419,15 +1443,15 @@ 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 + @call_logger(logger) def append_energy_axis( self, 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 @@ -1443,24 +1467,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: - 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, bias_voltage=bias_voltage, - verbose=verbose, **kwds, ) if self._timed_dataframe is not None and tof_column in self._timed_dataframe.columns: @@ -1468,7 +1485,7 @@ def append_energy_axis( df=self._timed_dataframe, calibration=calibration, bias_voltage=bias_voltage, - verbose=False, + suppress_output=True, **kwds, ) @@ -1485,11 +1502,11 @@ 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) + @call_logger(logger) def add_energy_offset( self, constant: float = None, @@ -1498,7 +1515,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. @@ -1516,15 +1532,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( @@ -1532,8 +1543,7 @@ def add_energy_offset( "Run `append_energy_axis()` first.", ) 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, @@ -1542,7 +1552,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( @@ -1553,6 +1562,7 @@ def add_energy_offset( weights=weights, reductions=reductions, preserve_mean=preserve_mean, + suppress_output=True, ) self._attributes.add( @@ -1568,9 +1578,9 @@ def add_energy_offset( else: raise ValueError("No dataframe loaded!") if preview: - print(self._dataframe.head(10)) - elif verbose: - print(self._dataframe) + logger.info(self._dataframe.head(10)) + else: + logger.info(self._dataframe) def save_energy_offset( self, @@ -1595,12 +1605,12 @@ 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}".') + @call_logger(logger) def append_tof_ns_axis( self, preview: bool = False, - verbose: bool = None, **kwds, ): """Convert time-of-flight channel steps to nanoseconds. @@ -1611,19 +1621,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: - 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,16 +1651,15 @@ 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) + @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. @@ -1666,18 +1669,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: - 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,18 +1700,17 @@ 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 + @call_logger(logger) def calibrate_delay_axis( self, 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 @@ -1727,20 +1723,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: - 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: @@ -1755,7 +1745,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: @@ -1763,7 +1752,7 @@ def calibrate_delay_axis( self._timed_dataframe, delay_range=delay_range, datafile=datafile, - verbose=False, + suppress_output=True, **kwds, ) @@ -1779,10 +1768,9 @@ 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.debug(self._dataframe) def save_delay_calibration( self, @@ -1821,6 +1809,7 @@ def save_delay_calibration( } save_config(config, filename, overwrite) + @call_logger(logger) def add_delay_offset( self, constant: float = None, @@ -1830,7 +1819,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. @@ -1849,22 +1837,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: - print("Adding delay offset to dataframe:") + logger.info("Adding delay offset to dataframe:") df, metadata = self.dc.add_offsets( df=self._dataframe, constant=constant, @@ -1874,7 +1856,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( @@ -1886,7 +1867,7 @@ def add_delay_offset( weights=weights, reductions=reductions, preserve_mean=preserve_mean, - verbose=False, + suppress_output=True, ) self._attributes.add( @@ -1900,10 +1881,9 @@ 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 +1912,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, @@ -1962,6 +1942,7 @@ def save_workflow_params( except (ValueError, AttributeError, KeyError): pass + @call_logger(logger) def add_jitter( self, cols: list[str] = None, @@ -2012,7 +1993,9 @@ 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}.") + @call_logger(logger) def add_time_stamped_data( self, dest_column: str, @@ -2085,7 +2068,9 @@ 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}.") + @call_logger(logger) def pre_binning( self, df_partitions: int | Sequence[int] = 100, @@ -2133,6 +2118,7 @@ def pre_binning( **kwds, ) + @call_logger(logger) def compute( self, bins: int | dict | tuple | list[int] | list[np.ndarray] | list[tuple] = 100, @@ -2264,9 +2250,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, @@ -2298,6 +2282,7 @@ def compute( return self._binned + @call_logger(logger) def get_normalization_histogram( self, axis: str = "delay", @@ -2462,6 +2447,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, ) diff --git a/sed/loader/base/loader.py b/sed/loader/base/loader.py index 4a9962d3..d2848d23 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,32 @@ 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 + + @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 1e9752eb..9b3524bc 100644 --- a/sed/loader/flash/loader.py +++ b/sed/loader/flash/loader.py @@ -17,35 +17,68 @@ 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 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) + + 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/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 ea5ea7fc..ebc9a08c 100644 --- a/sed/loader/mpes/loader.py +++ b/sed/loader/mpes/loader.py @@ -23,8 +23,13 @@ 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 +# Configure logging +logger = setup_logging("mpes_loader") + def hdf5_to_dataframe( files: Sequence[str], @@ -74,17 +79,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 +134,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.", ) @@ -183,18 +190,15 @@ def hdf5_to_timed_dataframe( if channel["dataset_key"] in test_proc: electron_channels.append(channel) column_names.append(name) - else: - print( - 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) @@ -236,12 +240,6 @@ def hdf5_to_timed_dataframe( ] dataframe = ddf.from_delayed(delayeds) - else: - print( - f"Entry \"{channel['dataset_key']}\" for channel \"{name}\" not found.", - "Skipping the channel.", - ) - return dataframe @@ -557,7 +555,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" @@ -567,14 +566,36 @@ class MpesLoader(BaseLoader): def __init__( self, config: dict = None, + verbose: bool = True, ): - super().__init__(config=config) + super().__init__(config=config, verbose=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, @@ -799,9 +820,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 +840,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 +850,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 +871,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 +922,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 +938,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 +959,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 +974,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/sed/loader/sxp/loader.py b/sed/loader/sxp/loader.py index 10213594..a77e8ed6 100644 --- a/sed/loader/sxp/loader.py +++ b/sed/loader/sxp/loader.py @@ -28,24 +28,36 @@ 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 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) + + set_verbosity(logger, self._verbose) + self.multi_index = ["trainId", "pulseId", "electronId"] self.index_per_electron: MultiIndex = None self.index_per_pulse: MultiIndex = None @@ -54,6 +66,25 @@ def __init__(self, config: dict) -> 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. 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: 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", ")" ] }, 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", ")" ] },