Coverage for  / home / jenkins / .local / lib / python3.10 / site-packages / hyper_parallel / tools / logging.py: 98%

99 statements  

« prev     ^ index     » next       coverage.py v7.13.1, created at 2026-08-25 04:27 +0800

1# Copyright 2026 Huawei Technologies Co., Ltd 

2# 

3# Licensed under the Apache License, Version 2.0 (the "License"); 

4# you may not use this file except in compliance with the License. 

5# You may obtain a copy of the License at 

6# 

7# http://www.apache.org/licenses/LICENSE-2.0 

8# 

9# Unless required by applicable law or agreed to in writing, software 

10# distributed under the License is distributed on an "AS IS" BASIS, 

11# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 

12# See the License for the specific language governing permissions and 

13# limitations under the License. 

14# ============================================================================ 

15"""Centralized logging for hyper_parallel. 

16 

17Every hyper_parallel component (FSDP, DTensor, ...) logs through a single 

18component-aware system instead of configuring ``logging`` by hand. Records are 

19rendered with a uniform prefix so a line tells you the level, which component, 

20when it was emitted and the exact call site:: 

21 

22 [DEBUG] [HP-FSDP]: 2026-06-23 11:20:31 [hsdp_state.py: 102] action=reshard ... 

23 

24Rank is intentionally not in the prefix -- emit it from the message when needed. 

25 

26Three concerns are deliberately decoupled so each can change independently: 

27 

28* **Format** -- one ``_LOG_FORMAT`` constant plus :class:`_ContextFilter`, which 

29 stamps the component label onto every record. Change the look of all logs in 

30 one place via :func:`set_format`; the components are unaffected. 

31* **Components** -- a module declares its component with an explicit label, 

32 ``logger = get_logger("FSDP")``. The label -- not the file's import path -- is 

33 what ties a module to a component, so moving or renaming files never changes 

34 where their logs land. Onboarding a new component (e.g. ``DTensor``) needs no 

35 registration here: just call ``get_logger("DTensor")`` and start logging. 

36* **Configuration** -- per-component levels come from the ``HP_LOG_CONFIG`` env 

37 var (``export HP_LOG_CONFIG=FSDP:INFO,DTensor:DEBUG``) or programmatically via 

38 :func:`set_level` / :func:`configure` / the :data:`logger` manager. Component 

39 names are case-insensitive for known components (:data:`_KNOWN_COMPONENTS`); an 

40 unrecognised name still works but warns once, to catch typos that would 

41 otherwise silently produce no logs. 

42 

43Logging is *off by default* (each component logger starts at ``WARNING``): the 

44stdout handler is always installed, but ``debug``/``info`` calls stay silent 

45until a component is enabled by env var or code. Output goes to ``stdout``. 

46 

47Usage:: 

48 

49 from hyper_parallel.tools.logging import get_logger 

50 log = get_logger("FSDP") 

51 log.debug("hook=forward_pre module=%s", name) 

52 

53 # or drive configuration from code: 

54 from hyper_parallel.tools.logging import logger 

55 logger.set_level("FSDP", "DEBUG") 

56""" 

57__all__ = [ 

58 "HP_LOG_CONFIG_ENV", 

59 "configure", 

60 "get_logger", 

61 "logger", 

62 "logging_enabled", 

63 "set_format", 

64 "set_level", 

65] 

66 

67import logging 

68import os 

69import sys 

70from typing import Dict, Optional, Union 

71 

72# Env var that enables/levels components, e.g. "FSDP:INFO,DTensor:DEBUG". 

73HP_LOG_CONFIG_ENV = "HP_LOG_CONFIG" 

74 

75# Logger namespace; each component lives at ``hyper_parallel.<component>``. 

76_NAMESPACE = "hyper_parallel" 

77 

78# Components stay silent until explicitly enabled. 

79_DEFAULT_LEVEL = logging.WARNING 

80 

81# Component label used when ``get_logger`` is called without one. 

82_DEFAULT_COMPONENT = "HP" 

83 

84# Known component labels. This list is NOT a gate -- unknown labels still work -- 

85# it exists only to (a) give case-insensitive matching its canonical spelling and 

86# (b) warn on a likely typo (e.g. ``FDSP`` for ``FSDP``), which would otherwise 

87# silently never match. Only FSDP is wired up today; whoever adds a new component 

88# (DTensor, CP, EP, ...) appends its name here (one line) to make it 

89# case-insensitive and silence the typo warning. 

90_KNOWN_COMPONENTS = (_DEFAULT_COMPONENT, "FSDP") 

