diff --git a/QEfficient/__init__.py b/QEfficient/__init__.py index 38ce0ca42e..eeb1b0ddf5 100644 --- a/QEfficient/__init__.py +++ b/QEfficient/__init__.py @@ -37,7 +37,9 @@ from QEfficient.peft import QEffAutoPeftModelForCausalLM from QEfficient.transformers.transform import transform from QEfficient.utils import custom_format_warning -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") # custom warning for the better logging experience warnings.formatwarning = custom_format_warning diff --git a/QEfficient/base/modeling_qeff.py b/QEfficient/base/modeling_qeff.py index e9213761d9..891657d1d1 100644 --- a/QEfficient/base/modeling_qeff.py +++ b/QEfficient/base/modeling_qeff.py @@ -7,7 +7,6 @@ import gc import inspect -import logging import shutil import subprocess import warnings @@ -45,8 +44,9 @@ to_named_specializations, ) from QEfficient.utils.export_utils import export_wrapper +from QEfficient.utils.logging_utils import QEFFLogger -logger = logging.getLogger(__name__) +logger = QEFFLogger.get_logger("INFRA") class QEFFBaseModel(ABC): @@ -382,6 +382,7 @@ def _export( raise e self.onnx_path = onnx_path + logger.info("Model export is finished and saved at: %s", onnx_path) return onnx_path def get_onnx_path( @@ -686,4 +687,5 @@ def _compile( logger.info("Hashed parameters exported successfully.") self.qpc_path = qpc_path + logger.info("Model compilation is finished and saved at: %s", qpc_path) return qpc_path diff --git a/QEfficient/base/pytorch_transforms.py b/QEfficient/base/pytorch_transforms.py index 812177eac2..6a5d64e96b 100644 --- a/QEfficient/base/pytorch_transforms.py +++ b/QEfficient/base/pytorch_transforms.py @@ -9,7 +9,9 @@ from torch import nn -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") class PytorchTransform: diff --git a/QEfficient/cloud/export.py b/QEfficient/cloud/export.py index a5e0b6e195..f50b78c5d0 100644 --- a/QEfficient/cloud/export.py +++ b/QEfficient/cloud/export.py @@ -12,7 +12,9 @@ from QEfficient.base.common import QEFFCommonLoader from QEfficient.utils import check_and_assign_cache_dir from QEfficient.utils.custom_yaml import generate_custom_io -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") # Specifically for Docker images. ROOT_DIR = os.path.dirname(os.path.abspath("")) diff --git a/QEfficient/cloud/infer.py b/QEfficient/cloud/infer.py index 3fa049a8ff..ab5dc194c7 100644 --- a/QEfficient/cloud/infer.py +++ b/QEfficient/cloud/infer.py @@ -17,7 +17,9 @@ from QEfficient.base.common import QEFFCommonLoader from QEfficient.utils import check_and_assign_cache_dir, load_hf_processor, load_hf_tokenizer -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") # TODO: Remove after adding support for VLM's compile and execute diff --git a/QEfficient/compile/compile_helper.py b/QEfficient/compile/compile_helper.py index 55dba0b12f..0abaa7ae9e 100644 --- a/QEfficient/compile/compile_helper.py +++ b/QEfficient/compile/compile_helper.py @@ -15,7 +15,9 @@ from QEfficient.compile.qnn_compiler import compile as qnn_compile from QEfficient.utils import constants from QEfficient.utils._utils import load_json, load_yaml, to_named_specializations -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") def create_and_dump_specializations( diff --git a/QEfficient/compile/qnn_compiler.py b/QEfficient/compile/qnn_compiler.py index a0054f0bdf..9ee16a3066 100644 --- a/QEfficient/compile/qnn_compiler.py +++ b/QEfficient/compile/qnn_compiler.py @@ -18,7 +18,9 @@ generate_qnn_specialization, ) from QEfficient.utils.hash_utils import to_hashable -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") class QNN: diff --git a/QEfficient/diffusers/models/transformers/transformer_flux.py b/QEfficient/diffusers/models/transformers/transformer_flux.py index 0492669db0..9ce7432230 100644 --- a/QEfficient/diffusers/models/transformers/transformer_flux.py +++ b/QEfficient/diffusers/models/transformers/transformer_flux.py @@ -20,7 +20,9 @@ ) from QEfficient.diffusers.models.modeling_utils import compute_blocked_attention, get_attention_blocking_config -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") def qeff_apply_rotary_emb( diff --git a/QEfficient/diffusers/pipelines/flux/pipeline_flux.py b/QEfficient/diffusers/pipelines/flux/pipeline_flux.py index eee79d8c72..8592605c12 100644 --- a/QEfficient/diffusers/pipelines/flux/pipeline_flux.py +++ b/QEfficient/diffusers/pipelines/flux/pipeline_flux.py @@ -38,7 +38,9 @@ set_execute_params, ) from QEfficient.generation.cloud_infer import QAICInferenceSession -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffFluxPipeline: diff --git a/QEfficient/diffusers/pipelines/pipeline_utils.py b/QEfficient/diffusers/pipelines/pipeline_utils.py index c20ee88665..ef606f6d68 100644 --- a/QEfficient/diffusers/pipelines/pipeline_utils.py +++ b/QEfficient/diffusers/pipelines/pipeline_utils.py @@ -16,7 +16,9 @@ from tqdm import tqdm from QEfficient.utils._utils import load_json -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") def calculate_compressed_latent_dimension(height: int, width: int, vae_scale_factor: int) -> int: diff --git a/QEfficient/diffusers/pipelines/wan/pipeline_wan.py b/QEfficient/diffusers/pipelines/wan/pipeline_wan.py index fa74d5b027..e061e86ead 100644 --- a/QEfficient/diffusers/pipelines/wan/pipeline_wan.py +++ b/QEfficient/diffusers/pipelines/wan/pipeline_wan.py @@ -37,7 +37,9 @@ ) from QEfficient.generation.cloud_infer import QAICInferenceSession from QEfficient.utils import constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffWanPipeline: diff --git a/QEfficient/diffusers/pipelines/wan/pipeline_wan_i2v.py b/QEfficient/diffusers/pipelines/wan/pipeline_wan_i2v.py index 0c302ca4b2..c4a8d0ccfa 100644 --- a/QEfficient/diffusers/pipelines/wan/pipeline_wan_i2v.py +++ b/QEfficient/diffusers/pipelines/wan/pipeline_wan_i2v.py @@ -41,7 +41,9 @@ ) from QEfficient.generation.cloud_infer import QAICInferenceSession from QEfficient.utils import constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffWanImageToVideoPipeline: diff --git a/QEfficient/exporter/export_hf_to_cloud_ai_100.py b/QEfficient/exporter/export_hf_to_cloud_ai_100.py index 2547d9db36..7b753b374f 100644 --- a/QEfficient/exporter/export_hf_to_cloud_ai_100.py +++ b/QEfficient/exporter/export_hf_to_cloud_ai_100.py @@ -20,7 +20,9 @@ from QEfficient.utils import load_hf_tokenizer from QEfficient.utils.constants import QEFF_MODELS_DIR, Constants from QEfficient.utils.generate_inputs import InputHandler -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") def convert_to_cloud_bertstyle( diff --git a/QEfficient/generation/embedding_handler.py b/QEfficient/generation/embedding_handler.py index 8ac2e1e588..5b64f18fc2 100644 --- a/QEfficient/generation/embedding_handler.py +++ b/QEfficient/generation/embedding_handler.py @@ -23,7 +23,9 @@ from QEfficient.generation.cloud_infer import QAICInferenceSession from QEfficient.utils import constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") class VisionHandler: diff --git a/QEfficient/generation/text_generation_inference.py b/QEfficient/generation/text_generation_inference.py index 4dffa1f7c5..47e542ccb3 100755 --- a/QEfficient/generation/text_generation_inference.py +++ b/QEfficient/generation/text_generation_inference.py @@ -19,9 +19,11 @@ from QEfficient.generation.cloud_infer import QAICInferenceSession from QEfficient.utils import padding_check_and_fix from QEfficient.utils.constants import Constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger from QEfficient.utils.sampler_utils import validate_sampler_inputs +logger = QEFFLogger.get_logger("INFRA") + @dataclass class PerfMetrics: @@ -1326,4 +1328,6 @@ def generate( generated_ids=self._qaic_model.generated_ids, perf_metrics=perf_metrics, ) + logger.info("Text generation finished") + QEFFLogger.print_table() return latency_stats diff --git a/QEfficient/generation/vlm_generation.py b/QEfficient/generation/vlm_generation.py index 892fc145c4..097d6c22a6 100644 --- a/QEfficient/generation/vlm_generation.py +++ b/QEfficient/generation/vlm_generation.py @@ -37,7 +37,9 @@ ) from QEfficient.utils import LRUCache from QEfficient.utils.constants import Constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") class VisionLanguageGeneration(QEffTextGenerationBase): diff --git a/QEfficient/peft/auto.py b/QEfficient/peft/auto.py index 2c1df37c5c..51c806a1df 100644 --- a/QEfficient/peft/auto.py +++ b/QEfficient/peft/auto.py @@ -6,7 +6,6 @@ # ---------------------------------------------------------------------------- import hashlib -import logging import warnings from typing import List, Optional, Union @@ -32,8 +31,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import get_padding_shape_from_config from QEfficient.utils.hash_utils import to_hashable +from QEfficient.utils.logging_utils import QEFFLogger -logger = logging.getLogger(__name__) +logger = QEFFLogger.get_logger("FT") class QEffAutoPeftModelForCausalLM(QEFFBaseModel): diff --git a/QEfficient/peft/lora/auto.py b/QEfficient/peft/lora/auto.py index 91a62ae51a..86c61184af 100644 --- a/QEfficient/peft/lora/auto.py +++ b/QEfficient/peft/lora/auto.py @@ -19,7 +19,9 @@ from QEfficient.peft.lora.pytorch_transforms import LoraModelInputsTransform, TargetModulesTransform from QEfficient.utils import constants, get_padding_shape_from_config from QEfficient.utils.hash_utils import to_hashable -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("FT") class QEffAutoLoraModelForCausalLM(QEFFAutoModelForCausalLM): diff --git a/QEfficient/transformers/modeling_utils.py b/QEfficient/transformers/modeling_utils.py index f9d7fe62cd..ba6abf856e 100644 --- a/QEfficient/transformers/modeling_utils.py +++ b/QEfficient/transformers/modeling_utils.py @@ -92,7 +92,7 @@ from QEfficient.customop import CustomRMSNormAIC from QEfficient.proxy.pytorch_transform import QeffProxyModuleTransform from QEfficient.utils.constants import MIN_MASKED_ATTENTION_VALUE -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger if TYPE_CHECKING: from QEfficient.base.modeling_qeff import QEFFBaseModel @@ -164,6 +164,8 @@ QEffWhisperPositionalEmbedding, ) +logger = QEFFLogger.get_logger("MODEL") + # Define a named tuple for ModelArchitectures # Required for the Automation tool ModelArchitectures = namedtuple("ModelArchitectures", ["architectures"]) diff --git a/QEfficient/transformers/models/gpt_oss/modeling_gpt_oss.py b/QEfficient/transformers/models/gpt_oss/modeling_gpt_oss.py index 6f805bfd4c..da136baf6a 100644 --- a/QEfficient/transformers/models/gpt_oss/modeling_gpt_oss.py +++ b/QEfficient/transformers/models/gpt_oss/modeling_gpt_oss.py @@ -39,7 +39,9 @@ from QEfficient.transformers.cache_utils import QEffHybridCacheForGPTOSS from QEfficient.transformers.modeling_attn_mask_utils import _create_causal_mask from QEfficient.utils.constants import MIN_MASKED_ATTENTION_VALUE -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffGptOssExperts(GptOssExperts): diff --git a/QEfficient/transformers/models/internvl/modeling_internvl.py b/QEfficient/transformers/models/internvl/modeling_internvl.py index 228b748a8b..04929c8fba 100644 --- a/QEfficient/transformers/models/internvl/modeling_internvl.py +++ b/QEfficient/transformers/models/internvl/modeling_internvl.py @@ -13,7 +13,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import IOInfo, get_padding_shape_from_config -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffInternEncoderWrapper(nn.Module): diff --git a/QEfficient/transformers/models/llava/modeling_llava.py b/QEfficient/transformers/models/llava/modeling_llava.py index dac3b19e61..847505742f 100644 --- a/QEfficient/transformers/models/llava/modeling_llava.py +++ b/QEfficient/transformers/models/llava/modeling_llava.py @@ -15,7 +15,9 @@ ) from QEfficient.utils._utils import IOInfo -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") BS = 1 FBS = 4 diff --git a/QEfficient/transformers/models/llava_next/modeling_llava_next.py b/QEfficient/transformers/models/llava_next/modeling_llava_next.py index 3822223ed2..e9864badcf 100755 --- a/QEfficient/transformers/models/llava_next/modeling_llava_next.py +++ b/QEfficient/transformers/models/llava_next/modeling_llava_next.py @@ -18,7 +18,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import IOInfo -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") BS = constants.ONNX_EXPORT_EXAMPLE_BATCH_SIZE FBS = constants.ONNX_EXPORT_EXAMPLE_FBS diff --git a/QEfficient/transformers/models/mistral3/modeling_mistral3.py b/QEfficient/transformers/models/mistral3/modeling_mistral3.py index eae4580c50..fe095331d5 100644 --- a/QEfficient/transformers/models/mistral3/modeling_mistral3.py +++ b/QEfficient/transformers/models/mistral3/modeling_mistral3.py @@ -21,7 +21,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import IOInfo, get_padding_shape_from_config -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") def custom_cumsum(tensor): diff --git a/QEfficient/transformers/models/modeling_auto.py b/QEfficient/transformers/models/modeling_auto.py index c5c50f1c7d..a5ef0192e6 100644 --- a/QEfficient/transformers/models/modeling_auto.py +++ b/QEfficient/transformers/models/modeling_auto.py @@ -76,9 +76,10 @@ get_padding_shape_from_config, ) from QEfficient.utils.check_ccl_specializations import process_ccl_specializations -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger from QEfficient.utils.sampler_utils import get_sampling_inputs_and_outputs +logger = QEFFLogger.get_logger("MODEL") CUSTOM_IO_DTYPE_MAP = { torch.float16: "float16", torch.bfloat16: "bfloat16", @@ -153,7 +154,7 @@ def from_pretrained(cls, pretrained_model_name_or_path: str, *args, **kwargs): logger.warning("Updating low_cpu_mem_usage=False") kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) - + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, *args, **kwargs) kwargs.update({"enable_proxy": enable_proxy} if enable_proxy else {}) @@ -315,7 +316,7 @@ def from_pretrained(cls, pretrained_model_name_or_path, pooling=None, *args, **k logger.warning("Updating low_cpu_mem_usage=False") kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) - + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, *args, **kwargs) # This is support models that should be classified to in a different auto class but transformers load them via this class @@ -695,7 +696,7 @@ def from_pretrained(cls, pretrained_model_name_or_path, *args, **kwargs): logger.warning("Updating low_cpu_mem_usage=False") kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) - + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, *args, **kwargs) kwargs.update({"enable_proxy": enable_proxy} if enable_proxy else {}) return cls(model, pretrained_model_name_or_path=pretrained_model_name_or_path, **kwargs) @@ -1271,7 +1272,7 @@ def from_pretrained(cls, pretrained_model_name_or_path: str, qaic_config: Option logger.warning("Updating low_cpu_mem_usage=False") kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) - + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, **kwargs) kwargs.update({"enable_proxy": enable_proxy} if enable_proxy else {}) @@ -2085,6 +2086,7 @@ def from_pretrained( config = AutoConfig.from_pretrained(pretrained_model_name_or_path, trust_remote_code=True) config._attn_implementation = "eager" config.vision_config.use_flash_attn = "false" + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, config, *args, **kwargs) kwargs.update({"enable_proxy": enable_proxy} if enable_proxy else {}) @@ -2697,6 +2699,7 @@ def from_pretrained( logger.warning("Updating low_cpu_mem_usage=False") kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, **kwargs) kwargs.update({"enable_proxy": enable_proxy} if enable_proxy else {}) @@ -2949,6 +2952,7 @@ def from_pretrained( kv_offload = kwargs.pop("kv_offload", None) kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, *args, **kwargs) if qaic_config is not None: qaic_config["pretrained_model_name_or_path"] = pretrained_model_name_or_path @@ -4209,7 +4213,7 @@ def from_pretrained(cls, pretrained_model_name_or_path, pooling=None, *args, **k logger.warning("Updating low_cpu_mem_usage=False") kwargs.update({"attn_implementation": "eager", "low_cpu_mem_usage": False}) - + logger.info("Initiating the model weight loading.") model = cls._hf_auto_class.from_pretrained(pretrained_model_name_or_path, *args, **kwargs) # This is support models that should be classified to in a different auto class but transformers load them via this class diff --git a/QEfficient/transformers/models/pytorch_transforms.py b/QEfficient/transformers/models/pytorch_transforms.py index 5ff06e6443..de9443c5fb 100644 --- a/QEfficient/transformers/models/pytorch_transforms.py +++ b/QEfficient/transformers/models/pytorch_transforms.py @@ -509,7 +509,9 @@ from QEfficient.transformers.post_processing import build_and_attach_mlp, model_type_registry from QEfficient.transformers.sampler.sampler import sampler_forward from QEfficient.transformers.spd.spd_transform_forward import tlm_forward -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") SPD_TARGET = "target" diff --git a/QEfficient/transformers/models/qwen2_5_vl/modeling_qwen2_5_vl.py b/QEfficient/transformers/models/qwen2_5_vl/modeling_qwen2_5_vl.py index da687e0ede..27995019d5 100644 --- a/QEfficient/transformers/models/qwen2_5_vl/modeling_qwen2_5_vl.py +++ b/QEfficient/transformers/models/qwen2_5_vl/modeling_qwen2_5_vl.py @@ -43,7 +43,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import IOInfo, get_padding_shape_from_config from QEfficient.utils.constants import MIN_MASKED_ATTENTION_VALUE -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") def qeff_prepare_mrope_cos_sin(cos, sin, position_ids): diff --git a/QEfficient/transformers/models/qwen3_vl/modeling_qwen3_vl.py b/QEfficient/transformers/models/qwen3_vl/modeling_qwen3_vl.py index 0995cc5bd0..b99090e13c 100644 --- a/QEfficient/transformers/models/qwen3_vl/modeling_qwen3_vl.py +++ b/QEfficient/transformers/models/qwen3_vl/modeling_qwen3_vl.py @@ -41,7 +41,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import IOInfo, get_padding_shape_from_config from QEfficient.utils.constants import MIN_MASKED_ATTENTION_VALUE -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") def qeff_apply_interleaved_mrope(freqs, mrope_section): diff --git a/QEfficient/transformers/models/qwen3_vl_moe/modeling_qwen3_vl_moe.py b/QEfficient/transformers/models/qwen3_vl_moe/modeling_qwen3_vl_moe.py index 976c80919b..c13a03f920 100644 --- a/QEfficient/transformers/models/qwen3_vl_moe/modeling_qwen3_vl_moe.py +++ b/QEfficient/transformers/models/qwen3_vl_moe/modeling_qwen3_vl_moe.py @@ -42,7 +42,9 @@ from QEfficient.utils import constants from QEfficient.utils._utils import IOInfo, get_padding_shape_from_config from QEfficient.utils.constants import MIN_MASKED_ATTENTION_VALUE -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") def qeff_apply_interleaved_mrope(freqs, mrope_section): diff --git a/QEfficient/transformers/quantizers/quantizer_awq.py b/QEfficient/transformers/quantizers/quantizer_awq.py index b7199a71ea..cf90271bbf 100644 --- a/QEfficient/transformers/quantizers/quantizer_awq.py +++ b/QEfficient/transformers/quantizers/quantizer_awq.py @@ -15,7 +15,9 @@ replace_linear_layer_with_target_layer, replace_quantization_scales, ) -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffAwqConfig(AwqConfig): diff --git a/QEfficient/transformers/quantizers/quantizer_compressed_tensors.py b/QEfficient/transformers/quantizers/quantizer_compressed_tensors.py index f7ecc5b218..55ecf52bed 100644 --- a/QEfficient/transformers/quantizers/quantizer_compressed_tensors.py +++ b/QEfficient/transformers/quantizers/quantizer_compressed_tensors.py @@ -15,7 +15,9 @@ from transformers.utils.quantization_config import CompressedTensorsConfig, QuantizationConfigMixin, QuantizationMethod from QEfficient.transformers.quantizers.quantizer_utils import blockwise_dequantize, get_keys_to_not_convert -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") FP8_DTYPE = torch.float8_e4m3fn diff --git a/QEfficient/transformers/quantizers/quantizer_gptq.py b/QEfficient/transformers/quantizers/quantizer_gptq.py index 8a0bea1a21..4117359f6f 100644 --- a/QEfficient/transformers/quantizers/quantizer_gptq.py +++ b/QEfficient/transformers/quantizers/quantizer_gptq.py @@ -15,7 +15,9 @@ repack_zeros, replace_linear_layer_with_target_layer, ) -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffGPTQConfig(GPTQConfig): diff --git a/QEfficient/transformers/quantizers/quantizer_mxfp4.py b/QEfficient/transformers/quantizers/quantizer_mxfp4.py index 44c255feb5..95386c2627 100644 --- a/QEfficient/transformers/quantizers/quantizer_mxfp4.py +++ b/QEfficient/transformers/quantizers/quantizer_mxfp4.py @@ -14,7 +14,9 @@ from transformers.utils.quantization_config import Mxfp4Config from QEfficient.transformers.quantizers.quantizer_utils import convert_moe_packed_tensors, get_keys_to_not_convert -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("MODEL") class QEffMxfp4GptOssExperts(nn.Module): diff --git a/QEfficient/transformers/transform.py b/QEfficient/transformers/transform.py index 11d7c1dfd4..4fde89039f 100644 --- a/QEfficient/transformers/transform.py +++ b/QEfficient/transformers/transform.py @@ -13,7 +13,9 @@ from QEfficient.base.modeling_qeff import QEFFBaseModel from QEfficient.transformers.cache_utils import QEffDynamicCache from QEfficient.transformers.modeling_utils import TransformersToQEffModulesDict -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") def replace_module_with_qeff_layers(model: nn.Module) -> None: diff --git a/QEfficient/utils/_utils.py b/QEfficient/utils/_utils.py index acc60aee13..21829bd7ac 100644 --- a/QEfficient/utils/_utils.py +++ b/QEfficient/utils/_utils.py @@ -28,7 +28,9 @@ from QEfficient.utils.constants import KWARGS_INCLUSION_LIST, QEFF_MODELS_DIR, Constants, QnnConstants from QEfficient.utils.hash_utils import json_serializable -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") class LRUCache: diff --git a/QEfficient/utils/check_ccl_specializations.py b/QEfficient/utils/check_ccl_specializations.py index b2f0ff9e7b..6dc8a2f74e 100644 --- a/QEfficient/utils/check_ccl_specializations.py +++ b/QEfficient/utils/check_ccl_specializations.py @@ -8,7 +8,9 @@ from typing import List, Tuple from QEfficient.utils import constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") # Better performance when context length is multiple of 1024 → map CL to the next multiple of 1024 diff --git a/QEfficient/utils/constants.py b/QEfficient/utils/constants.py index 339e4f4dac..a6ada868b4 100644 --- a/QEfficient/utils/constants.py +++ b/QEfficient/utils/constants.py @@ -316,3 +316,24 @@ class QnnConstants: }, "SKIP_QNN_CONVERTER_STEP": False, } + + +@dataclass +class LoggerConfig: + """ + Centralized logger configuration for the project. + - Keep all defaults here. + - Environment variable names are centralized to avoid magic strings. + """ + + # Environment variables + log_path_env: str = "QEFF_LOG_PATH" # optional: set log file path + log_level_env: str = "QEFF_LOG_LEVEL" # project-wide log level (e.g., DEBUG/INFO/WARN/ERROR) + + # Defaults + default_log_dir: str = os.path.expanduser("~/.cache/qefficient_logs") + default_level: str = "INFO" # default when env is not set + + # Rotating file behavior + max_bytes: int = 5 * 1024 * 1024 # 5 MB + backup_count: int = 10 # keep last 10 files diff --git a/QEfficient/utils/device_utils.py b/QEfficient/utils/device_utils.py index a76dfae8af..2e889f79a8 100644 --- a/QEfficient/utils/device_utils.py +++ b/QEfficient/utils/device_utils.py @@ -10,7 +10,9 @@ import subprocess from QEfficient.utils.constants import Constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") def is_networks_loaded(stdout): diff --git a/QEfficient/utils/export_utils.py b/QEfficient/utils/export_utils.py index 901484e724..4f6f13fbb1 100644 --- a/QEfficient/utils/export_utils.py +++ b/QEfficient/utils/export_utils.py @@ -16,9 +16,11 @@ from QEfficient.transformers.cache_utils import InvalidIndexProvider from QEfficient.utils.cache import QEFF_HOME from QEfficient.utils.hash_utils import create_export_hash -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger from QEfficient.utils.torch_patches import apply_torch_patches, undo_torch_patches +logger = QEFFLogger.get_logger("INFRA") + def export_wrapper(func): """ diff --git a/QEfficient/utils/logging_utils.py b/QEfficient/utils/logging_utils.py index d2086d830c..451d9a5449 100644 --- a/QEfficient/utils/logging_utils.py +++ b/QEfficient/utils/logging_utils.py @@ -5,54 +5,297 @@ # # ----------------------------------------------------------------------------- +import json import logging +import os +import threading +from datetime import datetime +from logging.handlers import RotatingFileHandler +from pathlib import Path +from typing import Any, Dict, Iterable, List, Optional, Tuple +from tabulate import tabulate -class QEffFormatter(logging.Formatter): +# Import centralized config +from QEfficient.utils.constants import LoggerConfig + + +class JSONNamespaceFormatter(logging.Formatter): """ - Formatter class used to set colors for printing different logging levels of messages on console. + Custom formatter to output log records in JSON format with metadata. """ - cyan: str = "\x1b[38;5;14m" - yellow: str = "\x1b[33;20m" - red: str = "\x1b[31;20m" - bold_red: str = "\x1b[31;1m" - reset: str = "\x1b[0m" - common_format: str = "%(levelname)s - %(name)s - %(message)s" # type: ignore - format_with_line_info = "%(levelname)s - %(name)s - %(message)s (%(filename)s:%(lineno)d)" # type: ignore - - FORMATS = { - logging.DEBUG: cyan + format_with_line_info + reset, - logging.INFO: cyan + common_format + reset, - logging.WARNING: yellow + common_format + reset, - logging.ERROR: red + format_with_line_info + reset, - logging.CRITICAL: bold_red + format_with_line_info + reset, - } - def format(self, record): - """ - Overriding the base class method to Choose format based on log level. - """ - log_fmt = self.FORMATS.get(record.levelno) - formatter = logging.Formatter(log_fmt) - return formatter.format(record) + log_record = { + "created": record.created, + "date": datetime.fromtimestamp(record.created).strftime("%Y-%m-%d"), + "time": datetime.fromtimestamp(record.created).strftime("%H:%M:%S"), + "level": record.levelname, + "namespace": getattr(record, "namespace", "default"), + "file": record.filename, + "line": record.lineno, + "message": record.getMessage(), + } + return json.dumps(log_record) -def create_logger() -> logging.Logger: +class QEFFLogger: """ - Creates a logger object with Colored QEffFormatter. + Singleton logger class for structured logging with namespace support. + + Project-wide behavior: + - A single log level is enforced using env `QEFF_LOG_LEVEL` (default = INFO). + - Log path resolved with priority: explicit arg > env `QEFF_LOG_PATH` > default dir + timestamp. """ - logger = logging.getLogger("QEfficient") - # create console handler and set level to debug - ch = logging.StreamHandler() - ch.setLevel(logging.INFO) - # define formatter - ch.setFormatter(QEffFormatter()) + _instance: Optional[logging.Logger] = None + _logfile: Optional[str] = None + _init_lock = threading.Lock() + + def __init__(self, loglevel: Optional[str] = None, log_path: Optional[str] = None): + """ + Initialize the logger instance with specified path. Level is globally controlled by env. + Args: + loglevel: kept for backward compatibility, but env `QEFF_LOG_LEVEL` takes precedence. + log_path: optional path to the log file (highest priority). + """ + with QEFFLogger._init_lock: + if QEFFLogger._instance is not None: + return + + # Determine effective log level: + # Priority: ENV(QEFF_LOG_LEVEL) -> arg(loglevel) -> LoggerConfig.default_level + env_level = os.environ.get(LoggerConfig.log_level_env) + effective_level_name = (env_level or loglevel or LoggerConfig.default_level).upper() + numeric_level = getattr(logging, effective_level_name, None) + if not isinstance(numeric_level, int): + raise ValueError(f"Invalid log level: {effective_level_name}") + self.loglevel = effective_level_name + + # Resolve log path (arg > env > default dir + timestamp) + env_path = os.environ.get(LoggerConfig.log_path_env) + self.log_path = self._resolve_log_path(log_path or env_path) + + # Initialize the base logger + self.logger = self._initialize_logger() + QEFFLogger._instance = self.logger + + @classmethod + def _resolve_log_path(cls, requested_path: Optional[str]) -> str: + """Resolve the final log file path from a user path or defaults.""" + timestamp = datetime.now().strftime("%Y%m%d_%H%M%S") + default_file = os.path.join(LoggerConfig.default_log_dir, f"QEFF_{timestamp}.log") + if not requested_path: + os.makedirs(LoggerConfig.default_log_dir, exist_ok=True) + return default_file + + path = Path(requested_path).expanduser() + if path.suffix.lower() == ".log": + path.parent.mkdir(parents=True, exist_ok=True) + return str(path) + + path.mkdir(parents=True, exist_ok=True) + return str(path / f"QEFF_{timestamp}.log") + + def _initialize_logger(self) -> logging.Logger: + """ + Set up the logger with rotating file handler and JSON formatter. + """ + QEFFLogger._logfile = self.log_path + + logger = logging.getLogger("QEFF_LOGGER") + logger.setLevel(getattr(logging, self.loglevel)) + logger.propagate = False + + # Avoid duplicate handlers if reinitialized in same process + for handler in logger.handlers[:]: + handler.close() + logger.removeHandler(handler) + + handler = RotatingFileHandler( + self.log_path, + maxBytes=LoggerConfig.max_bytes, + backupCount=LoggerConfig.backup_count, + ) + handler.setFormatter(JSONNamespaceFormatter()) + logger.addHandler(handler) + + return logger + + @classmethod + def get_logger( + cls, namespace: str, loglevel: Optional[str] = None, log_path: Optional[str] = None + ) -> logging.Logger: + """ + Retrieve a logger adapter with a specific namespace. + Note: project-wide level comes from env `QEFF_LOG_LEVEL` (default INFO). + """ + if cls._instance is None: + cls(loglevel, log_path) + return logging.LoggerAdapter(cls._instance, {"namespace": namespace}) + + @classmethod + def log(cls, level: str, namespace: str, msg: str, fn: str = "", lno: int = 0, func: str = ""): + """ + Log a message with specified level and metadata. + """ + if cls._instance is None: + raise RuntimeError("Logger has not been initialized. Call get_logger() first.") + + level_num = getattr(logging, level.upper(), None) + if not isinstance(level_num, int): + raise ValueError(f"Invalid log level: {level}") + + logger = logging.LoggerAdapter(cls._instance, {"namespace": namespace}) + logger.log(level_num, msg, stacklevel=2) + + @classmethod + def set_loglevel(cls, loglevel: Optional[str] = None): + """ + Update the log level of the logger at runtime. + Priority remains ENV > arg > default. + If ENV is set, it will continue to override; otherwise arg/default apply. + """ + if cls._instance is None: + raise RuntimeError("Logger has not been initialized yet. Call get_logger() first.") + + env_level = os.environ.get(LoggerConfig.log_level_env) + effective_level_name = (env_level or loglevel or LoggerConfig.default_level).upper() + numeric_level = getattr(logging, effective_level_name, None) + if not isinstance(numeric_level, int): + raise ValueError(f"Invalid log level: {effective_level_name}") + + cls._instance.setLevel(numeric_level) + + @classmethod + def close_logger(cls): + """ + Gracefully shut down the logger. + """ + if cls._instance: + handlers = cls._instance.handlers[:] + for handler in handlers: + handler.flush() + handler.close() + cls._instance.removeHandler(handler) + cls._instance = None + cls._logfile = None + + @classmethod + def _parse_dt(cls, date_str: str, time_str: str) -> datetime: + """Parse 'YYYY-MM-DD' and 'HH:MM:SS' into a datetime.""" + return datetime.strptime(f"{date_str} {time_str}", "%Y-%m-%d %H:%M:%S") + + @classmethod + def get_logfile_path(cls) -> Optional[str]: + """Return active log file path, if logger is initialized.""" + return cls._logfile + + @classmethod + def _iter_log_records(cls, path: str) -> Iterable[Dict[str, Any]]: + with open(path, "r", encoding="utf-8") as handle: + for raw in handle: + line = raw.strip() + if not line: + continue + try: + record = json.loads(line) + except json.JSONDecodeError: + continue + if isinstance(record, dict): + yield record + + @classmethod + def _get_record_timestamp(cls, record: Dict[str, Any]) -> Optional[datetime]: + created = record.get("created") + if isinstance(created, (float, int)): + return datetime.fromtimestamp(float(created)) + + date_str = record.get("date") + time_str = record.get("time") + if not date_str or not time_str: + return None + try: + return cls._parse_dt(str(date_str), str(time_str)) + except ValueError: + return None + + @classmethod + def _extract_milestone_times(cls, path: str) -> Dict[str, datetime]: + """ + Extract first occurrence timestamp for each milestone key from JSON log lines. + """ + milestone_patterns: Dict[str, Tuple[str, ...]] = { + "START_LOAD": ("initiating the model weight loading",), + "LOAD_DONE": ("pytorch transforms applied to model",), + "ONNX_SAVED": ("model export is finished and saved", "transformed onnx saved"), + "COMPILE_DONE": ("model compilation is finished and saved",), + "TEXT_DONE": ("text generation finished", "text generated finised"), + "TEXT_READY": ("specialization_file_path",), + } + + times: Dict[str, datetime] = {} + for record in cls._iter_log_records(path): + message = str(record.get("message", "")).lower() + timestamp = cls._get_record_timestamp(record) + if not timestamp: + continue + + for key, patterns in milestone_patterns.items(): + if key in times: + continue + if any(pattern in message for pattern in patterns): + times[key] = timestamp + break + return times + + @classmethod + def print_table(cls) -> bool: + """ + Parse the line-delimited JSON log in cls._logfile and print timing table with t1 as baseline (0.0s). + """ + path = cls._logfile + if not path: + return False + if not os.path.exists(path): + return False + + times = cls._extract_milestone_times(path) + if not times: + return False + + t_start = times.get("START_LOAD", min(times.values())) + t2 = times.get("LOAD_DONE", t_start) # end of loading + t3 = times.get("ONNX_SAVED", t2) # export end + t4 = times.get("COMPILE_DONE", t3) # compile end + t5 = times.get("TEXT_DONE", times.get("TEXT_READY", t4)) # text gen end + + # Keep boundaries monotonic for stable table output. + if t2 < t_start: + t2 = t_start + if t3 < t2: + t3 = t2 + if t4 < t3: + t4 = t3 + if t5 < t4: + t5 = t4 - logger.addHandler(ch) - return logger + def offset_seconds(t: datetime) -> float: + return (t - t_start).total_seconds() + o1 = 0.0 + o2 = offset_seconds(t2) + o3 = offset_seconds(t3) + o4 = offset_seconds(t4) + o5 = offset_seconds(t5) -# Define the logger object that can be used for logging purposes throughout the module. -logger = create_logger() + timing_data: List[List[Any]] = [ + ["Model Loading", max(0.0, o2 - o1)], + ["Model Exporting", max(0.0, o3 - o2)], + ["Model Compilation", max(0.0, o4 - o3)], + ["Text Generation", max(0.0, o5 - o4)], + ["Total Time", max(0.0, o5 - o1)], + ] + print("\n") + print(tabulate(timing_data, headers=["Step", "Time (s)"], tablefmt="github", floatfmt=".3f")) + return True diff --git a/QEfficient/utils/sampler_utils.py b/QEfficient/utils/sampler_utils.py index 82a0843bc5..aa0adb7a0e 100644 --- a/QEfficient/utils/sampler_utils.py +++ b/QEfficient/utils/sampler_utils.py @@ -11,7 +11,9 @@ from QEfficient.utils import constants from QEfficient.utils.constants import Constants -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") def validate_sampler_inputs( diff --git a/QEfficient/utils/torch_patches.py b/QEfficient/utils/torch_patches.py index 444c25bdf3..3fff6fdf38 100644 --- a/QEfficient/utils/torch_patches.py +++ b/QEfficient/utils/torch_patches.py @@ -11,6 +11,10 @@ import torch.onnx.utils as onnx_utils from torch import _C +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") + # Store original references before patching _original_setup_trace_module_map = onnx_utils._setup_trace_module_map _original_get_module_attributes = getattr(onnx_utils, "_get_module_attributes", None) diff --git a/pyproject.toml b/pyproject.toml index 9a3a639381..915abcdf36 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -44,6 +44,7 @@ dependencies = [ "tiktoken==0.12.0", "compressed-tensors==0.14.0", "torch==2.7.0; platform_machine=='aarch64'", + "tabulate==0.9.0", # Specifying torch cpu package URL per python version, update the list once pytorch releases whl for python>3.11 "torch@https://download.pytorch.org/whl/cpu/torch-2.4.1%2Bcpu-cp38-cp38-linux_x86_64.whl ; python_version=='3.8' and platform_machine=='x86_64'", "torch@https://download.pytorch.org/whl/cpu/torch-2.7.0%2Bcpu-cp39-cp39-manylinux_2_28_x86_64.whl ; python_version=='3.9' and platform_machine=='x86_64'", diff --git a/scripts/Jenkinsfile b/scripts/Jenkinsfile index c2ec8b2add..50af13cffd 100644 --- a/scripts/Jenkinsfile +++ b/scripts/Jenkinsfile @@ -81,6 +81,8 @@ pipeline { cd /efficient-transformers && . preflight_qeff/bin/activate && mkdir -p $PWD/Non_cli_qaic && + mkdir -p $PWD/Qeff_logs && + export QEFF_LOG_PATH=$PWD/Qeff_logs && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/Non_cli_qaic && pytest tests -m '(not on_qaic) and (not finetune) and ${TEST_FILTER}' --ignore tests/vllm --ignore tests/unit_test -n 4 --junitxml=tests/tests_log1.xml --durations=10 && @@ -99,6 +101,7 @@ pipeline { cd /efficient-transformers && . preflight_qeff/bin/activate && mkdir -p $PWD/Non_qaic_llm && + export QEFF_LOG_PATH=$PWD/Non_qaic_llm && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/Non_qaic_llm && pytest tests -m '(llm_model) and (not qnn) and ${TEST_FILTER}' --ignore tests/vllm --ignore tests/unit_test --junitxml=tests/tests_log2.xml --durations=10 && @@ -120,6 +123,8 @@ pipeline { cd /efficient-transformers && . preflight_qeff/bin/activate && mkdir -p $PWD/Non_qaic_feature && + mkdir -p $PWD/Qeff_logs && + export QEFF_LOG_PATH=$PWD/Qeff_logs && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/Non_qaic_feature && pytest tests -m '(on_qaic) and (feature) and (not qnn) and ${TEST_FILTER}' --ignore tests/transformers/sampler --ignore tests/vllm --ignore tests/unit_test --junitxml=tests/tests_log2_feature.xml --durations=10 && @@ -138,6 +143,8 @@ pipeline { cd /efficient-transformers && . preflight_qeff/bin/activate && mkdir -p $PWD/Non_cli_qaic_multimodal && + mkdir -p $PWD/Qeff_logs && + export QEFF_LOG_PATH=$PWD/Qeff_logs && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/Non_cli_qaic_multimodal && pytest tests -m '(multimodal) and (not qnn) and ${TEST_FILTER}' --ignore tests/vllm --ignore tests/unit_test --junitxml=tests/tests_log6.xml --durations=10 && @@ -157,6 +164,8 @@ pipeline { cd /efficient-transformers && . preflight_qeff/bin/activate && mkdir -p $PWD/Non_cli_qaic_diffusion && + mkdir -p $PWD/Qeff_logs && + export QEFF_LOG_PATH=$PWD/Qeff_logs && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/Non_cli_qaic_diffusion && export HF_HUB_CACHE=/huggingface_hub && @@ -179,6 +188,8 @@ pipeline { cd /efficient-transformers && . preflight_qeff/bin/activate && mkdir -p $PWD/cli && + mkdir -p $PWD/Qeff_logs && + export QEFF_LOG_PATH=$PWD/Qeff_logs && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/cli && pytest tests -m '(cli and not qnn) and (not finetune)' --ignore tests/vllm --ignore tests/unit_test --junitxml=tests/tests_log3.xml --durations=10 && @@ -202,6 +213,8 @@ pipeline { # pip install /opt/qti-aic/integrations/torch_qaic/py310/torch_qaic-0.1.0-cp310-cp310-linux_x86_64.whl && pip install torch==2.9.1 torchvision==0.24.1 torchaudio==2.9.1 --index-url https://download.pytorch.org/whl/cpu && mkdir -p $PWD/cli_qaic_finetuning && + mkdir -p $PWD/Qeff_logs && + export QEFF_LOG_PATH=$PWD/Qeff_logs && export TOKENIZERS_PARALLELISM=false && export QEFF_HOME=$PWD/cli_qaic_finetuning && pytest tests -m '(finetune)' --ignore tests/vllm --ignore tests/unit_test --junitxml=tests/tests_log_finetune.xml --durations=10 && diff --git a/scripts/perplexity_computation/calculate_perplexity.py b/scripts/perplexity_computation/calculate_perplexity.py index e2988a0ae2..d13f171f93 100644 --- a/scripts/perplexity_computation/calculate_perplexity.py +++ b/scripts/perplexity_computation/calculate_perplexity.py @@ -18,8 +18,9 @@ from transformers import AutoModelForCausalLM, AutoTokenizer from QEfficient.generation.cloud_infer import QAICInferenceSession +from QEfficient.utils.logging_utils import QEFFLogger -logger = logging.getLogger(__name__) +logger = QEFFLogger.get_logger("INFRA") # 1. Data Loading diff --git a/tests/conftest.py b/tests/conftest.py index 57d7a79213..321d1aaee4 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -13,7 +13,9 @@ from transformers import logging from QEfficient.utils.cache import QEFF_HOME -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") _QUICKCHECK_FILE = "tests/unit_test/models/test_model_quickcheck.py" _QUICKCHECK_SUMMARY = {} diff --git a/tests/transformers/models/audio_models/test_audio_embedding_models.py b/tests/transformers/models/audio_models/test_audio_embedding_models.py index 64dc06a595..82c613e557 100644 --- a/tests/transformers/models/audio_models/test_audio_embedding_models.py +++ b/tests/transformers/models/audio_models/test_audio_embedding_models.py @@ -139,7 +139,6 @@ def check_ctc_pytorch_vs_kv_vs_ort_vs_ai100( qnn_config: Optional[str] = None, compare_results: Optional[bool] = False, ): - replace_transformers_quantizers() model_config = {"model_name": model_name} model_config["n_layer"] = n_layer @@ -200,7 +199,6 @@ def check_ctc_pytorch_vs_kv_vs_ort_vs_ai100( @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_full_ctc_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) check_ctc_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, compare_results=True, manual_cleanup=manual_cleanup, num_devices=4 @@ -211,7 +209,6 @@ def test_full_ctc_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_few_ctc_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) check_ctc_pytorch_vs_kv_vs_ort_vs_ai100(model_name=model_name, n_layer=4, manual_cleanup=manual_cleanup) diff --git a/tests/transformers/models/audio_models/test_speech_seq2seq_models.py b/tests/transformers/models/audio_models/test_speech_seq2seq_models.py index 6509d02fe7..0c6fb29087 100644 --- a/tests/transformers/models/audio_models/test_speech_seq2seq_models.py +++ b/tests/transformers/models/audio_models/test_speech_seq2seq_models.py @@ -374,7 +374,6 @@ def check_seq2seq_pytorch_vs_kv_vs_ort_vs_ai100( @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_full_seq2seq_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) check_seq2seq_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, compare_results=True, manual_cleanup=manual_cleanup, num_devices=4 @@ -385,7 +384,6 @@ def test_full_seq2seq_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_few_seq2seq_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) check_seq2seq_pytorch_vs_kv_vs_ort_vs_ai100(model_name=model_name, n_layer=4, manual_cleanup=manual_cleanup) diff --git a/tests/transformers/models/causal_lm_models/check_causal_models.py b/tests/transformers/models/causal_lm_models/check_causal_models.py index cc2d074a08..f878acbe73 100644 --- a/tests/transformers/models/causal_lm_models/check_causal_models.py +++ b/tests/transformers/models/causal_lm_models/check_causal_models.py @@ -57,7 +57,6 @@ def check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( retain_full_kv: Optional[bool] = None, compare_results: bool = False, ): - torch.manual_seed(42) replace_transformers_quantizers() model_hf = load_hf_causal_lm_model(model_name, num_hidden_layers=n_layer, config=config) diff --git a/tests/transformers/models/causal_lm_models/test_causal_lm_blocking_hqkv.py b/tests/transformers/models/causal_lm_models/test_causal_lm_blocking_hqkv.py index 4bf067e7c4..0568939cd2 100644 --- a/tests/transformers/models/causal_lm_models/test_causal_lm_blocking_hqkv.py +++ b/tests/transformers/models/causal_lm_models/test_causal_lm_blocking_hqkv.py @@ -31,7 +31,6 @@ @pytest.mark.on_qaic @pytest.mark.parametrize("model_name", test_models_blockedKV[:1]) def test_full_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - HEAD_BLOCK_SIZE = 8 NUM_KV_BLOCKS = 2 NUM_Q_BLOCKS = 2 @@ -77,7 +76,6 @@ def test_full_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manu @pytest.mark.on_qaic @pytest.mark.parametrize("model_name", test_models_blockedKV[:1]) def test_few_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - HEAD_BLOCK_SIZE = 8 NUM_KV_BLOCKS = 2 NUM_Q_BLOCKS = 2 @@ -123,7 +121,6 @@ def test_few_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manua @pytest.mark.on_qaic @pytest.mark.parametrize("model_name", test_models_blockedKV[:1]) def test_dummy_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - HEAD_BLOCK_SIZE = 8 NUM_KV_BLOCKS = 2 NUM_Q_BLOCKS = 2 @@ -178,7 +175,6 @@ def test_dummy_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100(model_name, man @pytest.mark.on_qaic @pytest.mark.parametrize("model_name", test_models_blockedKV[:1]) def test_full_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cleanup): - HEAD_BLOCK_SIZE = 8 NUM_KV_BLOCKS = 2 NUM_Q_BLOCKS = 2 @@ -244,7 +240,6 @@ def test_full_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, m @pytest.mark.on_qaic @pytest.mark.parametrize("model_name", test_models_blockedKV[:1]) def test_few_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cleanup): - HEAD_BLOCK_SIZE = 8 NUM_KV_BLOCKS = 2 NUM_Q_BLOCKS = 2 @@ -310,7 +305,6 @@ def test_few_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, ma @pytest.mark.on_qaic @pytest.mark.parametrize("model_name", test_models_blockedKV[:1]) def test_dummy_causal_all_blocking_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cleanup): - HEAD_BLOCK_SIZE = 8 NUM_KV_BLOCKS = 2 NUM_Q_BLOCKS = 2 diff --git a/tests/transformers/models/causal_lm_models/test_causal_lm_models.py b/tests/transformers/models/causal_lm_models/test_causal_lm_models.py index 8dbb0915b8..8c61cdc98d 100644 --- a/tests/transformers/models/causal_lm_models/test_causal_lm_models.py +++ b/tests/transformers/models/causal_lm_models/test_causal_lm_models.py @@ -33,7 +33,6 @@ @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_causal) def test_full_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - if model_name in ModelConfig.FULL_MODEL_TESTS_TO_SKIP: pytest.skip(f"Skipping full model test for {model_name} due to resource constraints.") check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( @@ -55,7 +54,6 @@ def test_few_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup) @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_causal) def test_dummy_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - custom_config = model_config_dict[model_name] hf_config = AutoConfig.from_pretrained( model_name, @@ -89,7 +87,6 @@ def test_full_causal_lm_pytorch_vs_ort_vs_ai100_cb(model_name, manual_cleanup): @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_causal) def test_few_causal_lm_pytorch_vs_ort_vs_ai100_cb(model_name, manual_cleanup): - n_layer = get_custom_n_layers(model_name) check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, @@ -104,7 +101,6 @@ def test_few_causal_lm_pytorch_vs_ort_vs_ai100_cb(model_name, manual_cleanup): @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_causal) def test_dummy_causal_lm_pytorch_vs_ort_vs_ai100_cb(model_name, manual_cleanup): - custom_config = model_config_dict[model_name] hf_config = AutoConfig.from_pretrained( model_name, diff --git a/tests/transformers/models/causal_lm_models/test_causal_lm_pl1.py b/tests/transformers/models/causal_lm_models/test_causal_lm_pl1.py index b6641d7951..f5f2384e67 100644 --- a/tests/transformers/models/causal_lm_models/test_causal_lm_pl1.py +++ b/tests/transformers/models/causal_lm_models/test_causal_lm_pl1.py @@ -32,7 +32,6 @@ @pytest.mark.parametrize("model_name", test_models_pl1) @pytest.mark.parametrize("retain_full_kv", [True, False]) def test_full_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1(model_name, retain_full_kv, manual_cleanup): - if model_name == "gpt2" and retain_full_kv: pytest.skip("Skipping test for gpt2 with retain_full_kv=True as it is not supported.") @@ -52,7 +51,6 @@ def test_full_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1(model_name, retain_ful @pytest.mark.parametrize("model_name", test_models_pl1) @pytest.mark.parametrize("retain_full_kv", [True, False]) def test_few_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1(model_name, retain_full_kv, manual_cleanup): - if model_name == "gpt2" and retain_full_kv: pytest.skip("Skipping test for gpt2 with retain_full_kv=True as it is not supported.") torch.manual_seed(42) @@ -71,7 +69,6 @@ def test_few_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1(model_name, retain_full @pytest.mark.parametrize("model_name", test_models_pl1) @pytest.mark.parametrize("retain_full_kv", [True, False]) def test_dummy_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1(model_name, retain_full_kv, manual_cleanup): - if model_name == "gpt2" and retain_full_kv: pytest.skip("Skipping test for gpt2 with retain_full_kv=True as it is not supported.") @@ -97,7 +94,6 @@ def test_dummy_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1(model_name, retain_fu @pytest.mark.parametrize("model_name", test_models_pl1) @pytest.mark.parametrize("retain_full_kv", [True, False]) def test_full_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1_CB(model_name, retain_full_kv, manual_cleanup): - if model_name == "gpt2" and retain_full_kv: pytest.skip("Skipping test for gpt2 with retain_full_kv=True as it is not supported.") torch.manual_seed(42) @@ -117,7 +113,6 @@ def test_full_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1_CB(model_name, retain_ @pytest.mark.parametrize("model_name", test_models_pl1) @pytest.mark.parametrize("retain_full_kv", [True, False]) def test_few_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1_CB(model_name, retain_full_kv, manual_cleanup): - if model_name == "gpt2" and retain_full_kv: pytest.skip("Skipping test for gpt2 with retain_full_kv=True as it is not supported.") torch.manual_seed(42) @@ -137,7 +132,6 @@ def test_few_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1_CB(model_name, retain_f @pytest.mark.parametrize("model_name", test_models_pl1) @pytest.mark.parametrize("retain_full_kv", [True, False]) def test_dummy_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100_pl1_CB(model_name, retain_full_kv, manual_cleanup): - if model_name == "gpt2" and retain_full_kv: pytest.skip("Skipping test for gpt2 with retain_full_kv=True as it is not supported.") diff --git a/tests/transformers/models/causal_lm_models/test_causal_tlm_models.py b/tests/transformers/models/causal_lm_models/test_causal_tlm_models.py index 0b488a5037..9d02acbd29 100644 --- a/tests/transformers/models/causal_lm_models/test_causal_tlm_models.py +++ b/tests/transformers/models/causal_lm_models/test_causal_tlm_models.py @@ -32,7 +32,6 @@ @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_spd) def test_full_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, num_speculative_tokens=Constants.NUM_SPECULATIVE_TOKENS, @@ -46,7 +45,6 @@ def test_full_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanu @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_spd) def test_few_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - n_layer = get_custom_n_layers(model_name) check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, @@ -61,7 +59,6 @@ def test_few_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_spd) def test_dummy_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_cleanup): - custom_config = model_config_dict[model_name] hf_config = AutoConfig.from_pretrained( model_name, @@ -81,7 +78,6 @@ def test_dummy_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100(model_name, manual_clean @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_spd) def test_full_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cleanup): - check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, num_speculative_tokens=Constants.NUM_SPECULATIVE_TOKENS, @@ -96,7 +92,6 @@ def test_full_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cle @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_spd) def test_few_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cleanup): - n_layer = get_custom_n_layers(model_name) check_causal_lm_pytorch_vs_kv_vs_ort_vs_ai100( model_name=model_name, @@ -112,7 +107,6 @@ def test_few_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_clea @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models_spd) def test_dummy_causal_tlm_pytorch_vs_kv_vs_ort_vs_ai100_CB(model_name, manual_cleanup): - custom_config = model_config_dict[model_name] hf_config = AutoConfig.from_pretrained( model_name, diff --git a/tests/transformers/models/causal_lm_models/test_fp16_causal_lm.py b/tests/transformers/models/causal_lm_models/test_fp16_causal_lm.py index 2ff366ece2..af8c3b70f0 100644 --- a/tests/transformers/models/causal_lm_models/test_fp16_causal_lm.py +++ b/tests/transformers/models/causal_lm_models/test_fp16_causal_lm.py @@ -127,7 +127,6 @@ def check_causal_lm_pytorch_vs_kv_vs_ai100( @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_full_fp16_causal_lm_pytorch_vs_kv_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) check_causal_lm_pytorch_vs_kv_vs_ai100( model_name=model_name, torch_dtype=torch.float16, manual_cleanup=manual_cleanup @@ -139,7 +138,6 @@ def test_full_fp16_causal_lm_pytorch_vs_kv_vs_ai100(model_name, manual_cleanup): @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_few_fp16_causal_lm_pytorch_vs_kv_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) n_layer = get_custom_n_layers(model_name) check_causal_lm_pytorch_vs_kv_vs_ai100( @@ -152,7 +150,6 @@ def test_few_fp16_causal_lm_pytorch_vs_kv_vs_ai100(model_name, manual_cleanup): @pytest.mark.llm_model @pytest.mark.parametrize("model_name", test_models) def test_dummy_fp16_causal_lm_pytorch_vs_kv_vs_ai100(model_name, manual_cleanup): - torch.manual_seed(42) custom_config = model_config_dict[model_name] hf_config = AutoConfig.from_pretrained( diff --git a/tests/transformers/models/image_text_to_text/test_custom_dtype.py b/tests/transformers/models/image_text_to_text/test_custom_dtype.py index 95f62f1ac9..f291c5d12c 100644 --- a/tests/transformers/models/image_text_to_text/test_custom_dtype.py +++ b/tests/transformers/models/image_text_to_text/test_custom_dtype.py @@ -41,7 +41,6 @@ def test_full_image_text_to_text_pytorch_vs_kv_vs_ort_vs_ai100_custom_dtype( model_name, kv_offload, torch_dtype, manual_cleanup ): - if model_name in ModelConfig.SKIPPED_MODELS: pytest.skip("Test skipped for this model due to some issues.") if model_name in ModelConfig.DUAL_QPC_MODELS and not kv_offload: @@ -65,7 +64,6 @@ def test_full_image_text_to_text_pytorch_vs_kv_vs_ort_vs_ai100_custom_dtype( def test_few_image_text_to_text_pytorch_vs_kv_vs_ort_vs_ai100_custom_dtype( model_name, kv_offload, torch_dtype, manual_cleanup ): - if model_name in ModelConfig.SKIPPED_MODELS: pytest.skip("Test skipped for this model due to some issues.") if model_name in ModelConfig.DUAL_QPC_MODELS and not kv_offload: diff --git a/tests/transformers/subfunction/test_causal_lm_blocking_subfunction.py b/tests/transformers/subfunction/test_causal_lm_blocking_subfunction.py index 5c58508385..b3f42e1b0c 100644 --- a/tests/transformers/subfunction/test_causal_lm_blocking_subfunction.py +++ b/tests/transformers/subfunction/test_causal_lm_blocking_subfunction.py @@ -64,7 +64,6 @@ def check_blockedKV_onnx_function_count_with_subfunction( @pytest.mark.feature @pytest.mark.parametrize("model_name", test_models_blockedKV) def test_full_blockedKV_onnx_function_count_with_subfunction(model_name, manual_cleanup): - # Keep model small for test runtime, and avoid CB path (not needed for function count). check_blockedKV_onnx_function_count_with_subfunction(model_name, manual_cleanup=manual_cleanup) @@ -73,7 +72,6 @@ def test_full_blockedKV_onnx_function_count_with_subfunction(model_name, manual_ @pytest.mark.feature @pytest.mark.parametrize("model_name", test_models_blockedKV) def test_few_blockedKV_onnx_function_count_with_subfunction(model_name, manual_cleanup): - # Keep model small for test runtime, and avoid CB path (not needed for function count). n_layer = get_custom_n_layers(model_name) @@ -84,7 +82,6 @@ def test_few_blockedKV_onnx_function_count_with_subfunction(model_name, manual_c @pytest.mark.feature @pytest.mark.parametrize("model_name", test_models_blockedKV) def test_dummy_blockedKV_onnx_function_count_with_subfunction(model_name, manual_cleanup): - # Keep model small for test runtime, and avoid CB path (not needed for function count). hf_config = AutoConfig.from_pretrained( model_name, diff --git a/tests/transformers/subfunction/test_subfunction_vlm.py b/tests/transformers/subfunction/test_subfunction_vlm.py index baf690e638..39e2c6d0ac 100644 --- a/tests/transformers/subfunction/test_subfunction_vlm.py +++ b/tests/transformers/subfunction/test_subfunction_vlm.py @@ -50,7 +50,6 @@ def check_image_text_to_text_subfunction_core( num_devices: int = 1, config: Optional[AutoConfig] = None, ): - img_size = model_config_dict[model_name]["img_size"] img_url = model_config_dict[model_name]["img_url"] query = model_config_dict[model_name]["text_prompt"] @@ -117,7 +116,6 @@ def check_image_text_to_text_subfunction_core( @pytest.mark.parametrize("model_name", test_mm_models) @pytest.mark.parametrize("kv_offload", [True]) def test_full_image_text_to_text_subfunction(model_name, kv_offload, manual_cleanup): - torch.manual_seed(42) check_image_text_to_text_subfunction_core(model_name, kv_offload=kv_offload, manual_cleanup=manual_cleanup) @@ -127,7 +125,6 @@ def test_full_image_text_to_text_subfunction(model_name, kv_offload, manual_clea @pytest.mark.parametrize("model_name", test_mm_models) @pytest.mark.parametrize("kv_offload", [True]) def test_few_image_text_to_text_subfunction(model_name, kv_offload, manual_cleanup): - torch.manual_seed(42) check_image_text_to_text_subfunction_core( model_name, @@ -142,7 +139,6 @@ def test_few_image_text_to_text_subfunction(model_name, kv_offload, manual_clean @pytest.mark.parametrize("model_name", test_mm_models) @pytest.mark.parametrize("kv_offload", [True]) def test_dummy_image_text_to_text_subfunction(model_name, kv_offload, manual_cleanup): - torch.manual_seed(42) hf_config = AutoConfig.from_pretrained( model_name, trust_remote_code=True, **model_config_dict[model_name].get("additional_params", {}) diff --git a/tests/transformers/test_pytorch_transforms.py b/tests/transformers/test_pytorch_transforms.py index eb05b3f95e..7bc890ea7d 100644 --- a/tests/transformers/test_pytorch_transforms.py +++ b/tests/transformers/test_pytorch_transforms.py @@ -20,7 +20,9 @@ from QEfficient.transformers.quantizers.quant_transforms import AwqToMatmulNbitsTransform, GPTQToMatmulNbitsTransform from QEfficient.transformers.spd.turbo import ResBlock from QEfficient.utils._utils import get_padding_shape_from_config -from QEfficient.utils.logging_utils import logger +from QEfficient.utils.logging_utils import QEFFLogger + +logger = QEFFLogger.get_logger("INFRA") KVCacheTransformTestConfigs = [ ("llama", 3, 32, 128, {"num_key_value_heads": 8, "intermediate_size": 512}, 0.8), diff --git a/tests/utils/test_logger.py b/tests/utils/test_logger.py new file mode 100644 index 0000000000..6e27e44809 --- /dev/null +++ b/tests/utils/test_logger.py @@ -0,0 +1,67 @@ +# ----------------------------------------------------------------------------- +# +# Copyright (c) Qualcomm Technologies, Inc. and/or its subsidiaries. +# SPDX-License-Identifier: BSD-3-Clause +# +# ----------------------------------------------------------------------------- + +import json +import time + +import pytest + +from QEfficient.utils.logging_utils import QEFFLogger + + +@pytest.fixture(autouse=True) +def reset_logger_state(): + QEFFLogger.close_logger() + yield + QEFFLogger.close_logger() + # Keep process-global logger initialized for tests importing module-level adapters. + QEFFLogger.get_logger("INFRA") + + +def test_logger_writes_json_records(tmp_path): + logger = QEFFLogger.get_logger("model", "DEBUG", str(tmp_path)) + logger.info("hello logger") + logger.warning("warning logger") + + log_path = QEFFLogger.get_logfile_path() + assert log_path is not None + + QEFFLogger.close_logger() + with open(log_path, "r", encoding="utf-8") as handle: + rows = [json.loads(line) for line in handle if line.strip()] + + assert len(rows) >= 2 + assert rows[-1]["namespace"] == "model" + assert rows[-1]["level"] == "WARNING" + assert rows[-1]["message"] == "warning logger" + assert isinstance(rows[-1]["created"], float) + + +def test_print_table_from_logged_milestones(tmp_path, capsys): + logger = QEFFLogger.get_logger("infra", "INFO", str(tmp_path)) + logger.info("Initiating the model weight loading.") + time.sleep(0.01) + logger.info("Pytorch transforms applied to model: test") + time.sleep(0.01) + logger.info("Model export is finished and saved at: /tmp/model.onnx") + time.sleep(0.01) + logger.info("Model compilation is finished and saved at: /tmp/model.qpc") + time.sleep(0.01) + logger.info("Text generation finished") + + assert QEFFLogger.print_table() is True + output = capsys.readouterr().out + assert "Model Loading" in output + assert "Model Exporting" in output + assert "Model Compilation" in output + assert "Text Generation" in output + assert "Total Time" in output + + +def test_print_table_without_log_file_returns_false(): + QEFFLogger.close_logger() + assert QEFFLogger.print_table() is False