diff --git a/README.md b/README.md index 6f37d02bcd0..c5fd321daa5 100644 --- a/README.md +++ b/README.md @@ -409,4 +409,4 @@ know, please consider [joining the Ludwig Slack](https://join.slack.com/t/ludwig - [Slack](https://join.slack.com/t/ludwig-ai/shared_invite/zt-mrxo87w6-DlX5~73T2B4v_g6jj0pJcQ) - [Twitter](https://twitter.com/ludwig_ai) - [Medium](https://medium.com/ludwig-ai) -- [GitHub Issues](https://github.com/ludwig-ai/ludwig/issues) \ No newline at end of file +- [GitHub Issues](https://github.com/ludwig-ai/ludwig/issues) diff --git a/ludwig/automl/auto_tune_config.py b/ludwig/automl/auto_tune_config.py index e6686e20a99..ca680ce51f9 100644 --- a/ludwig/automl/auto_tune_config.py +++ b/ludwig/automl/auto_tune_config.py @@ -35,6 +35,8 @@ from ludwig.utils.defaults import merge_with_defaults from ludwig.utils.torch_utils import initialize_pytorch +logger = logging.getLogger(__name__) + # maps variable search space that can be modified to minimum permissible value for the range RANKED_MODIFIABLE_PARAM_LIST = { "tabnet": OrderedDict( @@ -228,7 +230,7 @@ def memory_tune_config(config, dataset, model_category, row_count, backend): if reduce_text_feature_max_length(config, training_set_metadata): reduce_text_feature_max_length(temp_config, training_set_metadata) mem_use = compute_memory_usage(temp_config, training_set_metadata, model_category) - logging.info(f"Checking model estimated mem use {mem_use} against memory size {max_memory}") + logger.info(f"Checking model estimated mem use {mem_use} against memory size {max_memory}") if mem_use <= max_memory: fits_in_memory = True break diff --git a/ludwig/automl/automl.py b/ludwig/automl/automl.py index 058dcc83271..f573b3ac6c7 100644 --- a/ludwig/automl/automl.py +++ b/ludwig/automl/automl.py @@ -58,6 +58,8 @@ raise ImportError(" ray is not installed. In order to use auto_train please run pip install ludwig[ray]") +logger = logging.getLogger(__name__) + OUTPUT_DIR = "." @@ -77,7 +79,7 @@ def best_trial_id(self) -> str: def best_model(self) -> Optional[LudwigModel]: checkpoint = self._experiment_analysis.best_checkpoint if checkpoint is None: - logging.warning("No best model found") + logger.warning("No best model found") return None if not _ray_113: diff --git a/ludwig/backend/datasource.py b/ludwig/backend/datasource.py index 88b8a78cd02..0f9a8c5ee72 100644 --- a/ludwig/backend/datasource.py +++ b/ludwig/backend/datasource.py @@ -110,7 +110,7 @@ def _read_file( try: data = get_bytes_obj_from_http_path(path) except urllib3.exceptions.HTTPError as e: - logging.warning(e) + logger.warning(e) data = None else: super_result = super()._read_file(f, path, **reader_args)[0] diff --git a/ludwig/benchmarking/benchmark.py b/ludwig/benchmarking/benchmark.py index 2a2d41c9554..356ad6a6251 100644 --- a/ludwig/benchmarking/benchmark.py +++ b/ludwig/benchmarking/benchmark.py @@ -11,6 +11,7 @@ from ludwig.utils.data_utils import load_yaml os.environ["TOKENIZERS_PARALLELISM"] = "false" +logger = logging.getLogger(__name__) def setup_experiment(experiment: Dict[str, str]) -> Dict[Any, Any]: @@ -32,7 +33,7 @@ def benchmark_one_local(experiment: Dict[str, str], export_artifacts_dict: Dict[ experiment: dictionary containing the dataset name, config path, and experiment name. export_artifacts_dict: dictionary containing an export boolean flag and a path to export to. """ - logging.info(f"\nRunning experiment *{experiment['experiment_name']}* on dataset *{experiment['dataset_name']}*") + logger.info(f"\nRunning experiment *{experiment['experiment_name']}* on dataset *{experiment['dataset_name']}*") # configuring backend and paths model_config = setup_experiment(experiment) diff --git a/ludwig/benchmarking/summary_dataclasses.py b/ludwig/benchmarking/summary_dataclasses.py index 95a3d7d3e83..7157aa0ee96 100644 --- a/ludwig/benchmarking/summary_dataclasses.py +++ b/ludwig/benchmarking/summary_dataclasses.py @@ -11,6 +11,8 @@ from ludwig.modules.metric_registry import get_metric_classes, metric_feature_registry # noqa: F401 from ludwig.utils.data_utils import load_json +logger = logging.getLogger(__name__) + @dataclass class MetricDiff: @@ -197,7 +199,7 @@ def export_metrics_diff_to_csv(metrics_diff: MetricsDiff, path: str): "Diff Percentage": diff_percentage, } ) - logging.info(f"Exported a CSV report to {path}") + logger.info(f"Exported a CSV report to {path}") def build_metrics_summary(experiment_local_directory: str) -> MetricsSummary: @@ -360,7 +362,7 @@ def export_resource_usage_diff_to_csv(resource_usage_diff: ResourceUsageDiff, pa "Diff Percentage": diff_percentage, } ) - logging.info(f"Exported a CSV report to {path}") + logger.info(f"Exported a CSV report to {path}") def average_runs(path_to_runs_dir: str) -> Dict[str, Union[int, float]]: diff --git a/ludwig/benchmarking/utils.py b/ludwig/benchmarking/utils.py index 4f681b4aa42..029c91c8f3a 100644 --- a/ludwig/benchmarking/utils.py +++ b/ludwig/benchmarking/utils.py @@ -18,6 +18,8 @@ from ludwig.utils.defaults import default_random_seed from ludwig.utils.fs_utils import get_fs_and_path +logger = logging.getLogger(__name__) + def load_from_module( dataset_module: Union[BaseDataset, ModuleType], output_feature: Dict[str, str], subsample_frac: float = 1 @@ -61,7 +63,7 @@ def export_artifacts(experiment: Dict[str, str], experiment_output_directory: st os.path.join("configs", experiment["config_path"]), os.path.join(export_full_path, CONFIG_YAML), ) - logging.info(f"Uploaded experiment artifact to\n\t{export_full_path}") + logger.info(f"Uploaded experiment artifact to\n\t{export_full_path}") except Exception: logging.exception( f"Failed to upload experiment artifacts for experiment *{experiment['experiment_name']}* on " diff --git a/ludwig/data/preprocessing.py b/ludwig/data/preprocessing.py index 7d44cabd3c3..d465f611195 100644 --- a/ludwig/data/preprocessing.py +++ b/ludwig/data/preprocessing.py @@ -107,6 +107,8 @@ REPARTITIONING_FEATURE_TYPES = {"image", "audio"} +logger = logging.getLogger(__name__) + class DataFormatPreprocessor(ABC): @staticmethod @@ -167,7 +169,7 @@ def preprocess_for_training( ): num_overrides = override_in_memory_flag(features, True) if num_overrides > 0: - logging.warning("Using in_memory = False is not supported " "with {} data format.".format("dict")) + logger.warning("Using in_memory = False is not supported " "with {} data format.".format("dict")) df_engine = backend.df_engine if dataset is not None: @@ -224,7 +226,7 @@ def preprocess_for_training( ): num_overrides = override_in_memory_flag(features, True) if num_overrides > 0: - logging.warning("Using in_memory = False is not supported " "with {} data format.".format("dataframe")) + logger.warning("Using in_memory = False is not supported " "with {} data format.".format("dataframe")) if isinstance(dataset, pd.DataFrame): dataset = backend.df_engine.from_pandas(dataset) @@ -1016,17 +1018,17 @@ def prepare_processed_data( if not training_set_metadata: raise ValueError("When providing HDF5 data, " "training_set_metadata must not be None.") - logging.info("Using full hdf5 and json") + logger.info("Using full hdf5 and json") if DATA_TRAIN_HDF5_FP not in training_set_metadata: - logging.warning( + logger.warning( "data_train_hdf5_fp not present in training_set_metadata. " "Adding it with the current HDF5 file path {}".format(not_none_set) ) training_set_metadata[DATA_TRAIN_HDF5_FP] = not_none_set elif training_set_metadata[DATA_TRAIN_HDF5_FP] != not_none_set: - logging.warning( + logger.warning( "data_train_hdf5_fp in training_set_metadata is {}, " "different from the current HDF5 file path {}. " "Replacing it".format(training_set_metadata[DATA_TRAIN_HDF5_FP], not_none_set) @@ -1099,7 +1101,7 @@ def build_dataset( # - In this case, the partitions should remain aligned throughout. # - Further, while the indices might not be globally unique, they should be unique within each partition. # - These two properties make it possible to do the join op within each partition without a global index. - logging.warning( + logger.warning( f"Dataset has {dataset_df.npartitions} partitions and feature types that cause repartitioning. " f"Resetting index to ensure globally unique indices." ) @@ -1109,7 +1111,7 @@ def build_dataset( sample_ratio = global_preprocessing_parameters["sample_ratio"] if sample_ratio < 1.0: - logging.debug(f"sample {sample_ratio} of data") + logger.debug(f"sample {sample_ratio} of data") dataset_df = dataset_df.sample(frac=sample_ratio) # If persisting DataFrames in memory is enabled, we want to do this after @@ -1132,13 +1134,13 @@ def build_dataset( for feature_config in feature_configs: dataset_cols[feature_config[COLUMN]] = dataset_df[feature_config[COLUMN]] - logging.debug("build preprocessing parameters") + logger.debug("build preprocessing parameters") feature_name_to_preprocessing_parameters = build_preprocessing_parameters( dataset_cols, feature_configs, global_preprocessing_parameters, backend, metadata=metadata ) # Happens after preprocessing parameters are built, so we can use precomputed fill values. - logging.debug("handle missing values") + logger.debug("handle missing values") # In some cases, there can be a (temporary) mismatch between the dtype of the column and the type expected by the # preprocessing config (e.g., a categorical feature represented as an int-like column). In particular, Dask @@ -1154,13 +1156,13 @@ def build_dataset( handle_missing_values(dataset_cols, feature_config, preprocessing_parameters) # Happens after missing values are handled to avoid NaN casting issues. - logging.debug("cast columns") + logger.debug("cast columns") cast_columns(dataset_cols, feature_configs, backend) for callback in callbacks or []: callback.on_build_metadata_start(dataset_df, mode) - logging.debug("build metadata") + logger.debug("build metadata") metadata = build_metadata( metadata, feature_name_to_preprocessing_parameters, dataset_cols, feature_configs, backend ) @@ -1171,7 +1173,7 @@ def build_dataset( for callback in callbacks or []: callback.on_build_data_start(dataset_df, mode) - logging.debug("build data") + logger.debug("build data") proc_cols = build_data(dataset_cols, feature_configs, metadata, backend, skip_save_processed_input) for callback in callbacks or []: @@ -1480,7 +1482,7 @@ def handle_missing_values(dataset_cols, feature, preprocessing_parameters): def load_hdf5(hdf5_file_path, preprocessing_params, backend, split_data=True, shuffle_training=False): # TODO dask: this needs to work with DataFrames - logging.info(f"Loading data from: {hdf5_file_path}") + logger.info(f"Loading data from: {hdf5_file_path}") def shuffle(df): return df.sample(frac=1).reset_index(drop=True) @@ -1500,7 +1502,7 @@ def shuffle(df): def load_metadata(metadata_file_path: str) -> Dict[str, Any]: - logging.info(f"Loading metadata from: {metadata_file_path}") + logger.info(f"Loading metadata from: {metadata_file_path}") training_set_metadata = data_utils.load_json(metadata_file_path) # TODO(travis): decouple config from training_set_metadata so we don't need to # upgrade it over time. @@ -1569,7 +1571,7 @@ def preprocess_for_training( if cache_results is not None: valid, *cache_values = cache_results if valid: - logging.info( + logger.info( "Found cached dataset and meta.json with the same filename " "of the dataset, using them instead" ) @@ -1579,7 +1581,7 @@ def preprocess_for_training( cached = True dataset = None else: - logging.info( + logger.info( "Found cached dataset and meta.json with the same filename " "of the dataset, but checksum don't match, " "if saving of processed input is not skipped " @@ -1627,25 +1629,25 @@ def preprocess_for_training( # cache the dataset if backend.cache.can_cache(skip_save_processed_input): with use_credentials(backend.cache.credentials): - logging.debug("cache processed data") + logger.debug("cache processed data") processed = cache.put(*processed) # set cached=True to ensure credentials are used correctly below cached = True training_set, test_set, validation_set, training_set_metadata = processed with use_credentials(backend.cache.credentials if cached else None): - logging.debug("create training dataset") + logger.debug("create training dataset") training_dataset = backend.dataset_manager.create(training_set, config, training_set_metadata) if not len(training_set): raise ValueError("Training data is empty following preprocessing.") validation_dataset = None if validation_set is not None: - logging.debug("create validation dataset") + logger.debug("create validation dataset") validation_dataset = backend.dataset_manager.create(validation_set, config, training_set_metadata) if not len(validation_dataset): # Validation dataset is empty. - logging.warning( + logger.warning( "Encountered empty validation dataset. If this is unintentional, please check the " "preprocessing configuration." ) @@ -1653,11 +1655,11 @@ def preprocess_for_training( test_dataset = None if test_set is not None: - logging.debug("create test dataset") + logger.debug("create test dataset") test_dataset = backend.dataset_manager.create(test_set, config, training_set_metadata) if not len(test_dataset): # Test dataset is empty. - logging.warning( + logger.warning( "Encountered empty test dataset. If this is unintentional, please check the " "preprocessing configuration." ) @@ -1698,8 +1700,8 @@ def _preprocess_file_for_training( if dataset: # Use data and ignore _train, _validation and _test. # Also ignore data and train set metadata needs preprocessing - logging.info("Using full raw dataset, no hdf5 and json file " "with the same name have been found") - logging.info("Building dataset (it may take a while)") + logger.info("Using full raw dataset, no hdf5 and json file " "with the same name have been found") + logger.info("Building dataset (it may take a while)") dataset_df = read_fn(dataset, backend.df_engine.df_lib) training_set_metadata[SRC] = dataset @@ -1720,8 +1722,8 @@ def _preprocess_file_for_training( # use data_train (including _validation and _test if they are present) # and ignore data and train set metadata # needs preprocessing - logging.info("Using training raw csv, no hdf5 and json " "file with the same name have been found") - logging.info("Building dataset (it may take a while)") + logger.info("Using training raw csv, no hdf5 and json " "file with the same name have been found") + logger.info("Building dataset (it may take a while)") concatenated_df = concatenate_files(training_set, validation_set, test_set, read_fn, backend) training_set_metadata[SRC] = training_set @@ -1755,16 +1757,16 @@ def _preprocess_file_for_training( else: raise ValueError("either data or data_train have to be not None") - logging.debug("split train-val-test") + logger.debug("split train-val-test") training_data, validation_data, test_data = split_dataset(data, preprocessing_params, backend, random_seed) if dataset and backend.is_coordinator() and not skip_save_processed_input: - logging.debug("writing split file") + logger.debug("writing split file") splits_df = concatenate_splits(training_data, validation_data, test_data, backend) split_fp = get_split_path(dataset or training_set) backend.df_engine.to_parquet(splits_df, split_fp, index=True) - logging.info("Building dataset: DONE") + logger.info("Building dataset: DONE") if preprocessing_params["oversample_minority"] or preprocessing_params["undersample_majority"]: training_data = balance_data(training_data, config["output_features"], preprocessing_params, backend) @@ -1791,10 +1793,10 @@ def _preprocess_df_for_training( """ if dataset is not None: # needs preprocessing - logging.info("Using full dataframe") + logger.info("Using full dataframe") elif training_set is not None: # needs preprocessing - logging.info("Using training dataframe") + logger.info("Using training dataframe") dataset = concatenate_df(training_set, validation_set, test_set, backend) # Data is pre-split, so we override whatever split policy the user specified @@ -1812,7 +1814,7 @@ def _preprocess_df_for_training( }, } - logging.info("Building dataset (it may take a while)") + logger.info("Building dataset (it may take a while)") data, training_set_metadata = build_dataset( dataset, @@ -1825,10 +1827,10 @@ def _preprocess_df_for_training( mode="training", ) - logging.debug("split train-val-test") + logger.debug("split train-val-test") training_set, validation_set, test_set = split_dataset(data, preprocessing_params, backend, random_seed) - logging.info("Building dataset: DONE") + logger.info("Building dataset: DONE") if preprocessing_params["oversample_minority"] or preprocessing_params["undersample_majority"]: training_set = balance_data(training_set, config["output_features"], preprocessing_params, backend) @@ -1870,7 +1872,7 @@ def preprocess_for_prediction( if data_format not in HDF5_FORMATS: num_overrides = override_in_memory_flag(config["input_features"], True) if num_overrides > 0: - logging.warning("Using in_memory = False is not supported " "with {} data format.".format(data_format)) + logger.warning("Using in_memory = False is not supported " "with {} data format.".format(data_format)) preprocessing_params = merge_config_preprocessing_with_feature_specific_defaults( config.get(PREPROCESSING, {}), config.get(DEFAULTS, {}) @@ -1907,7 +1909,7 @@ def preprocess_for_prediction( if cache_results is not None: valid, *cache_values = cache_results if valid: - logging.info( + logger.info( "Found cached dataset and meta.json with the same filename " "of the input file, using them instead" ) @@ -1941,7 +1943,7 @@ def preprocess_for_prediction( training_set_metadata[DATA_TRAIN_HDF5_FP] = new_hdf5_fp if split != FULL: - logging.debug("split train-val-test") + logger.debug("split train-val-test") training_set, validation_set, test_set = split_dataset(dataset, preprocessing_params, backend) if split == TRAINING: diff --git a/ludwig/data/split.py b/ludwig/data/split.py index f0944fdda80..e5eaecc445f 100644 --- a/ludwig/data/split.py +++ b/ludwig/data/split.py @@ -29,6 +29,7 @@ split_registry = Registry() default_random_seed = 42 +logger = logging.getLogger(__name__) TMP_SPLIT_COL = "__SPLIT__" @@ -171,7 +172,7 @@ def validate(self, config: Dict[str, Any]): features = config["input_features"] + config["output_features"] feature_names = {f[COLUMN] for f in features} if self.column not in feature_names: - logging.info( + logger.info( f"Stratify column {self.column} is not among the features. " f"Cannot establish if it is a binary or category" ) @@ -233,7 +234,7 @@ def validate(self, config: Dict[str, Any]): features = config["input_features"] + config["output_features"] feature_names = {f[COLUMN] for f in features} if self.column not in feature_names: - logging.info( + logger.info( f"Datetime split column {self.column} is not among the features. " f"Cannot establish if it is a valid datetime." ) diff --git a/ludwig/features/audio_feature.py b/ludwig/features/audio_feature.py index 9b75acdcd6a..d72a91b58de 100644 --- a/ludwig/features/audio_feature.py +++ b/ludwig/features/audio_feature.py @@ -165,7 +165,7 @@ def _process_in_memory( try: default_audio = get_default_audio([audio for audio in raw_audio if is_torch_audio_tuple(audio)]) except RuntimeError: - logging.info("Unable to process audio files provided") + logger.info("Unable to process audio files provided") raise RuntimeError raw_audio = df_engine.map_objects(raw_audio, lambda row: row if is_torch_audio_tuple(row) else default_audio) diff --git a/ludwig/features/h3_feature.py b/ludwig/features/h3_feature.py index 079f60114ee..b6c6bfa9519 100644 --- a/ludwig/features/h3_feature.py +++ b/ludwig/features/h3_feature.py @@ -80,7 +80,7 @@ def cast_column(column, backend): try: return column.astype(int) except ValueError: - logging.warning("H3Feature could not be read as int directly. Reading as float and converting to int.") + logger.warning("H3Feature could not be read as int directly. Reading as float and converting to int.") return column.astype(float).astype(int) @staticmethod diff --git a/ludwig/features/image_feature.py b/ludwig/features/image_feature.py index 6d8b4a7f0d5..917c1a80b89 100644 --- a/ludwig/features/image_feature.py +++ b/ludwig/features/image_feature.py @@ -204,7 +204,7 @@ def _read_image_if_bytes_obj_and_resize( img = torch.nn.functional.pad(img, [0, 0, 0, 0, 0, extra_channels]) if img_num_channels != num_channels: - logging.warning( + logger.warning( "Image has {} channels, where as {} " "channels are expected. Dropping/adding channels " "with 0s as appropriate".format(img_num_channels, num_channels) @@ -277,16 +277,16 @@ def _infer_number_of_channels(image_sample: List[torch.Tensor]): else: # Default case: use 3 channels. num_channels = 3 - logging.info(f"Inferring num_channels from the first {n_images} images.") - logging.info("\n".join([f" images with {k} channels: {v}" for k, v in sorted(channel_frequency.items())])) + logger.info(f"Inferring num_channels from the first {n_images} images.") + logger.info("\n".join([f" images with {k} channels: {v}" for k, v in sorted(channel_frequency.items())])) if num_channels == max(channel_frequency, key=channel_frequency.get): - logging.info( + logger.info( f"Using {num_channels} channels because it is the majority in sample. If an image with" f" a different depth is read, will attempt to convert to {num_channels} channels." ) else: - logging.info(f"Defaulting to {num_channels} channels.") - logging.info( + logger.info(f"Defaulting to {num_channels} channels.") + logger.info( "To explicitly set the number of channels, define num_channels in the preprocessing dictionary of " "the image input feature config." ) @@ -471,7 +471,7 @@ def add_feature_data( proc_df[feature_config[PROC_COLUMN]] = np.arange(num_images) if num_failed_image_reads > 0: - logging.warning( + logger.warning( f"Failed to read {num_failed_image_reads} images while preprocessing feature `{name}`. " "Using default image for these rows in the dataset." ) diff --git a/ludwig/hyperopt/run.py b/ludwig/hyperopt/run.py index 6309e8fe70f..1dae13f4371 100644 --- a/ludwig/hyperopt/run.py +++ b/ludwig/hyperopt/run.py @@ -43,6 +43,9 @@ class RayBackend: pass +logger = logging.getLogger(__name__) + + def hyperopt( config: Union[str, dict], dataset: Union[str, dict, pd.DataFrame] = None, @@ -204,9 +207,9 @@ def hyperopt( update_hyperopt_params_with_defaults(hyperopt_config) # print hyperopt config - logging.info("Hyperopt config") - logging.info(pformat(hyperopt_config, indent=4)) - logging.info("\n") + logger.info("Hyperopt config") + logger.info(pformat(hyperopt_config, indent=4)) + logger.info("\n") search_alg = hyperopt_config["search_alg"] executor = hyperopt_config[EXECUTOR] @@ -324,8 +327,8 @@ def hyperopt( dataset_statistics = generate_dataset_statistics(training_set, validation_set, test_set) - logging.info("\nDataset Statistics") - logging.info(tabulate(dataset_statistics, headers="firstrow", tablefmt="fancy_grid")) + logger.info("\nDataset Statistics") + logger.info(tabulate(dataset_statistics, headers="firstrow", tablefmt="fancy_grid")) for callback in callbacks or []: callback.on_hyperopt_preprocessing_end(experiment_name) @@ -377,13 +380,13 @@ def hyperopt( } save_hyperopt_stats(hyperopt_stats, results_directory) - logging.info(f"Hyperopt stats saved to: {results_directory}") + logger.info(f"Hyperopt stats saved to: {results_directory}") for callback in callbacks or []: callback.on_hyperopt_end(experiment_name) callback.on_hyperopt_finish(experiment_name) - logging.info("Finished hyperopt") + logger.info("Finished hyperopt") return hyperopt_results diff --git a/ludwig/models/inference.py b/ludwig/models/inference.py index d046da59a31..61569f3380c 100644 --- a/ludwig/models/inference.py +++ b/ludwig/models/inference.py @@ -24,6 +24,8 @@ if TYPE_CHECKING: from ludwig.models.base import BaseModel +logger = logging.getLogger(__name__) + class InferenceModule(nn.Module): """A nn.Module subclass that wraps the inference preprocessor, predictor, and postprocessor.""" @@ -97,7 +99,7 @@ def from_ludwig_model( ): """Create an InferenceModule from a trained LudwigModel.""" if device is None: - logging.info(f'No device specified. Loading using device "{DEVICE}".') + logger.info(f'No device specified. Loading using device "{DEVICE}".') device = DEVICE stage_to_module = _init_inference_stages_from_ludwig_model( @@ -121,7 +123,7 @@ def from_directory( ): """Create an InferenceModule from a directory containing a model, config, and training set metadata.""" if device is None: - logging.info(f'No device specified. Loading using device "{DEVICE}".') + logger.info(f'No device specified. Loading using device "{DEVICE}".') device = DEVICE stage_to_module = _init_inference_stages_from_directory(directory, device=device) @@ -237,7 +239,7 @@ def save_ludwig_model_for_inference( ) -> None: """Saves a LudwigModel (a BaseModel model, config, and training_set_metadata) for inference.""" if device is None: - logging.info(f'No device specified. Saving using device "{DEVICE}".') + logger.info(f'No device specified. Saving using device "{DEVICE}".') device = DEVICE stage_to_filenames = { @@ -253,16 +255,16 @@ def save_ludwig_model_for_inference( config_path = os.path.join(save_path, MODEL_HYPERPARAMETERS_FILE_NAME) if not os.path.exists(config_path): save_json(config_path, config) - logging.info(f"Saved model config to {config_path}") + logger.info(f"Saved model config to {config_path}") training_set_metadata_path = os.path.join(save_path, TRAIN_SET_METADATA_FILE_NAME) if not os.path.exists(training_set_metadata_path): save_json(training_set_metadata_path, training_set_metadata) - logging.info(f"Saved training set metadata to {training_set_metadata_path}") + logger.info(f"Saved training set metadata to {training_set_metadata_path}") for stage, module in stage_to_module.items(): module.save(os.path.join(save_path, stage_to_filenames[stage])) - logging.info(f"Saved torchscript module for {stage} to {stage_to_filenames[stage]}.") + logger.info(f"Saved torchscript module for {stage} to {stage_to_filenames[stage]}.") def _init_inference_stages_from_directory( diff --git a/ludwig/models/registry.py b/ludwig/models/registry.py index 201901c16a5..88b57f44977 100644 --- a/ludwig/models/registry.py +++ b/ludwig/models/registry.py @@ -3,12 +3,14 @@ from ludwig.constants import MODEL_ECD, MODEL_GBM from ludwig.models.ecd import ECD +logger = logging.getLogger(__name__) + def gbm(*args, **kwargs): try: from ludwig.models.gbm import GBM except ImportError: - logging.warning( + logger.warning( "Importing GBM requirements failed. Not loading GBM model type. " "If you want to use GBM, install Ludwig's 'tree' extra." ) diff --git a/ludwig/trainers/trainer.py b/ludwig/trainers/trainer.py index aa66b97dfde..5c2b5c7f687 100644 --- a/ludwig/trainers/trainer.py +++ b/ludwig/trainers/trainer.py @@ -840,7 +840,7 @@ def train(self, training_set, validation_set=None, test_set=None, save_path="mod if self.is_coordinator(): # ========== Save training progress ========== - logging.debug( + logger.debug( f"Epoch {progress_tracker.epoch} took: " f"{time_utils.strdelta((time.time()- start_time) * 1000.0)}." ) diff --git a/ludwig/trainers/trainer_lightgbm.py b/ludwig/trainers/trainer_lightgbm.py index 885b19f785b..76b31e64880 100644 --- a/ludwig/trainers/trainer_lightgbm.py +++ b/ludwig/trainers/trainer_lightgbm.py @@ -29,6 +29,8 @@ from ludwig.utils.misc_utils import set_random_seed from ludwig.utils.trainer_utils import append_metrics, get_new_progress_tracker, ProgressTracker +logger = logging.getLogger(__name__) + def iter_feature_metrics(features: LudwigFeatureDict) -> Iterable[Tuple[str, str]]: """Helper for iterating feature names and metric names.""" @@ -227,7 +229,7 @@ def run_evaluation( self.callback(lambda c: c.on_eval_start(self, progress_tracker, save_path)) if self.is_coordinator(): - logging.info(f"\nRunning evaluation for step: {progress_tracker.steps}, epoch: {progress_tracker.epoch}") + logger.info(f"\nRunning evaluation for step: {progress_tracker.steps}, epoch: {progress_tracker.epoch}") # ================ Eval ================ # init tables @@ -305,9 +307,9 @@ def run_evaluation( elapsed_time = (time.time() - start_time) * 1000.0 if self.is_coordinator(): - logging.debug(f"Evaluation took {time_utils.strdelta(elapsed_time)}\n") + logger.debug(f"Evaluation took {time_utils.strdelta(elapsed_time)}\n") for output_feature, table in tables.items(): - logging.info(tabulate(table, headers="firstrow", tablefmt="fancy_grid", floatfmt=".4f")) + logger.info(tabulate(table, headers="firstrow", tablefmt="fancy_grid", floatfmt=".4f")) # ================ Validation Logic ================ should_break = False @@ -421,13 +423,13 @@ def check_progress_on_validation( if self.is_coordinator() and not skip_save_model: self.model.save(save_path) - logging.info( + logger.info( f"Validation {validation_metric} on {validation_output_feature_name} improved, model saved.\n" ) progress_tracker.last_improvement = progress_tracker.steps - progress_tracker.last_improvement_steps if progress_tracker.last_improvement != 0 and self.is_coordinator(): - logging.info( + logger.info( f"Last improvement of {validation_output_feature_name} validation {validation_metric} happened " + f"{progress_tracker.last_improvement} step(s) ago.\n" ) @@ -447,7 +449,7 @@ def check_progress_on_validation( should_early_stop = self.horovod.allreduce(should_early_stop) if should_early_stop.item(): if self.is_coordinator(): - logging.info( + logger.info( "\nEARLY STOPPING due to lack of validation improvement. " f"It has been {progress_tracker.steps - progress_tracker.last_improvement_steps} step(s) since " f"last validation improvement.\n" @@ -526,7 +528,7 @@ def train( only_of = next(iter(output_features)) if self.validation_metric in metrics_names[only_of]: self._validation_field = only_of - logging.warning( + logger.warning( "Replacing 'combined' validation field " "with '{}' as the specified validation " "metric {} is invalid for 'combined' " @@ -603,16 +605,16 @@ def train( early_stopping_steps = self.boosting_rounds_per_checkpoint * self.early_stop if self.is_coordinator(): - logging.info( + logger.info( f"Training for {self.total_steps} boosting round(s), approximately " f"{int(self.total_steps / self.boosting_rounds_per_checkpoint)} round(s) of evaluation." ) - logging.info( + logger.info( f"Early stopping policy: {self.early_stop} round(s) of evaluation, or {early_stopping_steps} " f"boosting round(s).\n" ) - logging.info(f"Starting with step {progress_tracker.steps}") + logger.info(f"Starting with step {progress_tracker.steps}") progress_bar_config = { "desc": "Training", @@ -654,7 +656,7 @@ def train( if self.is_coordinator(): # ========== Save training progress ========== - logging.debug( + logger.debug( f"Epoch {progress_tracker.epoch} took: " f"{time_utils.strdelta((time.time()- start_time) * 1000.0)}." ) diff --git a/ludwig/utils/audio_utils.py b/ludwig/utils/audio_utils.py index b913d8bc559..fe97176cd76 100644 --- a/ludwig/utils/audio_utils.py +++ b/ludwig/utils/audio_utils.py @@ -26,6 +26,8 @@ from ludwig.utils.fs_utils import get_bytes_obj_from_path from ludwig.utils.types import TorchAudioTuple +logger = logging.getLogger(__name__) + # https://github.com/pytorch/audio/blob/main/torchaudio/csrc/sox/types.cpp AUDIO_EXTENSIONS = (".wav", ".amb", ".mp3", ".ogg", ".vorbis", ".flac", ".opus", ".sphere") @@ -68,7 +70,7 @@ def read_audio_from_bytes_obj(bytes_obj: bytes) -> Optional[TorchAudioTuple]: f = BytesIO(bytes_obj) return torchaudio.backend.sox_io_backend.load(f) except Exception as e: - logging.warning(e) + logger.warning(e) return None diff --git a/ludwig/utils/automl/utils.py b/ludwig/utils/automl/utils.py index c049e273b82..7c2cdd899c7 100644 --- a/ludwig/utils/automl/utils.py +++ b/ludwig/utils/automl/utils.py @@ -23,6 +23,8 @@ from ludwig.modules.metric_registry import metric_registry from ludwig.utils.defaults import default_combiner_type +logger = logging.getLogger(__name__) + def avg_num_tokens(field: Series) -> int: # sample a subset if dataframe is large @@ -68,7 +70,7 @@ def _add_transfer_config(base_config: Dict, ref_configs: Dict) -> Dict: min_dataset = dataset if min_dataset is not None: - logging.info("Transfer config from dataset {}".format(min_dataset["name"])) + logger.info("Transfer config from dataset {}".format(min_dataset["name"])) min_dataset_config = min_dataset[CONFIG] hyperopt_params = base_config[HYPEROPT][PARAMETERS] point_to_evaluate = {} @@ -136,7 +138,7 @@ def has_imbalanced_output(base_config, features_metadata) -> bool: for feature_metadata in features_metadata: if output_feature[NAME] == feature_metadata.name: if feature_metadata.imbalance_ratio < IMBALANCE_DETECTION_RATIO: - logging.info( + logger.info( f"Imbalance in {output_feature[NAME]}: minority/majority={feature_metadata.imbalance_ratio}" ) imbalanced_output = True diff --git a/ludwig/utils/calibration.py b/ludwig/utils/calibration.py index b1233f75582..37b211a77d2 100644 --- a/ludwig/utils/calibration.py +++ b/ludwig/utils/calibration.py @@ -26,6 +26,8 @@ from ludwig.constants import BINARY, CATEGORY from ludwig.utils.registry import DEFAULT_KEYS, Registry +logger = logging.getLogger(__name__) + calibration_registry = Registry() @@ -163,7 +165,7 @@ def train_calibration( # Calculate NLL and ECE before temperature scaling before_calibration_nll = nll_criterion(logits, one_hot_labels).item() before_calibration_ece = ece_criterion(logits, one_hot_labels).item() - logging.info( + logger.info( "Before temperature scaling:\n" " Negative log-likelihood: %.3f\n" " Expected Calibration Error: %.3f" % (before_calibration_nll, before_calibration_ece) @@ -183,8 +185,8 @@ def eval(): # Calculate NLL and ECE after temperature scaling after_calibration_nll = nll_criterion(self.scale_logits(logits), one_hot_labels).item() after_calibration_ece = ece_criterion(self.scale_logits(logits), one_hot_labels).item() - logging.info("Optimal temperature: %.3f" % self.temperature.item()) - logging.info( + logger.info("Optimal temperature: %.3f" % self.temperature.item()) + logger.info( "After temperature scaling:\n" " Negative log-likelihood: %.3f\n" " Expected Calibration Error: %.3f" % (after_calibration_nll, after_calibration_ece) @@ -192,7 +194,7 @@ def eval(): self.temperature.requires_grad = False # This should never happen, but if expected calibration error is higher after optimizing temperature, revert. if after_calibration_ece > before_calibration_ece: - logging.warning( + logger.warning( "Expected calibration error higher after scaling, " "reverting to temperature=%.3f." % original_temperature.item() ) @@ -253,7 +255,7 @@ def train_calibration( # Calculate NLL and ECE before temperature scaling before_calibration_nll = nll_criterion(logits, one_hot_labels).item() before_calibration_ece = ece_criterion(logits, one_hot_labels).item() - logging.info( + logger.info( "Before matrix scaling:\n" " Negative log-likelihood: %.3f\n" " Expected Calibration Error: %.3f" % (before_calibration_nll, before_calibration_ece) @@ -273,7 +275,7 @@ def eval(): # Calculate NLL and ECE after matrix scaling after_calibration_nll = nll_criterion(self.scale_logits(logits), one_hot_labels).item() after_calibration_ece = ece_criterion(self.scale_logits(logits), one_hot_labels).item() - logging.info( + logger.info( "After matrix scaling:\n" " Negative log-likelihood: %.3f\n" " Expected Calibration Error: %.3f" % (after_calibration_nll, after_calibration_ece) @@ -282,7 +284,7 @@ def eval(): self.b.requires_grad = False # This should never happen, but if expected calibration error is higher after optimizing matrix, revert. if after_calibration_ece > before_calibration_ece: - logging.warning("Expected calibration error higher after matrix scaling, reverting to identity.") + logger.warning("Expected calibration error higher after matrix scaling, reverting to identity.") with torch.no_grad(): self.w.data = torch.eye(self.num_classes) self.b.data = torch.zeros(self.num_classes) diff --git a/ludwig/utils/fs_utils.py b/ludwig/utils/fs_utils.py index 205c572da7f..f65dd5285b7 100644 --- a/ludwig/utils/fs_utils.py +++ b/ludwig/utils/fs_utils.py @@ -33,6 +33,8 @@ from filelock import FileLock from fsspec.core import split_protocol +logger = logging.getLogger(__name__) + def get_fs_and_path(url): protocol, path = split_protocol(url) @@ -67,14 +69,14 @@ def get_bytes_obj_from_path(path: str) -> Optional[bytes]: try: return get_bytes_obj_from_http_path(path) except Exception as e: - logging.warning(e) + logger.warning(e) return None else: try: with open_file(path) as f: return f.read() except OSError as e: - logging.warning(e) + logger.warning(e) return None @@ -93,7 +95,7 @@ def get_bytes_obj_from_http_path(path: str) -> bytes: if resp.status == 404: upgraded = upgrade_http(path) if upgraded: - logging.info(f"reading url {path} failed. upgrading to https and retrying") + logger.info(f"reading url {path} failed. upgrading to https and retrying") return get_bytes_obj_from_http_path(upgraded) else: raise urllib3.exceptions.HTTPError(f"reading url {path} failed and cannot be upgraded to https") diff --git a/ludwig/utils/tokenizers.py b/ludwig/utils/tokenizers.py index 2a73ac2cc0b..7aac4b8e453 100644 --- a/ludwig/utils/tokenizers.py +++ b/ludwig/utils/tokenizers.py @@ -1148,7 +1148,7 @@ def get_hf_tokenizer(pretrained_model_name_or_path, **kwargs): pretrained_model_name_or_path in PRETRAINED_VOCAB_FILES_MAP["vocab_file"] and pretrained_model_name_or_path not in SKIP_TORCHTEXT_BERT_HF_MODEL_NAMES ): - logging.info(f"Loading TorchText implementation of {pretrained_model_name_or_path} tokenizer") + logger.info(f"Loading TorchText implementation of {pretrained_model_name_or_path} tokenizer") vocab_file = PRETRAINED_VOCAB_FILES_MAP["vocab_file"][pretrained_model_name_or_path] init_kwargs = PRETRAINED_INIT_CONFIGURATION.get(pretrained_model_name_or_path, {}) return BERTTokenizer( @@ -1159,7 +1159,7 @@ def get_hf_tokenizer(pretrained_model_name_or_path, **kwargs): # If pretrained_model_name_or_path does not have a torchtext equivalent implementation, load the # HuggingFace implementation. - logging.info(f"Loading HuggingFace implementation of {pretrained_model_name_or_path} tokenizer") + logger.info(f"Loading HuggingFace implementation of {pretrained_model_name_or_path} tokenizer") return HFTokenizer(pretrained_model_name_or_path) diff --git a/ludwig/utils/trainer_utils.py b/ludwig/utils/trainer_utils.py index 945b98a2523..db19ea7866f 100644 --- a/ludwig/utils/trainer_utils.py +++ b/ludwig/utils/trainer_utils.py @@ -14,6 +14,8 @@ from ludwig.utils.data_utils import load_json, save_json from ludwig.utils.metric_utils import TrainerMetric +logger = logging.getLogger(__name__) + def initialize_trainer_metric_dict(output_features) -> Dict[str, Dict[str, List[TrainerMetric]]]: """Returns a dict of dict of metrics, output_feature_name -> metric_name -> List[TrainerMetric].""" @@ -219,7 +221,7 @@ def get_final_steps_per_checkpoint( # Cap steps_per_checkpoint at steps_per_epoch. if steps_per_checkpoint > steps_per_epoch: if should_log: - logging.info( + logger.info( f"Note: steps_per_checkpoint (was {steps_per_checkpoint}) is now set to the number of " f"steps per epoch: {steps_per_epoch}.\n" ) diff --git a/ludwig/visualize.py b/ludwig/visualize.py index 95bc582506d..5647b9cbb96 100644 --- a/ludwig/visualize.py +++ b/ludwig/visualize.py @@ -3889,7 +3889,7 @@ def cli(sys_argv): try: vis_func = visualizations_registry[args.visualization] except KeyError: - logging.info("Visualization argument not recognized") + logger.info("Visualization argument not recognized") raise vis_func(**vars(args)) diff --git a/tests/ludwig/utils/test_fs_utils.py b/tests/ludwig/utils/test_fs_utils.py index bf0e69e1db0..15a2e091a3f 100644 --- a/tests/ludwig/utils/test_fs_utils.py +++ b/tests/ludwig/utils/test_fs_utils.py @@ -8,10 +8,12 @@ from ludwig.utils.fs_utils import get_fs_and_path +logger = logging.getLogger(__name__) + def create_file(url): _, path = get_fs_and_path(url) - logging.info(f"saving url '{url}' to path '{path}'") + logger.info(f"saving url '{url}' to path '{path}'") with tempfile.TemporaryDirectory() as tmpdir: file_path = os.path.join(tmpdir, path) os.makedirs(os.path.dirname(file_path))