Coverage for python / lsst / daf / butler / cli / cliLog.py: 24%
159 statements
« prev ^ index » next coverage.py v7.13.5, created at 2026-05-06 08:30 +0000
1# This file is part of daf_butler.
2#
3# Developed for the LSST Data Management System.
4# This product includes software developed by the LSST Project
5# (http://www.lsst.org).
6# See the COPYRIGHT file at the top-level directory of this distribution
7# for details of code ownership.
8#
9# This software is dual licensed under the GNU General Public License and also
10# under a 3-clause BSD license. Recipients may choose which of these licenses
11# to use; please see the files gpl-3.0.txt and/or bsd_license.txt,
12# respectively. If you choose the GPL option then the following text applies
13# (but note that there is still no warranty even if you opt for BSD instead):
14#
15# This program is free software: you can redistribute it and/or modify
16# it under the terms of the GNU General Public License as published by
17# the Free Software Foundation, either version 3 of the License, or
18# (at your option) any later version.
19#
20# This program is distributed in the hope that it will be useful,
21# but WITHOUT ANY WARRANTY; without even the implied warranty of
22# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
23# GNU General Public License for more details.
24#
25# You should have received a copy of the GNU General Public License
26# along with this program. If not, see <http://www.gnu.org/licenses/>.
27from __future__ import annotations
29__all__ = (
30 "CliLog",
31 "PrecisionLogFormatter",
32)
34import datetime
35import logging
36import os
37from typing import Any
39try:
40 import lsst.log as lsstLog
41except ModuleNotFoundError:
42 lsstLog = None
44from lsst.utils.logging import TRACE, VERBOSE
46from ..logging import ButlerMDC, JsonLogFormatter
49class PrecisionLogFormatter(logging.Formatter):
50 """A log formatter that issues accurate timezone-aware timestamps."""
52 converter = datetime.datetime.fromtimestamp # type: ignore
54 use_local = True
55 """Control whether local time is displayed instead of UTC."""
57 def formatTime(self, record: logging.LogRecord, datefmt: str | None = None) -> str:
58 """Format the time as an aware datetime.
60 Parameters
61 ----------
62 record : `logging.LogRecord`
63 The record to format.
64 datefmt : `str` or `None`, optional
65 Format to use when formatting the date.
67 Returns
68 -------
69 formatted : `str`
70 Formatted date string.
71 """
72 ct: datetime.datetime = self.converter(record.created, tz=datetime.UTC) # type: ignore
73 if self.use_local:
74 ct = ct.astimezone()
75 if datefmt:
76 s = ct.strftime(datefmt)
77 else:
78 s = ct.isoformat(sep="T", timespec="milliseconds")
79 return s
82class CliLog:
83 """Interface for managing python logging and ``lsst.log``.
85 This class defines log format strings for the log output and timestamp
86 formats. It also configures ``lsst.log`` to forward all messages to
87 Python `logging`.
89 This class can perform log uninitialization, which allows command line
90 interface code that initializes logging to run unit tests that execute in
91 batches, without affecting other unit tests. See ``resetLog``.
92 """
94 defaultLsstLogLevel = lsstLog.FATAL if lsstLog is not None else None
96 pylog_longLogFmt = "{levelname} {asctime} {name} ({MDC[LABEL]})({filename}:{lineno}) - {message}"
97 """The log format used when the lsst.log package is not importable and the
98 log is initialized with longlog=True."""
100 pylog_normalFmt = "{name} {levelname}: {message}"
101 """The log format used when the lsst.log package is not importable and the
102 log is initialized with longlog=False."""
104 configState: list[tuple[Any, ...]] = []
105 """Configuration state. Contains tuples where first item in a tuple is
106 a method and remaining items are arguments for the method.
107 """
109 _initialized = False
110 _componentSettings: list[ComponentSettings] = []
112 _fileHandlers: list[logging.FileHandler] = []
113 """Any FileHandler classes attached to the root logger by this class
114 that need to be closed on reset."""
116 @staticmethod
117 def root_loggers() -> set[str]:
118 """Return the default root logger.
120 Returns
121 -------
122 log_name : `set` of `str`
123 The name(s) of the root logger(s) to use when the log level is
124 being set without a log name being specified.
126 Notes
127 -----
128 The default is ``lsst`` (which controls the butler infrastructure)
129 but additional loggers can be specified by setting the environment
130 variable ``DAF_BUTLER_ROOT_LOGGER``. This variable can contain
131 multiple default loggers separated by a ``:``.
132 """
133 log_names = {"lsst"}
134 envvar = "DAF_BUTLER_ROOT_LOGGER"
135 if envvar in os.environ: 135 ↛ 136line 135 didn't jump to line 136 because the condition on line 135 was never true
136 log_names |= set(os.environ[envvar].split(":"))
137 return log_names
139 @classmethod
140 def initLog(
141 cls,
142 longlog: bool,
143 log_tty: bool = True,
144 log_file: tuple[str, ...] = (),
145 log_label: dict[str, str] | None = None,
146 ) -> None:
147 """Initialize logging. This should only be called once per program
148 execution. After the first call this will log a warning and return.
150 If lsst.log is importable, will add its log handler to the python
151 root logger's handlers.
153 Parameters
154 ----------
155 longlog : `bool`
156 If True, make log messages appear in long format, by default False.
157 log_tty : `bool`
158 Control whether a default stream handler is enabled that logs
159 to the terminal.
160 log_file : `tuple` of `str`
161 Path to files to write log records. If path ends in ``.json`` the
162 records will be written in JSON format. Else they will be written
163 in text format. If empty no log file will be created. Records
164 will be appended to this file if it exists.
165 log_label : `dict` of `str`
166 Keys and values to be stored in logging MDC for all JSON log
167 records. Keys will be upper-cased.
168 """
169 if cls._initialized:
170 # Unit tests that execute more than one command do end up
171 # calling this function multiple times in one program execution,
172 # so do log a debug but don't log an error or fail, just make the
173 # re-initialization a no-op.
174 log = logging.getLogger(__name__)
175 log.debug("Log is already initialized, returning without re-initializing.")
176 return
177 cls._initialized = True
178 cls._recordComponentSetting(None)
180 if lsstLog is not None:
181 # Ensure that log messages are forwarded back to python.
182 # Disable use of lsst.log MDC -- we expect butler uses to
183 # use ButlerMDC.
184 lsstLog.configure_pylog_MDC("DEBUG", MDC_class=None)
186 # Forward python lsst.log messages directly to python logging.
187 # This can bypass the C++ layer entirely but requires that
188 # MDC is set via ButlerMDC, rather than in lsst.log.
189 lsstLog.usePythonLogging()
191 formatter: logging.Formatter
192 if not log_tty:
193 logging.basicConfig(force=True, handlers=[logging.NullHandler()])
194 elif longlog:
195 # Want to create our own Formatter so that we can get high
196 # precision timestamps. This requires we attach our own
197 # default stream handler.
198 defaultHandler = logging.StreamHandler()
199 formatter = PrecisionLogFormatter(fmt=cls.pylog_longLogFmt, style="{")
200 defaultHandler.setFormatter(formatter)
202 logging.basicConfig(
203 level=logging.WARNING,
204 force=True,
205 handlers=[defaultHandler],
206 )
208 else:
209 logging.basicConfig(level=logging.WARNING, format=cls.pylog_normalFmt, style="{")
211 # Initialize the root logger. Calling this ensures that both
212 # python loggers and lsst loggers are consistent in their default
213 # logging level.
214 cls._setLogLevel(".", "WARNING")
216 # Initialize default root logger level.
217 cls._setLogLevel(None, "INFO")
219 # also capture warnings and send them to logging
220 logging.captureWarnings(True)
222 # Create a record factory that ensures that an MDC is attached
223 # to the records. By default this is only used for long-log
224 # but always enable it for when someone adds a new handler
225 # that needs it.
226 ButlerMDC.add_mdc_log_record_factory()
228 # Set up the file logger
229 for file in log_file:
230 handler = logging.FileHandler(file)
231 if file.endswith(".json"):
232 formatter = JsonLogFormatter()
233 else:
234 if longlog:
235 formatter = PrecisionLogFormatter(fmt=cls.pylog_longLogFmt, style="{")
236 else:
237 formatter = logging.Formatter(fmt=cls.pylog_normalFmt, style="{")
238 handler.setFormatter(formatter)
239 logging.getLogger().addHandler(handler)
240 cls._fileHandlers.append(handler)
242 # Add any requested MDC records.
243 if log_label:
244 for key, value in log_label.items():
245 ButlerMDC.MDC(key.upper(), value)
247 # remember this call
248 cls.configState.append((cls.initLog, longlog, log_tty, log_file, log_label))
250 @classmethod
251 def resetLog(cls) -> None:
252 """Uninitialize the butler CLI Log handler and reset component log
253 levels.
255 If the lsst.log handler was added to the python root logger's handlers
256 in `initLog`, it will be removed here.
258 For each logger level that was set by this class, sets that logger's
259 level to the value it was before this class set it. For ``lsst.log``,
260 if a component level was uninitialized, it will be set to
261 `CliLog.defaultLsstLogLevel` because there is no log4cxx api to set a
262 component back to an uninitialized state.
263 """
264 if lsstLog:
265 lsstLog.doNotUsePythonLogging()
266 for componentSetting in reversed(cls._componentSettings):
267 if lsstLog is not None and componentSetting.lsstLogLevel is not None:
268 lsstLog.setLevel(componentSetting.component or "", componentSetting.lsstLogLevel)
269 logger = logging.getLogger(componentSetting.component)
270 logger.setLevel(componentSetting.pythonLogLevel)
271 cls._setLogLevel(None, "INFO")
273 ButlerMDC.restore_log_record_factory()
275 # Remove the FileHandler we may have attached.
276 root = logging.getLogger()
277 for handler in cls._fileHandlers:
278 handler.close()
279 root.removeHandler(handler)
281 cls._fileHandlers.clear()
282 cls._initialized = False
283 cls.configState = []
285 @classmethod
286 def setLogLevels(cls, logLevels: list[tuple[str | None, str]] | dict[str, str]) -> None:
287 """Set log level for one or more components or the root logger.
289 Parameters
290 ----------
291 logLevels : `list` of `tuple`
292 Per-component logging levels, each item in the list is a `tuple`
293 of (component, level), ``component`` is a logger name or an empty
294 string or `None` for default root logger, ``level`` is a logging
295 level name, one of CRITICAL, ERROR, WARNING, INFO, DEBUG (case
296 insensitive).
298 Notes
299 -----
300 The special name ``.`` can be used to set the Python root
301 logger.
302 """
303 if isinstance(logLevels, dict):
304 logLevels = list(logLevels.items())
306 # configure individual loggers
307 for component, level in logLevels:
308 cls._setLogLevel(component, level)
309 # remember this call
310 cls.configState.append((cls._setLogLevel, component, level))
312 @classmethod
313 def _setLogLevel(cls, component: str | None, level: str) -> None:
314 """Set the log level for the given component. Record the current log
315 level of the component so that it can be restored when resetting this
316 log.
318 Parameters
319 ----------
320 component : `str` or None
321 The name of the log component or `None` for the default logger.
322 The root logger can be specified either by an empty string or
323 with the special name ``.``.
324 level : `str`
325 A valid python logging level.
326 """
327 components: set[str | None]
328 if component is None:
329 components = set(cls.root_loggers())
330 elif not component or component == ".":
331 components = {None}
332 else:
333 components = {component}
334 for component in components:
335 cls._recordComponentSetting(component)
336 if lsstLog is not None:
337 lsstLogger = lsstLog.Log.getLogger(component or "")
338 lsstLogger.setLevel(cls._getLsstLogLevel(level))
339 pylevel = cls._getPyLogLevel(level)
340 if pylevel is not None:
341 logging.getLogger(component or None).setLevel(pylevel)
343 @staticmethod
344 def _getPyLogLevel(level: str) -> int | None:
345 """Get the numeric value for the given log level name.
347 Parameters
348 ----------
349 level : `str`
350 One of the python `logging` log level names.
352 Returns
353 -------
354 numericValue : `int`
355 The python `logging` numeric value for the log level.
356 """
357 if level == "VERBOSE":
358 return VERBOSE
359 elif level == "TRACE":
360 return TRACE
361 return getattr(logging, level, None)
363 @staticmethod
364 def _getLsstLogLevel(level: str) -> int | None:
365 """Get the numeric value for the given log level name.
367 If `lsst.log` is not setup this function will return `None` regardless
368 of input. `daf_butler` does not directly depend on `lsst.log` and so it
369 will not be setup when `daf_butler` is setup. Packages that depend on
370 `daf_butler` and use `lsst.log` may setup `lsst.log`.
372 Parameters
373 ----------
374 level : `str`
375 One of the python `logging` log level names.
377 Returns
378 -------
379 numericValue : `int` or `None`
380 The `lsst.log` numeric value.
382 Notes
383 -----
384 ``VERBOSE`` and ``TRACE`` logging are not supported by the LSST logger.
385 ``VERBOSE`` will be converted to ``INFO`` and ``TRACE`` will be
386 converted to ``DEBUG``.
387 """
388 if lsstLog is None:
389 return None
390 if level == "VERBOSE":
391 level = "INFO"
392 elif level == "TRACE":
393 level = "DEBUG"
394 pylog_level = CliLog._getPyLogLevel(level)
395 return lsstLog.LevelTranslator.logging2lsstLog(pylog_level)
397 class ComponentSettings:
398 """Container for log level values for a logging component.
400 Parameters
401 ----------
402 component : `str` or `None`
403 The logger component.
404 """
406 def __init__(self, component: str | None):
407 self.component = component
408 self.pythonLogLevel = logging.getLogger(component).level
409 self.lsstLogLevel = (
410 lsstLog.Log.getLogger(component or "").getLevel() if lsstLog is not None else None
411 )
412 if self.lsstLogLevel == -1:
413 self.lsstLogLevel = CliLog.defaultLsstLogLevel
415 def __repr__(self) -> str:
416 return (
417 f"ComponentSettings(component={self.component}, pythonLogLevel={self.pythonLogLevel}, "
418 f"lsstLogLevel={self.lsstLogLevel})"
419 )
421 @classmethod
422 def _recordComponentSetting(cls, component: str | None) -> None:
423 """Cache current levels for the given component in the list of
424 component levels.
425 """
426 componentSettings = cls.ComponentSettings(component)
427 cls._componentSettings.append(componentSettings)
429 @classmethod
430 def replayConfigState(cls, configState: list[tuple[Any, ...]]) -> None:
431 """Re-create configuration using configuration state recorded earlier.
433 Parameters
434 ----------
435 configState : `list` of `tuple`
436 Tuples contain a method as first item and arguments for the method,
437 in the same format as ``cls.configState``.
438 """
439 if cls._initialized or cls.configState:
440 # Already initialized, do not touch anything.
441 log = logging.getLogger(__name__)
442 log.warning("Log is already initialized, will not replay configuration.")
443 return
445 # execute each one in order
446 for call in configState:
447 method, *args = call
448 method(*args)