diff --git a/av/logging.pyi b/av/logging.pyi index a85eba2df..1db5e4a3b 100644 --- a/av/logging.pyi +++ b/av/logging.pyi @@ -1,5 +1,3 @@ -import logging -from threading import Lock from typing import Any, Callable PANIC: int @@ -13,11 +11,9 @@ TRACE: int CRITICAL: int def adapt_level(level: int) -> int: ... -def get_level() -> int: ... -def set_level(level: int) -> None: ... +def get_level() -> int | None: ... +def set_level(level: int | None) -> None: ... def restore_default_callback() -> None: ... -def get_print_after_shutdown() -> bool: ... -def set_print_after_shutdown(v: bool) -> None: ... def get_skip_repeated() -> bool: ... def set_skip_repeated(v: bool) -> None: ... def get_last_error() -> tuple[int, tuple[int, str, str] | None]: ... @@ -34,13 +30,3 @@ class Capture: value: Exception | None, traceback: Callable[..., Any] | None, ) -> None: ... - -level_threshold: int -print_after_shutdown: bool -skip_repeated: bool -skip_lock: Lock -last_log: tuple[int, str, str] | None -skip_count: int -last_error: tuple[int, str, str] | None -global_captures: list[list[tuple[int, str, str]]] -thread_captures: dict[int, list[tuple[int, str, str]]] diff --git a/av/logging.pyx b/av/logging.pyx index 8940c3139..1006d094c 100644 --- a/av/logging.pyx +++ b/av/logging.pyx @@ -1,6 +1,21 @@ """ -FFmpeg has a logging system that it uses extensively. PyAV hooks into that system -to translate FFmpeg logs into Python's +FFmpeg has a logging system that it uses extensively. It's very noisy so PyAV turns it +off by default. This, unfortunately has the effect of making raised errors having less +detailed messages. It's therefore recommended to use VERBOSE when developing. + +.. _enable_logging: + +Enabling Logging +~~~~~~~~~~~~~~~~~ + +You can hook the logging system with Python by setting the log level:: + + import av + + av.logging.set_level(av.logging.VERBOSE) + + +PyAV hooks into that system to translate FFmpeg logs into Python's `logging system `_. If you are not already using Python's logging system, you can initialize it @@ -10,19 +25,12 @@ quickly with:: logging.basicConfig() -.. _disable_logging: - -Disabling Logging -~~~~~~~~~~~~~~~~~ - -You can disable hooking the logging system with an environment variable:: - - export PYAV_LOGGING=off - -or at runtime with :func:`restore_default_callback`. +Note that handling logs with Python sometimes doesn't play nice multi-threads workflows. +An alternative is :func:`restore_default_callback`. -This will leave (or restore) the FFmpeg logging system, which prints to the terminal. -This may also result in raised errors having less detailed messages. +This will restores FFmpeg's logging default system, which prints to the terminal. +Like with setting the log level to ``None``, this may also result in raised errors +having less detailed messages. API Reference @@ -37,12 +45,10 @@ from libc.stdio cimport fprintf, stderr from libc.stdlib cimport free, malloc import logging -import os import sys from threading import Lock, get_ident # Library levels. -# QUIET = lib.AV_LOG_QUIET # -8; not really a level. PANIC = lib.AV_LOG_PANIC # 0 FATAL = lib.AV_LOG_FATAL # 8 ERROR = lib.AV_LOG_ERROR @@ -72,13 +78,10 @@ cpdef adapt_level(int level): elif level <= lib.AV_LOG_DEBUG: return 5 # Lower than any logging constant. else: # lib.AV_LOG_TRACE - return 1 # ... yeah. + return 1 -# While we start with the level quite low, Python defaults to INFO, and so -# they will not show. The logging system can add significant overhead, so -# be wary of dropping this lower. -cdef int level_threshold = lib.AV_LOG_VERBOSE +cdef object level_threshold = None # ... but lets limit ourselves to WARNING (assuming nobody already did this). if "libav" not in logging.Logger.manager.loggerDict: @@ -86,33 +89,34 @@ if "libav" not in logging.Logger.manager.loggerDict: def get_level(): - """Return current FFmpeg logging threshold. See :func:`set_level`.""" + """Returns the current log level. See :func:`set_level`.""" return level_threshold -def set_level(int level): +def set_level(level): """set_level(level) - Sets logging threshold when converting from FFmpeg's logging system - to Python's. It is recommended to use the constants available in this - module to set the level: ``PANIC``, ``FATAL``, ``ERROR``, - ``WARNING``, ``INFO``, ``VERBOSE``, and ``DEBUG``. - - While less efficient, it is generally preferable to modify logging - with Python's :mod:`logging`, e.g.:: + Sets PyAV's log level. It can be set to constants available in this + module: ``PANIC``, ``FATAL``, ``ERROR``, ``WARNING``, ``INFO``, + ``VERBOSE``, ``DEBUG``, or ``None`` (the default). - logging.getLogger('libav').setLevel(logging.ERROR) + PyAV defaults to totally ignoring all ffmpeg logs. This has the side effect of + making certain Exceptions have no messages. It's therefore recommended to use: - PyAV defaults to translating everything except ``AV_LOG_DEBUG``, so this - function is only nessesary to use if you want to see those messages as well. - ``AV_LOG_DEBUG`` will be translated to a level 5 message, which is lower - than any builtin Python logging level, so you must lower that as well:: - - logging.getLogger().setLevel(5) + av.logging.set_level(av.logging.VERBOSE) + When developing your application. """ global level_threshold - level_threshold = level + + if level is None: + level_threshold = level + lib.av_log_set_callback(nolog_callback) + elif type(level) is int: + level_threshold = level + lib.av_log_set_callback(log_callback) + else: + raise ValueError("level must be: int | None") def restore_default_callback(): @@ -120,20 +124,6 @@ def restore_default_callback(): lib.av_log_set_callback(lib.av_log_default_callback) -cdef bint print_after_shutdown = False - - -def get_print_after_shutdown(): - """Will logging continue to ``stderr`` after Python shutdown?""" - return print_after_shutdown - - -def set_print_after_shutdown(v): - """Set if logging should continue to ``stderr`` after Python shutdown.""" - global print_after_shutdown - print_after_shutdown = bool(v) - - cdef bint skip_repeated = True cdef skip_lock = Lock() cdef object last_log = None @@ -226,47 +216,6 @@ cpdef log(int level, str name, str message): free(obj) -cdef void log_callback(void *ptr, int level, const char *format, lib.va_list args) noexcept nogil: - - cdef bint inited = lib.Py_IsInitialized() - if not inited and not print_after_shutdown: - return - - # Fast path: avoid logging overhead. This should match the - # log_callback_gil() checks that result in ignoring the message. - with gil: - if level > level_threshold and level != lib.AV_LOG_ERROR: - return - - # Format the message. - cdef char message[1024] - lib.vsnprintf(message, 1023, format, args) - - # Get the name. - cdef const char *name = NULL - cdef lib.AVClass *cls = (ptr)[0] if ptr else NULL - if cls and cls.item_name: - # I'm not 100% on this, but this should be static, and so - # it doesn't matter if the AVClass that returned it vanishes or not. - name = cls.item_name(ptr) - - if not inited: - fprintf(stderr, "av.logging (after shutdown): %s[%d]: %s\n", - name, level, message) - return - - with gil: - try: - log_callback_gil(level, name, message) - - except Exception as e: - fprintf(stderr, "av.logging: exception while handling %s[%d]: %s\n", - name, level, message) - # For some reason lib.PyErr_PrintEx(0) won't work. - exc, type_, tb = sys.exc_info() - lib.PyErr_Display(exc, type_, tb) - - cdef log_callback_gil(int level, const char *c_name, const char *c_message): global error_count global skip_count @@ -336,8 +285,37 @@ cdef log_callback_emit(log): logger.log(py_level, message.strip()) -# Start the magic! -# We allow the user to fully disable the logging system as it will not play -# nicely with subinterpreters due to FFmpeg-created threads. -if os.environ.get("PYAV_LOGGING") != "off": - lib.av_log_set_callback(log_callback) +cdef void log_callback(void *ptr, int level, const char *format, lib.va_list args) noexcept nogil: + cdef bint inited = lib.Py_IsInitialized() + if not inited: + return + + with gil: + if level > level_threshold and level != lib.AV_LOG_ERROR: + return + + # Format the message. + cdef char message[1024] + lib.vsnprintf(message, 1023, format, args) + + # Get the name. + cdef const char *name = NULL + cdef lib.AVClass *cls = (ptr)[0] if ptr else NULL + if cls and cls.item_name: + name = cls.item_name(ptr) + + with gil: + try: + log_callback_gil(level, name, message) + except Exception as e: + fprintf(stderr, "av.logging: exception while handling %s[%d]: %s\n", + name, level, message) + # For some reason lib.PyErr_PrintEx(0) won't work. + exc, type_, tb = sys.exc_info() + lib.PyErr_Display(exc, type_, tb) + + +cdef void nolog_callback(void *ptr, int level, const char *format, lib.va_list args) noexcept nogil: + pass + +lib.av_log_set_callback(nolog_callback) diff --git a/docs/index.rst b/docs/index.rst index 66c8ffbba..afeaa60d6 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -53,6 +53,7 @@ Basic Demo import av + av.logging.set_level(av.logging.VERBOSE) container = av.open(path_to_video) for index, frame in enumerate(container.decode(video=0)): diff --git a/tests/test_colorspace.py b/tests/test_colorspace.py index 571e7bd2b..afc16846f 100644 --- a/tests/test_colorspace.py +++ b/tests/test_colorspace.py @@ -22,6 +22,7 @@ def test_penguin_joke(self) -> None: for packet in container.demux(stream): for frame in packet.decode(): + assert isinstance(frame, av.VideoFrame) self.assertEqual(frame.color_range, ColorRange.JPEG) # a.k.a "pc" self.assertEqual(frame.colorspace, Colorspace.ITU601) return diff --git a/tests/test_logging.py b/tests/test_logging.py index 2e35879e1..2a09a9c1a 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -22,6 +22,8 @@ def test_adapt_level(self): ) def test_threaded_captures(self): + av.logging.set_level(av.logging.VERBOSE) + with av.logging.Capture(local=True) as logs: do_log("main") thread = threading.Thread(target=do_log, args=("thread",)) @@ -29,8 +31,11 @@ def test_threaded_captures(self): thread.join() self.assertIn((av.logging.INFO, "test", "main"), logs) + av.logging.set_level(None) def test_global_captures(self): + av.logging.set_level(av.logging.VERBOSE) + with av.logging.Capture(local=False) as logs: do_log("main") thread = threading.Thread(target=do_log, args=("thread",)) @@ -39,8 +44,11 @@ def test_global_captures(self): self.assertIn((av.logging.INFO, "test", "main"), logs) self.assertIn((av.logging.INFO, "test", "thread"), logs) + av.logging.set_level(None) def test_repeats(self): + av.logging.set_level(av.logging.VERBOSE) + with av.logging.Capture() as logs: do_log("foo") do_log("foo") @@ -62,7 +70,11 @@ def test_repeats(self): ], ) + av.logging.set_level(None) + def test_error(self): + av.logging.set_level(av.logging.VERBOSE) + log = (av.logging.ERROR, "test", "This is a test.") av.logging.log(*log) try: @@ -71,3 +83,5 @@ def test_error(self): self.assertEqual(e.log, log) else: self.fail() + + av.logging.set_level(None) diff --git a/tests/test_python_io.py b/tests/test_python_io.py index 42b8dd132..58ae4fd0d 100644 --- a/tests/test_python_io.py +++ b/tests/test_python_io.py @@ -292,6 +292,8 @@ def test_writing_to_pipe_readonly(self) -> None: ) def test_writing_to_pipe_writeonly(self): + av.logging.set_level(av.logging.VERBOSE) + buf = WriteOnlyPipe() with self.assertRaises(ValueError) as cm: self.write(buf) @@ -300,6 +302,8 @@ def test_writing_to_pipe_writeonly(self): str(cm.exception), ) + av.logging.set_level(None) + def read(self, fh, seekable: bool = True) -> None: wrapped = MethodLogger(fh)