logging.py 5.14 KB
Newer Older
chenych's avatar
chenych committed
1
# Copyright 2025 Optuna, HuggingFace Inc. and the LlamaFactory team.
luopl's avatar
luopl committed
2
3
4
#
# This code is inspired by the HuggingFace's transformers library.
# https://github.com/huggingface/transformers/blob/v4.40.0/src/transformers/utils/logging.py
chenych's avatar
chenych committed
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
#     http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.

import logging
import os
import sys
luopl's avatar
luopl committed
21
import threading
chenych's avatar
chenych committed
22
from concurrent.futures import ThreadPoolExecutor
luopl's avatar
luopl committed
23
from functools import lru_cache
luopl's avatar
luopl committed
24
from typing import Optional
chenych's avatar
chenych committed
25
26
27
28

from .constants import RUNNING_LOG


luopl's avatar
luopl committed
29
30
31
32
33
_thread_lock = threading.RLock()
_default_handler: Optional["logging.Handler"] = None
_default_log_level: "logging._Level" = logging.INFO


chenych's avatar
chenych committed
34
class LoggerHandler(logging.Handler):
chenych's avatar
chenych committed
35
    r"""Redirect the logging output to the logging file for LLaMA Board."""
chenych's avatar
chenych committed
36
37
38

    def __init__(self, output_dir: str) -> None:
        super().__init__()
luopl's avatar
luopl committed
39
40
41
        self._formatter = logging.Formatter(
            fmt="[%(levelname)s|%(asctime)s] %(filename)s:%(lineno)s >> %(message)s",
            datefmt="%Y-%m-%d %H:%M:%S",
chenych's avatar
chenych committed
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
        )
        self.setLevel(logging.INFO)
        os.makedirs(output_dir, exist_ok=True)
        self.running_log = os.path.join(output_dir, RUNNING_LOG)
        if os.path.exists(self.running_log):
            os.remove(self.running_log)

        self.thread_pool = ThreadPoolExecutor(max_workers=1)

    def _write_log(self, log_entry: str) -> None:
        with open(self.running_log, "a", encoding="utf-8") as f:
            f.write(log_entry + "\n\n")

    def emit(self, record) -> None:
        if record.name == "httpx":
            return

luopl's avatar
luopl committed
59
        log_entry = self._formatter.format(record)
chenych's avatar
chenych committed
60
61
62
63
64
65
66
        self.thread_pool.submit(self._write_log, log_entry)

    def close(self) -> None:
        self.thread_pool.shutdown(wait=True)
        return super().close()


luopl's avatar
luopl committed
67
class _Logger(logging.Logger):
chenych's avatar
chenych committed
68
    r"""A logger that supports rank0 logging."""
luopl's avatar
luopl committed
69
70
71
72
73
74
75

    def info_rank0(self, *args, **kwargs) -> None:
        self.info(*args, **kwargs)

    def warning_rank0(self, *args, **kwargs) -> None:
        self.warning(*args, **kwargs)

luopl's avatar
luopl committed
76
    def warning_rank0_once(self, *args, **kwargs) -> None:
luopl's avatar
luopl committed
77
78
79
        self.warning(*args, **kwargs)


luopl's avatar
luopl committed
80
def _get_default_logging_level() -> "logging._Level":
chenych's avatar
chenych committed
81
    r"""Return the default logging level."""
chenych's avatar
chenych committed
82
    env_level_str = os.getenv("LLAMAFACTORY_VERBOSITY", None)
luopl's avatar
luopl committed
83
84
85
86
    if env_level_str:
        if env_level_str.upper() in logging._nameToLevel:
            return logging._nameToLevel[env_level_str.upper()]
        else:
luopl's avatar
luopl committed
87
            raise ValueError(f"Unknown logging level: {env_level_str}.")
luopl's avatar
luopl committed
88
89
90
91
92
93
94
95

    return _default_log_level


def _get_library_name() -> str:
    return __name__.split(".")[0]


luopl's avatar
luopl committed
96
def _get_library_root_logger() -> "_Logger":
luopl's avatar
luopl committed
97
98
99
100
    return logging.getLogger(_get_library_name())


def _configure_library_root_logger() -> None:
chenych's avatar
chenych committed
101
    r"""Configure root logger using a stdout stream handler with an explicit format."""
luopl's avatar
luopl committed
102
    global _default_handler
chenych's avatar
chenych committed
103

luopl's avatar
luopl committed
104
    with _thread_lock:
luopl's avatar
luopl committed
105
        if _default_handler:  # already configured
luopl's avatar
luopl committed
106
            return
chenych's avatar
chenych committed
107

luopl's avatar
luopl committed
108
        formatter = logging.Formatter(
luopl's avatar
luopl committed
109
110
            fmt="[%(levelname)s|%(asctime)s] %(name)s:%(lineno)s >> %(message)s",
            datefmt="%Y-%m-%d %H:%M:%S",
luopl's avatar
luopl committed
111
112
113
114
115
116
117
        )
        _default_handler = logging.StreamHandler(sys.stdout)
        _default_handler.setFormatter(formatter)
        library_root_logger = _get_library_root_logger()
        library_root_logger.addHandler(_default_handler)
        library_root_logger.setLevel(_get_default_logging_level())
        library_root_logger.propagate = False
chenych's avatar
chenych committed
118
119


luopl's avatar
luopl committed
120
def get_logger(name: Optional[str] = None) -> "_Logger":
chenych's avatar
chenych committed
121
    r"""Return a logger with the specified name. It it not supposed to be accessed externally."""
luopl's avatar
luopl committed
122
123
124
125
126
    if name is None:
        name = _get_library_name()

    _configure_library_root_logger()
    return logging.getLogger(name)
luopl's avatar
luopl committed
127
128
129


def add_handler(handler: "logging.Handler") -> None:
chenych's avatar
chenych committed
130
    r"""Add a handler to the root logger."""
luopl's avatar
luopl committed
131
132
133
134
135
    _configure_library_root_logger()
    _get_library_root_logger().addHandler(handler)


def remove_handler(handler: logging.Handler) -> None:
chenych's avatar
chenych committed
136
    r"""Remove a handler to the root logger."""
luopl's avatar
luopl committed
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
    _configure_library_root_logger()
    _get_library_root_logger().removeHandler(handler)


def info_rank0(self: "logging.Logger", *args, **kwargs) -> None:
    if int(os.getenv("LOCAL_RANK", "0")) == 0:
        self.info(*args, **kwargs)


def warning_rank0(self: "logging.Logger", *args, **kwargs) -> None:
    if int(os.getenv("LOCAL_RANK", "0")) == 0:
        self.warning(*args, **kwargs)


@lru_cache(None)
luopl's avatar
luopl committed
152
def warning_rank0_once(self: "logging.Logger", *args, **kwargs) -> None:
luopl's avatar
luopl committed
153
154
155
156
157
158
    if int(os.getenv("LOCAL_RANK", "0")) == 0:
        self.warning(*args, **kwargs)


logging.Logger.info_rank0 = info_rank0
logging.Logger.warning_rank0 = warning_rank0
luopl's avatar
luopl committed
159
logging.Logger.warning_rank0_once = warning_rank0_once