`logging.log` doesn't naively work as audit hook for `sys.addaudithook`

Abierto
#98,105 1 comentario 0 reacciones 0 asignados Ver en GitHub

Nadie ha tomado este issue todavía.

Evaluación

Dificultad
5/5
Tiempo estimado
Más de una semana
Aptitud para principiantes
25/100
Tipo de issue
Error
Claridad
Bastante claro
Estado de actividad
Estancado
Stack tecnológico
python

Línea de trabajo

Reproduce la recursión usando los ejemplos sys.addaudithook y logging.warning; después, lea logging.init, especialmente Logger._log, findCaller() y la nota sobre _srcfile, junto con la documentación de sys.addaudithook. Determine cuál de los comportamientos propuestos o qué cambio en la documentación es aceptable y verifique que el registro mediante el audit hook ya no entre en recursión ni falle silenciosamente.

Escrito por el modelo de indexación a partir del texto del issue.

Descripción

stdlib type-bug

Bug report

Documentation for sys.addaudithook states "Hooks can then log the event [...]".
This works when I don't log, but instead print:

sys.addaudithook(print)
id(0)  # printed

However, nothing gets logged when I follow the suggestion to log, like:

sys.addaudithook(functools.partial(logging.warning, 'Audit hook %s %s'))
id(0)  # NOT logged

The cause is that logging.Logger._log (called by logging.warning) tries to find the caller (to populate module, lineno, funcName log format fields). For this, logging.Logger._log itself then causes audit events, which again call the audit hook. That results in infinite recursion, i.e. a RecursionError exception, which aborts the audit hook, and silences logging.

Workaround

By (temporarily) modifying logging._srcfile, the attempt to find the caller is skipped (and the log format fields are instead populated as "unknown"), infinite recursion and exception are prevented, and logging does happen:

sys.addaudithook(functools.partial(logging.warning, 'Audit hook %s %s'))
logging._srcfile = None  # prevent finding caller
id(0)  # logged

This is existing functionality, only (?) documented in source (file logging.__init__, line 188: "Setting _srcfile to None will prevent findCaller() from being called. This way, you can avoid the overhead of fetching caller information"). Though it works, the workaround is hard to find and not ideal.

Solutions

  • Ideally, logging should not attempt to gather caller info in an audit hook (however, this requires tight coupling of the logging and sys modules, so they understand each others' internals)
  • Equally user-friendly, audit events would not be generated within audit hooks (that risks incompleteness of auditing, but so does silencing logging)
  • Less user-friendly, a keyword parameter (e.g. find_caller: bool = True) could be added to the signature of each log function, logging.Logger._log can inspect it, and the documentation for sys.addaudithook should recommend to use find_caller=False for logging in audit hooks
# logging.Logger._log
if logging._srcfile and find_caller:
    ...

# to use
sys.addaudithook(functools.partial(logging.warning, 'Audit hook %s %s', find_caller=False))
id(0)  # logged
  • At the minimum, the documentation for sys.addaudithook should recommend above workaround, i.e. temporarily set logging._srcfile = None
def my_log(event, args):
    save_srcfile = logging._srcfile
    logging._srcfile = None
    logging.warning('Audit hook %s %s', event, args)
    logging._srcfile = save_srcfile

sys.addaudithook(my_log)
id(0)  # logged

Environment

The above issue exists in all Python versions supporting sys.addaudithook, i.e. 3.8, 3.9, 3.10, and 3.11.
I tested on 3.8.10, 3.9.13, 3.10.4, and 3.110rc2 on Windows 11 64 bit.

Lenguaje dominante
Python
Estrellas
77.2k
Forks
36k
Merge medio
1 d 9 h
PR fusionados (30 d)
558

Guía de contribución

Abrir la guía de contribución

Primeros pasos

  1. Lee el issue completo y luego la guía de contribución del proyecto.
  2. Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
  3. Haz un fork del repositorio y trabaja en una rama.
  4. Abre un pull request que haga referencia al número del issue.

Más de python/cpython

Todos los issues de python/cpython

Issues similares

Más issues de Python

Recibe los nuevos issues en tu correo

Un resumen breve de issues de GitHub para principiantes.