91_CANONICAL = {name.upper(): name for name in _KNOWN_COMPONENTS} 

92_warned_unknown = set() 

93 

94# A component listed in HP_LOG_CONFIG without an explicit level is just enabled. 

95_DEFAULT_ENABLED_LEVEL = logging.INFO 

96 

97# --------------------------------------------------------------------------- 

98# Format concern -- the single place that decides how a record looks. 

99# --------------------------------------------------------------------------- 

100 

101# The ``hp_component`` field is supplied by _ContextFilter; ``filename``/``lineno`` 

102# are standard LogRecord fields pointing at the ``logger.debug(...)`` call site. 

103_LOG_FORMAT = "[%(levelname)s] [HP-%(hp_component)s]: %(asctime)s [%(filename)s: %(lineno)d] %(message)s" 

104_DATE_FORMAT = "%Y-%m-%d %H:%M:%S" 

105 

106 

107class _ContextFilter(logging.Filter): 

108 """Stamp the component label onto every record. 

109 

110 Keeping this out of the format string lets :data:`_LOG_FORMAT` stay a pure, 

111 declarative template -- the only thing :func:`set_format` ever needs to touch. 

112 """ 

113 

114 def __init__(self, component: str): 

115 super().__init__() 

116 self._component = component 

117 

118 def filter(self, record: logging.LogRecord) -> bool: 

119 record.hp_component = self._component 

120 return True 

121 

122 

123class _HPStreamHandler(logging.StreamHandler): 

124 """Stream handler owned by the HyperParallel component logger.""" 

125 

126 

127def _build_formatter() -> logging.Formatter: 

128 """Return a formatter for the current global format settings.""" 

129 return logging.Formatter(_LOG_FORMAT, datefmt=_DATE_FORMAT) 

130 

131 

132# --------------------------------------------------------------------------- 

133# Component registry concern -- lazily create one stdout logger per component. 

134# --------------------------------------------------------------------------- 

135 

136_registry: Dict[str, logging.Logger] = {} 

137 

138 

139def _normalize_level(level: Union[int, str]) -> int: 

140 """Convert a level name or value to the integer level.""" 

141 if isinstance(level, int): 

142 return level 

143 level_value = logging.getLevelName(str(level).upper()) 

144 if isinstance(level_value, int): 

145 return level_value 

146 raise ValueError(f"Invalid logging level: {level!r}") 

147 

148 

149def _canonical_component(component: str) -> str: 

150 """Return the canonical label for ``component`` (case-insensitive). 

151 

152 A known label is returned in its registered spelling, so ``fsdp`` / ``Fsdp`` / 

153 ``FSDP`` all resolve to ``FSDP`` and share one logger. An unknown label is 

154 returned unchanged but triggers a one-time stderr warning -- it still works, 

155 but a typo such as ``FDSP`` would otherwise silently never match 

156 ``get_logger("FSDP")`` and no logs would appear. 

157 """ 

158 canonical = _CANONICAL.get(component.upper()) 

159 if canonical is not None: 

160 return canonical 

161 if component not in _warned_unknown: 

162 _warned_unknown.add(component) 

163 logging.getLogger(__name__).warning( 

164 "unknown component %r; known components: %s. It still works but won't " 

165 "match a registered component -- check for a typo (e.g. 'FDSP' vs 'FSDP').", 

166 component, 

167 ", ".join(_KNOWN_COMPONENTS), 

168 ) 

169 return component 

170 

171 

172def _parse_config(spec: str) -> Dict[str, int]: 

173 """Parse ``"FSDP:INFO,DTensor:DEBUG"`` into ``{component: level}``. 

174 

175 A bare component name (``"FSDP"``) enables it at ``_DEFAULT_ENABLED_LEVEL``. 

176 Names are canonicalized (case-insensitive) so the config matches the labels 

177 used by :func:`get_logger`. 

178 """ 

179 levels: Dict[str, int] = {} 

180 for item in spec.split(","): 

181 item = item.strip() 

182 if not item: 

183 continue 

184 name, sep, level = item.partition(":") 

185 name = name.strip() 

186 if not name: 

187 continue 

188 level = level.strip() 

189 parsed = _normalize_level(level) if (sep and level) else _DEFAULT_ENABLED_LEVEL 

190 levels[_canonical_component(name)] = parsed 

191 return levels 

192 

193 

194def _env_levels() -> Dict[str, int]: 

195 """Per-component levels parsed from the ``HP_LOG_CONFIG`` env var.""" 

