diff --git a/server.py b/server.py index de71e7b..7098161 100644 --- a/server.py +++ b/server.py @@ -74,6 +74,7 @@ recents = db_iptv['recents'] settings_collection = db_iptv['settings'] devices_db = db_iptv['devices'] +MAX_STREAMING_ERRORS_PER_DEVICE = 5 devices = [] active_xtream_imports = {} sio_session_ips = {} @@ -1471,6 +1472,21 @@ async def communication(fromSid, data): await sio.emit('communication', data, room=toSidDevice ,callback=messageReceived) +@sio.event +async def streaming_error(sid, data): + IdDevice = data.get('IdDevice') + message = data.get('message', '') + if not IdDevice: + return + + print('streaming_error from device :', IdDevice, message, flush=True) + error_entry = {'message': str(message)[:500], 'timestamp': time.time()} + devices_db.update_one( + {'id_device': IdDevice}, + {'$push': {'last_errors': {'$each': [error_entry], '$slice': -MAX_STREAMING_ERRORS_PER_DEVICE}}} + ) + + @sio.event def disconnect(sid): sio_session_ips.pop(sid, None) diff --git a/static/IPTV.py b/static/IPTV.py index 90ee051..38804cb 100644 --- a/static/IPTV.py +++ b/static/IPTV.py @@ -5,6 +5,7 @@ import logging +import logging.handlers import vlc import os import re @@ -12,7 +13,6 @@ import sys import json import queue import psutil -import logging import requests import time import threading @@ -44,6 +44,31 @@ sio = socketio.Client( ) urllib3.disable_warnings(urllib3.exceptions.InsecureRequestWarning) +# ---------------------------------------------------------------- +# LOGGING (fichier local avec rotation, consultable via le Terminal +# du menu device sur le site, ex: tail -n 200 iptv.log) +# ---------------------------------------------------------------- +LOG_FILE_PATH = "/home/pi/Documents/iptv.log" +LOG_FILE_MAX_BYTES = 1_000_000 +LOG_FILE_BACKUP_COUNT = 5 + +logger = logging.getLogger(__name__) +logger.setLevel(logging.INFO) +_log_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') + +_console_handler = logging.StreamHandler() +_console_handler.setFormatter(_log_formatter) +logger.addHandler(_console_handler) + +try: + _file_handler = logging.handlers.RotatingFileHandler( + LOG_FILE_PATH, maxBytes=LOG_FILE_MAX_BYTES, backupCount=LOG_FILE_BACKUP_COUNT + ) + _file_handler.setFormatter(_log_formatter) + logger.addHandler(_file_handler) +except OSError as exc: + logger.warning("Unable to open log file %s: %s", LOG_FILE_PATH, exc) + class IdleScreenManager: def __init__(self): @@ -167,7 +192,7 @@ class IdleScreenManager: self.root.after(IDLE_SCREEN_REFRESH_INTERVAL_MS, self._refresh_recent_data) self.root.mainloop() except Exception as exc: - print("Unable to start idle screen:", exc, flush=True) + logger.warning("Unable to start idle screen: %s", exc) self.enabled = False def _process_commands(self): @@ -358,7 +383,7 @@ def fetch_channel_logo_photo(item): try: photo_image = ImageTk.PhotoImage(background) except Exception as exc: - print("Unable to create Tk logo image:", exc, flush=True) + logger.warning("Unable to create Tk logo image: %s", exc) return None, f"Tk image creation failed: {exc}" logo_cache[cache_key] = photo_image @@ -482,7 +507,7 @@ def sync_recent_channels_from_server(): if normalized_items: return save_recent_channels_to_db(normalized_items) except Exception as exc: - print("Unable to refresh recent channels from server:", exc, flush=True) + logger.warning("Unable to refresh recent channels from server: %s", exc) return recent @@ -494,7 +519,34 @@ def focus_vlc_player(): try: media_principal.set_fullscreen(True) except Exception as exc: - print("Unable to focus VLC player:", exc, flush=True) + logger.warning("Unable to focus VLC player: %s", exc) + + +STREAMING_ERROR_REPORT_MIN_INTERVAL_SECONDS = 5 +_last_streaming_error_report_ts = 0 + + +def report_streaming_error(message): + """Log a critical streaming error and forward it to the server (best effort, + rate-limited so a burst of VLC errors doesn't flood the socket).""" + global _last_streaming_error_report_ts + + logger.error(message) + + now = time.time() + if now - _last_streaming_error_report_ts < STREAMING_ERROR_REPORT_MIN_INTERVAL_SECONDS: + return + _last_streaming_error_report_ts = now + + try: + if sio.connected: + sio.emit('streaming_error', {'IdDevice': IdDevice, 'message': str(message)}) + except Exception as exc: + logger.warning("Unable to report streaming error to server: %s", exc) + + +def on_vlc_encountered_error(event): + report_streaming_error("VLC encountered a playback error (channel: %s)" % mediaRunning) def wait_for_vlc_playback_start(): @@ -507,11 +559,11 @@ def wait_for_vlc_playback_start(): focus_vlc_player() return True except Exception as exc: - print("Unable to determine VLC playback state:", exc, flush=True) + logger.warning("Unable to determine VLC playback state: %s", exc) break time.sleep(VLC_PLAYBACK_POLL_INTERVAL_SECONDS) - print("VLC did not report playback start before timeout", flush=True) + report_streaming_error("VLC did not report playback start before timeout (channel: %s)" % mediaRunning) return False @@ -617,6 +669,7 @@ def new_media_player(url): media.add_option(f":vout={forced_vout}") player.set_media(media) + player.event_manager().event_attach(vlc.EventType.MediaPlayerEncounteredError, on_vlc_encountered_error) return player @@ -650,7 +703,7 @@ def capture_and_upload_snapshot(): snapshot_path = get_snapshot_filepath() snapshot_status = media_principal.video_take_snapshot(0, snapshot_path, 0, 0) if snapshot_status != 0: - print('snapshot capture failed', flush=True) + logger.error("Snapshot capture failed") return False upload_snapshot_file(snapshot_path) @@ -663,7 +716,7 @@ def snapshot_loop(): if auto_snapshot_enabled and data_running: capture_and_upload_snapshot() except Exception as exc: - print('snapshot loop error', exc, flush=True) + logger.warning("Snapshot loop error: %s", exc) time.sleep(SNAPSHOT_INTERVAL_SECONDS) def RepresentsInt(s): @@ -677,7 +730,7 @@ def convertMillis(millis): seconds=(millis/1000)%60 minutes=(millis/(1000*60))%60 hours=(millis/(1000*60*60))%24 - print(str(seconds)+" "+str(minutes)+" "+ str(hours)) + logger.debug("%s %s %s", seconds, minutes, hours) return seconds, minutes, hours def is_vpn_connected(): @@ -730,12 +783,12 @@ def findInfo(tag, s): def restart_process(): try: - print('restart new process') + logger.info("Restarting process") p = psutil.Process(os.getpid()) for handler in p.get_open_files() + p.connections(): os.close(handler.fd) except Exception as e: - logging.error(e) + logger.error(e) python = sys.executable os.execl(python, python, *sys.argv) @@ -768,7 +821,7 @@ def display_overlay_message(message, duration_ms=10000): media_principal.video_set_marquee_int(vlc.VideoMarqueeOption.Timeout, duration_ms) media_principal.video_set_marquee_int(vlc.VideoMarqueeOption.Position, 8) except Exception as exc: - print('Unable to display overlay message:', exc, flush=True) + logger.warning("Unable to display overlay message: %s", exc) def playMedia(id_channel, url_channel, name_channel, id_playlist): @@ -781,20 +834,20 @@ def playMedia(id_channel, url_channel, name_channel, id_playlist): media_principal.stop() media_principal.release() except Exception as e: - print("Unable to reset VLC player:", e, flush=True) + logger.warning("Unable to reset VLC player: %s", e) media_principal = new_media_player(url_channel) try: media_principal.set_fullscreen(True) except Exception as e: - print("Unable to enable fullscreen:", e, flush=True) + logger.warning("Unable to enable fullscreen: %s", e) media_principal.audio_set_volume(200) media_principal.play() start_playback_transition() mediaRunning = name_channel data_running = {'name_channel':name_channel, 'id_channel':id_channel, 'id_playlist':id_playlist, 'url_channel': url_channel, 'progress':0} prepend_recent_channel(id_channel, url_channel, name_channel, id_playlist) - print(' DATA : ', data_running, flush=True) + logger.info("Playback started: %s", data_running) media_principal.video_set_marquee_int(vlc.VideoMarqueeOption.Enable, 1) media_principal.video_set_marquee_string(vlc.VideoMarqueeOption.Text, name_channel) @@ -813,7 +866,7 @@ def update_source(): updated_file.write(r.content) os.replace(temp_path, path + 'IPTV.py') except Exception as exc: - print('error update_source', exc, flush=True) + logger.error("Error during update_source: %s", exc) if os.path.exists(temp_path): os.remove(temp_path) raise @@ -821,14 +874,14 @@ def update_source(): def wait_for_internet_connection(): while True: - print("Checking connexion ...", flush=True) + logger.info("Checking connexion ...") for check_url, verify_ssl in CONNECTIVITY_CHECK_TARGETS: try: requests.get(check_url, timeout=CONNECTIVITY_CHECK_TIMEOUT_SECONDS, verify=verify_ssl) - print(f"Connectivity check succeeded with {check_url}", flush=True) + logger.info("Connectivity check succeeded with %s", check_url) return except requests.RequestException as exc: - print(f"Connectivity check failed for {check_url}: {exc}", flush=True) + logger.warning("Connectivity check failed for %s: %s", check_url, exc) time.sleep(CONNECTIVITY_CHECK_RETRY_SECONDS) @@ -856,18 +909,18 @@ def ensure_socket_connection(force_reset=False): pass wait_for_internet_connection() - print('Attempting socket connection...', flush=True) + logger.info("Attempting socket connection...") sio.connect( url_update_server, wait=True, wait_timeout=SOCKET_CONNECT_TIMEOUT, transports=['websocket', 'polling'] ) - print('Socket connection ready', flush=True) + logger.info("Socket connection ready") server_connection_ready = True return True except Exception as exc: - print('Socket reconnection failed', exc, flush=True) + logger.warning("Socket reconnection failed: %s", exc) server_connection_ready = False return False @@ -876,7 +929,7 @@ def polling_server(): global media_principal global data_running global status_vpn - print('polling_server') + logger.info("Polling loop started") while True: try: if not sio.connected: @@ -890,7 +943,7 @@ def polling_server(): percentage = media_principal.get_position()*100 if data_running: - print(data_running_tmp) + logger.debug("Current playback state: %s", data_running_tmp) data_running = {'name_channel':data_running_tmp['name_channel'], 'id_channel':data_running_tmp['id_channel'], 'id_playlist':data_running_tmp['id_playlist'], 'url_channel':data_running_tmp['url_channel'], 'progress':milli, 'percentage':percentage} sio.emit('polling', { 'name': name_device, @@ -902,7 +955,7 @@ def polling_server(): 'snapshot_interval_seconds': SNAPSHOT_INTERVAL_SECONDS }) except Exception as exc: - print('Polling failed, will reconnect', exc, flush=True) + logger.warning("Polling failed, will reconnect: %s", exc) ensure_socket_connection(force_reset=True) time.sleep(POLLING_INTERVAL_SECONDS) @@ -911,23 +964,23 @@ def polling_server(): def sendMessage(fromSidDevice, toSidDevice, typeCommand, payload, num_packet): new_data = {'fromSidDevice': fromSidDevice, 'toSidDevice': toSidDevice, 'typeCommand': typeCommand, 'payload': payload, 'packet':num_packet} - print(new_data) + logger.info("Sending message: %s", new_data) if sio.connected or ensure_socket_connection(): sio.emit('communication', new_data) else: - print('Socket disconnected, unable to send message', flush=True) + logger.warning("Socket disconnected, unable to send message") @sio.event def connect(): global server_connection_ready server_connection_ready = True - print('connection established') + logger.info("Connection established") @sio.event def connect_error(data): - print('connection error', data, flush=True) + logger.error("Connection error: %s", data) @sio.event @@ -973,14 +1026,14 @@ def communication(data): # PLAY A CHANNEL ON # -------------------------------- if typeCommand == "on": - print ("switch on") + logger.info("Switch on requested") data_channel = data['payload'] - name_channel = data_channel['name'] + name_channel = data_channel['name'] url_channel = data_channel['url'] id_channel = data_channel['id_channel'] id_playlist = data_channel['id_playlist'] - print(id_channel, name_channel, url_channel, flush=True) + logger.info("Playing channel id=%s name=%s url=%s", id_channel, name_channel, url_channel) playMedia(id_channel, url_channel, name_channel, id_playlist) sendMessage(toSidDevice, fromSidDevice, 'playing', name_channel, 0) sendMessage(toSidDevice, fromSidDevice, 'warning', 'Starting media', 0) @@ -1105,7 +1158,7 @@ def communication(data): if typeCommand == "changeDeviceName": global name_device name_device = data['payload'] - print(name_device) + logger.info("Change device name to: %s", name_device) query = "UPDATE settings SET valueParameter = '" + name_device + "' WHERE nameParameter = 'deviceName'" cur_ = con.cursor() cur_.execute(query) @@ -1134,7 +1187,7 @@ def communication(data): # -------------------------------- if typeCommand == "takeSnapshot": try: - print('take snapshot') + logger.info("Take snapshot requested") time.sleep(1) capture_and_upload_snapshot() except Exception as e: @@ -1152,22 +1205,19 @@ def communication(data): # Command line # -------------------------------- if typeCommand == "command_line": + logger.info("Command line requested: %s", data['payload']) records = re.split(r' ', data['payload']) - #result = subprocess.run(records, capture_output=True, text=True) - process = subprocess.Popen(records, stdout=subprocess.PIPE, text=True) + process = subprocess.Popen(records, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True) for line in process.stdout: - print(line, end="") + logger.info("command_line output: %s", line.rstrip()) sendMessage(toSidDevice, fromSidDevice, 'display_command_result', line, 0) - #print(result.stdout) - - @sio.event def disconnect(): global server_connection_ready server_connection_ready = False - print('Disconnected from server', flush=True) + logger.warning("Disconnected from server") @@ -1181,7 +1231,7 @@ def initDB(): cur = con.cursor() cur.execute('SELECT SQLITE_VERSION()') data = cur.fetchone() - print ("Connexion succeed : SQLite version: %s" % data) + logger.info("Connexion succeed : SQLite version: %s", data) cur.execute( """ CREATE TABLE IF NOT EXISTS recent_channels_cache ( @@ -1197,7 +1247,7 @@ def initDB(): con.commit() except (lite.Error, e): - print ("Error %s:" % e.args[0]) + logger.error("Error %s:", e.args[0]) sys.exit(1) @@ -1217,9 +1267,9 @@ def initIPTV(): record = cur_.fetchone() if record: IdDevice = record[0] - print(IdDevice) + logger.info("Device ID: %s", IdDevice) else: - print("No ID device found") + logger.info("No ID device found, generating one") IdDevice = str(uuid.uuid4()) query = "INSERT INTO settings (nameParameter, valueParameter) VALUES ('IdDevice', '"+IdDevice+"')" cur_ = con.cursor() @@ -1234,7 +1284,7 @@ def initIPTV(): valueParameter = cur_.fetchone() if valueParameter is not None: name_device = valueParameter - print('Update device name : ' + str(name_device)) + logger.info("Update device name : %s", name_device) # SAVE PID @@ -1252,7 +1302,7 @@ def initIPTV(): # ---------------------------------------------------------------- # ---------------------------------------------------------------- -num_version='5.0.4' +num_version='5.0.6' # ---------------------------------------------------------------- # ---------------------------------------------------------------- @@ -1266,7 +1316,7 @@ db_file = 'config.db' path = os.path.dirname(os.path.realpath(__file__))+'/' con = None pid = os.getppid() -print('PID : ', pid) +logger.info("PID : %s", pid) channels = [] playlists = [] @@ -1317,15 +1367,11 @@ auth_file = "/home/pi/Documents/auth.txt" # ---------------------------------------------------------------- -# ---------------------------------------------------------------- - -logging.basicConfig( - format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', level=logging.INFO -) -logger = logging.getLogger(__name__) +# --------------------------------------------------------------- +# (logging configuré plus haut dans le fichier, juste après les imports) # ---------------------------------------------------------------- -# LOOP PRINCIPAL +# LOOP PRINCIPAL # ---------------------------------------------------------------- if __name__ == '__main__': diff --git a/static/index.html b/static/index.html index 33d48ed..45d2435 100644 --- a/static/index.html +++ b/static/index.html @@ -961,6 +961,8 @@