From 40cad1c98f8ba37bdceb98eca37848e78716a54c Mon Sep 17 00:00:00 2001 From: Keith Edmunds Date: Fri, 2 Aug 2024 18:34:30 +0100 Subject: [PATCH] Fix resource leak After around 1.5h of operation, we'd get messages such as: vlcpulse audio output error: PulseAudio server connection failure: Connection terminated Tracked down to not correctly releasing vlc player resources when track had finished playing. Fixed now, and much simplified the fadeout code as well. --- app/classes.py | 196 +++++++++++++++++-------------------------- app/musicmuster.py | 1 - app/playlistmodel.py | 2 +- app/vlcmanager.py | 29 +++++++ 4 files changed, 107 insertions(+), 121 deletions(-) create mode 100644 app/vlcmanager.py diff --git a/app/classes.py b/app/classes.py index 53d563d..9ca0360 100644 --- a/app/classes.py +++ b/app/classes.py @@ -5,15 +5,12 @@ import ctypes from dataclasses import dataclass, field import datetime as dt from enum import auto, Enum -import os import platform -import threading from time import sleep from typing import Any, Optional, NamedTuple # Third party imports import numpy as np -from pprint import pprint as pp import pyqtgraph as pg # type: ignore import vlc # type: ignore @@ -21,9 +18,7 @@ import vlc # type: ignore from PyQt6.QtCore import ( pyqtSignal, QObject, - QRunnable, QThread, - QThreadPool, ) from pyqtgraph import PlotWidget from pyqtgraph.graphicsItems.PlotDataItem import PlotDataItem # type: ignore @@ -39,19 +34,18 @@ from helpers import ( show_warning, singleton, ) - -lock = threading.Lock() -players: dict[int, str] = {} +from vlcmanager import VLCManager # Define the VLC callback function type -VLC_LOG_CB = ctypes.CFUNCTYPE( - None, - ctypes.c_void_p, - ctypes.c_int, - ctypes.c_void_p, - ctypes.c_char_p, - ctypes.c_void_p, -) +# VLC logging is very noisy so comment out unless needed +# VLC_LOG_CB = ctypes.CFUNCTYPE( +# None, +# ctypes.c_void_p, +# ctypes.c_int, +# ctypes.c_void_p, +# ctypes.c_char_p, +# ctypes.c_void_p, +# ) # Determine the correct C library for vsnprintf based on the platform if platform.system() == "Windows": @@ -184,11 +178,15 @@ class _FadeCurve: # Update region position if self.region: - log.debug("issue223: _FadeCurve: update region") + # Next line is very noisy + # log.debug("issue223: _FadeCurve: update region") self.region.setRegion([0, ms_of_graph * self.ms_to_array_factor]) -class _FadeTrack(QRunnable): +class _FadeTrack(QThread): + + finished = pyqtSignal() + def __init__(self, player: vlc.MediaPlayer, fade_seconds: int) -> None: super().__init__() self.player = player @@ -202,7 +200,6 @@ class _FadeTrack(QRunnable): if not self.player: return - log.info("fade starting") # Reduce volume logarithmically total_steps = self.fade_seconds * Config.FADEOUT_STEPS_PER_SECOND db_reduction_per_step = Config.FADEOUT_DB / total_steps @@ -216,13 +213,10 @@ class _FadeTrack(QRunnable): ) sleep(1 / Config.FADEOUT_STEPS_PER_SECOND) - log.info("fade ended") - if self.player: - log.info(f"Releasing {self.player=}") - self.player.release() # Release resources - del players[id(self.player)] - pp(players) - self.player = None # Clear the reference + self.finished.emit() + + +vlc_instance = VLCManager().vlc_instance class _Music: @@ -231,38 +225,37 @@ class _Music: """ def __init__(self, name: str) -> None: - self.VLC = vlc.Instance() - self.VLC.set_user_agent(name, name) + vlc_instance.set_user_agent(name, name) self.player: Optional[vlc.MediaPlayer] = None self.name = name self.max_volume: int = Config.VLC_VOLUME_DEFAULT self.start_dt: Optional[dt.datetime] = None - self.player_count: int = 0 # Set up logging - self._set_vlc_log() + # self._set_vlc_log() - @VLC_LOG_CB - def log_callback(data, level, ctx, fmt, args): - try: - # Create a ctypes string buffer to hold the formatted message - buf = ctypes.create_string_buffer(1024) + # VLC logging very noisy so comment out unless needed + # @VLC_LOG_CB + # def log_callback(data, level, ctx, fmt, args): + # try: + # # Create a ctypes string buffer to hold the formatted message + # buf = ctypes.create_string_buffer(1024) - # Use vsnprintf to format the string with the va_list - libc.vsnprintf(buf, len(buf), fmt, args) + # # Use vsnprintf to format the string with the va_list + # libc.vsnprintf(buf, len(buf), fmt, args) - # Decode the formatted message - message = buf.value.decode("utf-8", errors="replace") - log.debug("VLC: " + message) - except Exception as e: - log.error(f"Error in VLC log callback: {e}") + # # Decode the formatted message + # message = buf.value.decode("utf-8", errors="replace") + # log.debug("VLC: " + message) + # except Exception as e: + # log.error(f"Error in VLC log callback: {e}") - def _set_vlc_log(self): - try: - vlc.libvlc_log_set(self.VLC, self.log_callback, None) - log.debug("VLC logging set up successfully") - except Exception as e: - log.error(f"Failed to set up VLC logging: {e}") + # def _set_vlc_log(self): + # try: + # vlc.libvlc_log_set(vlc_instance, self.log_callback, None) + # log.debug("VLC logging set up successfully") + # except Exception as e: + # log.error(f"Failed to set up VLC logging: {e}") def adjust_by_ms(self, ms: int) -> None: """Move player position by ms milliseconds""" @@ -303,26 +296,10 @@ class _Music: self.stop() return - # Take a copy of current player to allow another track to be - # started without interfering here - with lock: - p = self.player - # Connect to the end-of-playback event - p.event_manager().event_attach( - vlc.EventType.MediaPlayerEndReached, self.on_playback_end - ) - del players[id(self.player)] - players[id(p)] = f"From fade {self.player=}" - pp(players) - self.player = None - - pool = QThreadPool.globalInstance() - if pool: - fader = _FadeTrack(p, fade_seconds=fade_seconds) - pool.start(fader) - self.start_dt = None - else: - log.error("_Music: failed to allocate QThreadPool") + self.fader_worker = _FadeTrack(self.player, fade_seconds=fade_seconds) + self.fader_worker.finished.connect(self.player.release) + self.fader_worker.start() + self.start_dt = None def get_playtime(self) -> int: """ @@ -369,11 +346,8 @@ class _Music: """ if self.player: - log.info(f"Releasing {self.player=}") - del players[id(self.player)] - pp(players) - self.player.release() # Release resources - self.player = None # Clear the reference + self.player.release() + self.player = None def play( self, @@ -396,47 +370,38 @@ class _Music: log.error(f"play({path}): path not readable") return None - media = self.VLC.media_new_path(path) - if media is None: - log.error(f"_Music:play: failed to create media ({path=})") - show_warning(None, "Error loading file", f"Cannot play file ({path})") + self.player = vlc.MediaPlayer(vlc_instance, path) + if self.player is None: + log.error(f"_Music:play: failed to create MediaPlayer ({path=})") + show_warning(None, "Error creating MediaPlayer", f"Cannot play file ({path})") return - self.player = media.player_new_from_media() - log.info(f"Created {self.player=}") - players[id(self.player)] = os.path.basename(path) - pp(players) # Connect to the end-of-playback event self.player.event_manager().event_attach( vlc.EventType.MediaPlayerEndReached, self.on_playback_end ) - if self.player: - _ = self.player.play() - self.set_volume(self.max_volume) - self.player_count += 1 - log.debug(f"_Music.play: {self.player_count=}") + _ = self.player.play() + self.set_volume(self.max_volume) - if position: - self.player.set_position(position) - self.start_dt = start_time + if position: + self.player.set_position(position) + self.start_dt = start_time - # For as-yet unknown reasons. sometimes the volume gets - # reset to zero within 200mS or so of starting play. This - # only happened since moving to Debian 12, which uses - # Pipewire for sound (which may be irrelevant). - # It has been known for the volume to need correcting more - # than once in the first 200mS. - for _ in range(3): - if self.player: - volume = self.player.audio_get_volume() - if volume < Config.VLC_VOLUME_DEFAULT: - self.set_volume(Config.VLC_VOLUME_DEFAULT) - log.error(f"Reset from {volume=}") - sleep(0.1) - else: - log.error("_Music:play: failed to create media player") - show_warning(None, "Media player", "Unable to create media player") + # For as-yet unknown reasons. sometimes the volume gets + # reset to zero within 200mS or so of starting play. This + # only happened since moving to Debian 12, which uses + # Pipewire for sound (which may be irrelevant). + # It has been known for the volume to need correcting more + # than once in the first 200mS. + # Update August 2024: This no longer seems to be an issue + # for _ in range(3): + # if self.player: + # volume = self.player.audio_get_volume() + # if volume < Config.VLC_VOLUME_DEFAULT: + # self.set_volume(Config.VLC_VOLUME_DEFAULT) + # log.error(f"Reset from {volume=}") + # sleep(0.1) def set_position(self, position: float) -> None: """ @@ -483,20 +448,11 @@ class _Music: if not self.player: return - p = self.player - del players[id(self.player)] - players[id(p)] = f"From stop {self.player=}" - pp(players) - self.player = None self.start_dt = None - - with lock: - p.stop() - p.release() - del players[id(p)] - pp(players) - log.info(f"_Music.stop: Releasing player {p=}, {self.player_count=}") - p = None + if self.player.is_playing(): + self.player.stop() + self.player.release() + self.player = None @singleton @@ -613,6 +569,8 @@ class RowAndTrack: self.start_time = None if self.fade_graph: self.fade_graph.clear() + # Ensure that player is released + self.music.stop() self.signal_end_of_track() self.end_of_track_signalled = True @@ -739,7 +697,7 @@ class RowAndTrack: def signal_end_of_track(self) -> None: """ - Send end of track signal unless we are a preview player + Send end of track signal """ self.signals.track_ended_signal.emit() diff --git a/app/musicmuster.py b/app/musicmuster.py index 5d3ebf5..34f523c 100755 --- a/app/musicmuster.py +++ b/app/musicmuster.py @@ -670,7 +670,6 @@ class Window(QMainWindow, Ui_MainWindow): # Reset clocks self.frame_fade.setStyleSheet("") self.frame_silent.setStyleSheet("") - self.label_elapsed_timer.setText("00:00 / 00:00") self.label_fade_timer.setText("00:00") self.label_silent_timer.setText("00:00") diff --git a/app/playlistmodel.py b/app/playlistmodel.py index 6787287..228262a 100644 --- a/app/playlistmodel.py +++ b/app/playlistmodel.py @@ -561,7 +561,7 @@ class PlaylistModel(QAbstractTableModel): for a in self.playlist_rows.values() if not a.played and a.track_id is not None ] - log.debug(f"{self}: get_unplayed_rows() returned: {result=}") + # log.debug(f"{self}: get_unplayed_rows() returned: {result=}") return result def headerData( diff --git a/app/vlcmanager.py b/app/vlcmanager.py new file mode 100644 index 0000000..8ae882d --- /dev/null +++ b/app/vlcmanager.py @@ -0,0 +1,29 @@ +# Standard library imports + +# PyQt imports + +# Third party imports +import vlc # type: ignore + +# App imports + + +class VLCManager: + """ + Singleton class to ensure we only ever have one vlc Instance + """ + + __instance = None + + def __init__(self) -> None: + if VLCManager.__instance is None: + self.vlc_instance = vlc.Instance() + VLCManager.__instance = self + else: + raise Exception("Attempted to create a second VLCManager instance") + + @staticmethod + def get_instance() -> vlc.Instance: + if VLCManager.__instance is None: + VLCManager() + return VLCManager.__instance