196 return _parse_config(os.environ.get(HP_LOG_CONFIG_ENV, "")) 

197 

198 

199def _make_handler(component: str) -> logging.StreamHandler: 

200 """Build the stdout handler for ``component`` with HP formatting.""" 

201 handler = _HPStreamHandler(sys.stdout) 

202 handler.setLevel(logging.NOTSET) 

203 handler.setFormatter(_build_formatter()) 

204 handler.addFilter(_ContextFilter(component)) 

205 return handler 

206 

207 

208def get_logger(component: str = _DEFAULT_COMPONENT) -> logging.Logger: 

209 """Return the logger for ``component``, registering it lazily. 

210 

211 ``component`` is an explicit label (``"FSDP"``, ``"DTensor"``, ...) -- the same 

212 string used in ``HP_LOG_CONFIG`` and :func:`set_level`. A module just declares 

213 ``logger = get_logger("FSDP")``; the label is independent of the file's path, 

214 so moving or renaming modules never changes which component they log under. 

215 All callers passing the same label share one ``[HP-<component>]`` logger, level 

216 and handler. The first call installs a stdout handler with HP formatting and 

217 applies any ``HP_LOG_CONFIG`` level for it. Matching is case-insensitive for 

218 known components; an unrecognised label still works but warns once (typo guard). 

219 """ 

220 component = _canonical_component(component) 

221 existing = _registry.get(component) 

222 if existing is not None: 

223 return existing 

224 component_logger = logging.getLogger(f"{_NAMESPACE}.{component}") 

225 # Own a single stdout handler; never propagate to the root logger so HP logs 

226 # are not duplicated by an app-level root handler. 

227 component_logger.handlers = [_make_handler(component)] 

228 component_logger.propagate = False 

229 component_logger.setLevel(_env_levels().get(component, _DEFAULT_LEVEL)) 

230 _registry[component] = component_logger 

231 return component_logger 

232 

233 

234# --------------------------------------------------------------------------- 

235# Configuration concern -- env var and programmatic entry points. 

236# --------------------------------------------------------------------------- 

237 

238 

239def set_level(component: str, level: Union[int, str]) -> logging.Logger: 

240 """Set ``component``'s level (registering it if needed) and return its logger.""" 

241 component_logger = get_logger(component) 

242 component_logger.setLevel(_normalize_level(level)) 

243 return component_logger 

244 

245 

246def configure(spec: str) -> None: 

247 """Apply a ``HP_LOG_CONFIG``-style spec programmatically. 

248 

249 Example: ``configure("FSDP:INFO,DTensor:DEBUG")``. 

250 """ 

251 for component, level in _parse_config(spec).items(): 

252 _ = set_level(component, level) 

253 

254 

255def set_format(fmt: Optional[str] = None, datefmt: Optional[str] = None) -> None: 

256 """Override the global log format and refresh every registered handler. 

257 

258 Use ``%(hp_component)s`` in ``fmt`` for the component label, alongside any 

259 standard ``LogRecord`` field (``%(levelname)s``, ``%(filename)s``, ...). 

260 """ 

261 global _LOG_FORMAT, _DATE_FORMAT 

262 if fmt is not None: 

263 _LOG_FORMAT = fmt 

264 if datefmt is not None: 

265 _DATE_FORMAT = datefmt 

266 for component_logger in _registry.values(): 

267 for handler in component_logger.handlers: 

268 if isinstance(handler, _HPStreamHandler): 

269 handler.setFormatter(_build_formatter()) 

270 

271 

272def logging_enabled(component: str, level: int = logging.DEBUG) -> bool: 

273 """Whether ``component`` would emit a record at ``level``.""" 

274 return get_logger(component).isEnabledFor(level) 

275 

276 

277# --------------------------------------------------------------------------- 

278# Manager facade -- ``from hyper_parallel.tools.logging import logger``. 

279# --------------------------------------------------------------------------- 

280 

281 

282class _LoggingManager: 

283 """Thin object facade over the module-level configuration functions. 

284 

285 Lets callers drive the logging system from code without importing each 

286 function separately:: 

287 

288 from hyper_parallel.tools.logging import logger 

289 logger.set_level("FSDP", "DEBUG") 

290 log = logger.get_logger("FSDP") 

291 """ 

292 

293 get_logger = staticmethod(get_logger) 

294 set_level = staticmethod(set_level) 

295 configure = staticmethod(configure) 

296 set_format = staticmethod(set_format) 

297 enabled = staticmethod(logging_enabled) 

298 

299 

300logger = _LoggingManager()