class ControlMessageHelper: # Control message types TYPE_VOLUME = 'volume' TYPE_INIT_VIDEO = 'init_video' TYPE_PLAY_VIDEO = 'play_video' TYPE_SKIP_VIDEO = 'skip_video' TYPE_DISPLAY_MODE = 'display_mode' TYPE_SHOW_LOADING_SCREEN = 'type_show_loading_screen' TYPE_END_LOADING_SCREEN = 'type_end_loading_screen' CTRL_MSG_TYPE_KEY = 'msg_type' CONTENT_KEY = 'content' def __init__(self): self.__logger = Logger().set_namespace(self.__class__.__name__) def setup_for_broadcaster(self): self.__multicast_helper = MulticastHelper().setup_broadcaster_socket() return self def setup_for_receiver(self): self.__multicast_helper = MulticastHelper( ).setup_receiver_control_socket() return self def send_msg(self, ctrl_msg_type, content): msg = json.dumps({ self.CTRL_MSG_TYPE_KEY: ctrl_msg_type, self.CONTENT_KEY: content }) self.__multicast_helper.send(msg.encode(), MulticastHelper.CONTROL_PORT) """ Returns a dictionary representing the message. The dictionary has two keys: 1) self.CTRL_MSG_TYPE_KEY 2) self.CONTENT_KEY """ def receive_msg(self): msg_bytes = self.__multicast_helper.receive( MulticastHelper.CONTROL_PORT) try: msg = json.loads(msg_bytes) except Exception as e: self.__logger.error( f"Unable to load control message json: {msg_bytes}.") raise e return msg
class Queue: __TICKS_PER_SECOND = 10 __RECEIVER_VOLUME_SETS_PER_SECOND = 0.5 def __init__(self): self.__logger = Logger().set_namespace(self.__class__.__name__) self.__logger.info("Starting queue...") self.__config_loader = ConfigLoader() self.__playlist = Playlist() self.__settings_db = SettingsDb() self.__volume_controller = VolumeController() self.__control_message_helper = ControlMessageHelper( ).setup_for_broadcaster() self.__last_tick_time = 0 self.__last_set_receiver_vol_time = 0 self.__broadcast_proc = None self.__playlist_item = None self.__is_broadcast_in_progress = False self.__animator = Animator(self.__TICKS_PER_SECOND) self.__remote = Remote(self.__TICKS_PER_SECOND) # house keeping self.__volume_controller.set_vol_pct(50) self.__playlist.clean_up_state() def run(self): while True: if self.__is_broadcast_in_progress: self.__maybe_skip_broadcast() if self.__broadcast_proc and self.__broadcast_proc.poll( ) is not None: self.__logger.info( "Ending broadcast because broadcast proc is no longer running..." ) self.__stop_broadcast_if_broadcasting() else: next_item = self.__playlist.get_next_playlist_item() if next_item: self.__play_playlist_item(next_item) else: self.__play_screensaver() self.__tick_animation_and_set_receiver_state() self.__remote.check_for_input_and_handle(self.__playlist_item) time.sleep(0.050) def __play_playlist_item(self, playlist_item): if not self.__playlist.set_current_video( playlist_item["playlist_video_id"]): # Someone deleted the item from the queue in between getting the item and starting it. return log_uuid = Logger.make_uuid() Logger.set_uuid(log_uuid) self.__logger.info( f"Starting broadcast for playlist_video_id: {playlist_item['playlist_video_id']}" ) msg = { 'log_uuid': log_uuid, 'loading_screen_data': self.__choose_random_loading_screen() } self.__control_message_helper.send_msg( ControlMessageHelper.TYPE_SHOW_LOADING_SCREEN, msg) self.__do_broadcast(playlist_item['url'], log_uuid) self.__playlist_item = playlist_item def __choose_random_loading_screen(self): loading_screens_config = self.__config_loader.get_raw_config( )['loading_screens'] if self.__config_loader.is_any_receiver_dual_video_output(): options = loading_screens_config['720p'] else: options = loading_screens_config['1080p'] loading_screen_data = random.choice(list(options.values())) return loading_screen_data def __play_screensaver(self): log_uuid = 'SCREENSAVER__' + Logger.make_uuid() Logger.set_uuid(log_uuid) # choose random screensaver video to play screensavers_config = self.__config_loader.get_raw_config( )['screensavers'] if self.__config_loader.is_any_receiver_dual_video_output(): options = screensavers_config['720p'] else: options = screensavers_config['1080p'] screensaver_data = random.choice(list(options.values())) path = DirectoryUtils().root_dir + '/' + screensaver_data['video_path'] self.__logger.info("Starting broadcast of screensaver...") self.__do_broadcast(path, log_uuid) def __do_broadcast(self, url, log_uuid): cmd = ( f"{DirectoryUtils().root_dir}/bin/broadcast --url {shlex.quote(url)} " + f"--log-uuid {shlex.quote(log_uuid)} --no-show-loading-screen") # Using start_new_session = False here because it is not necessary to start a new session here (though # it should not hurt if we were to set it to True either) self.__broadcast_proc = subprocess.Popen(cmd, shell=True, executable='/usr/bin/bash', start_new_session=False) self.__is_broadcast_in_progress = True def __maybe_skip_broadcast(self): if not self.__is_broadcast_in_progress: return should_skip = False if self.__playlist_item: try: # Might result in: `sqlite3.OperationalError: database is locked`, when DB is under load should_skip = self.__playlist.should_skip_video_id( self.__playlist_item['playlist_video_id']) except Exception as e: self.__logger.info(f"Caught exception: {e}.") elif self.__is_screensaver_broadcast_in_progress(): should_skip = self.__playlist.get_next_playlist_item() is not None if should_skip: self.__stop_broadcast_if_broadcasting(was_skipped=True) return True return False def __is_screensaver_broadcast_in_progress(self): return self.__is_broadcast_in_progress and self.__playlist_item is None def __stop_broadcast_if_broadcasting(self, was_skipped=False): if not self.__is_broadcast_in_progress: return if self.__broadcast_proc: self.__logger.info( "Killing broadcast proc (if it's still running)...") was_killed = True try: os.kill(self.__broadcast_proc.pid, signal.SIGTERM) except Exception: # might raise: `ProcessLookupError: [Errno 3] No such process` was_killed = False exit_status = self.__broadcast_proc.wait() if exit_status != 0: if was_killed and exit_status == signal.SIGTERM: pass # We expect a specific non-zero exit code if the broadcast was killed. else: self.__logger.error( f'Got non-zero exit_status for broadcast proc: {exit_status}' ) self.__control_message_helper.send_msg( ControlMessageHelper.TYPE_SKIP_VIDEO, {}) if self.__playlist_item: if self.__should_reenqueue_current_playlist_item(was_skipped): self.__playlist.reenqueue( self.__playlist_item["playlist_video_id"]) else: self.__playlist.end_video( self.__playlist_item["playlist_video_id"]) self.__logger.info("Ended video broadcast.") Logger.set_uuid('') self.__broadcast_proc = None self.__playlist_item = None self.__is_broadcast_in_progress = False """ Starting a channel video causes the currently playing video to immediately be skipped. Playing a lot of channel videos in quick succession could therefore cause the playlist queue to become depleted without the videos even having had a chance to play. Thus, when we are skipping a video, we check if a channel video is the next item in the queue. If so, we reenqueue the video so as not to deplete the queue when a lot of channel videos are being played. """ def __should_reenqueue_current_playlist_item( self, was_current_playlist_item_skipped): if self.__playlist_item["type"] != Playlist.TYPE_VIDEO: return False if not was_current_playlist_item_skipped: return False next_playlist_item = self.__playlist.get_next_playlist_item() if next_playlist_item and next_playlist_item[ "type"] == Playlist.TYPE_CHANNEL_VIDEO: return True return False # Set all receiver state on an interval to ensure eventual consistency. # We already set all state from the server in response to user UI actions (adjusting volume, toggling display mode) # # Possible failure scenarios: # 1) A UDP packet was dropped, so a receiver missed setting some state adjustment. This seems unlikely given that # we tuned everything to minimize UDP packet loss (very important for a successful video broadcast). # 2) We ignored setting state the first time due to throttling to avoid being overwhelmed with user state modification. # See: OmxplayerController.__MAX_IN_FLIGHT_PROCS # 3) A receiver process was restarted and thus lost its state. def __tick_animation_and_set_receiver_state(self): now = time.time() if (now - self.__last_tick_time) > (1 / self.__TICKS_PER_SECOND): # sets the display_mode of the TVs self.__animator.tick() self.__last_tick_time = now # maybe set volume if (now - self.__last_set_receiver_vol_time) > ( 1 / self.__RECEIVER_VOLUME_SETS_PER_SECOND): vol_pct = self.__volume_controller.get_vol_pct() self.__control_message_helper.send_msg( ControlMessageHelper.TYPE_VOLUME, vol_pct) self.__last_set_receiver_vol_time = now
class ServerRequestHandler(http.server.BaseHTTPRequestHandler): def __init__(self, request, client_address, server): self.__root_dir = DirectoryUtils().root_dir + "/app/build" self.__api = Piwall2Api() self.__logger = Logger().set_namespace(self.__class__.__name__) http.server.BaseHTTPRequestHandler.__init__(self, request, client_address, server) def do_OPTIONS(self): self.send_response(200, "ok") self.send_header('Access-Control-Allow-Origin', '*') self.send_header('Access-Control-Allow-Methods', 'GET, POST, OPTIONS') self.send_header('Access-Control-Allow-Headers', 'X-Requested-With') self.send_header('Access-Control-Allow-Headers', 'Content-Type') self.end_headers() def do_GET(self): try: if self.path[:4] == "/api": return self.__do_api_GET(self.path[5:]) return self.__serve_static_asset() except Exception: self.log_error('Exception: {}'.format(traceback.format_exc())) def do_POST(self): try: if self.path[:4] == "/api": return self.__do_api_POST(self.path[5:]) return self.__serve_static_asset() except Exception: self.log_error('Exception: {}'.format(traceback.format_exc())) def __do_404(self): self.send_response(404) self.end_headers() def __do_api_GET(self, path): parsed_path = urllib.parse.urlparse(path) get_data = urllib.parse.unquote(parsed_path.query) if get_data: get_data = json.loads(get_data) if parsed_path.path == 'queue': response = self.__api.get_queue() elif parsed_path.path == 'vol_pct': response = self.__api.get_volume() elif parsed_path.path == 'youtube_api_key': response = self.__api.get_youtube_api_key() elif parsed_path.path == 'title': response = self.__api.get_title() else: self.__do_404() return self.send_response(200) self.send_header("Access-Control-Allow-Origin", "*") self.send_header("Content-Type", "application/json") self.end_headers() resp = io.BytesIO() resp.write(bytes(json.dumps(response), 'utf-8')) self.wfile.write(resp.getvalue()) def __do_api_POST(self, path): content_length = int(self.headers['Content-Length']) post_data = None if content_length > 0: body = self.rfile.read(content_length) post_data = json.loads(body.decode("utf-8")) if path == 'queue': response = self.__api.enqueue(post_data) elif path == 'skip': response = self.__api.skip(post_data) elif path == 'remove': response = self.__api.remove(post_data) elif path == 'clear': response = self.__api.clear() elif path == 'vol_pct': response = self.__api.set_vol_pct(post_data) elif path == 'display_mode': response = self.__api.set_display_mode(post_data) elif path == 'animation_mode': response = self.__api.set_animation_mode(post_data) else: self.__do_404() return self.send_response(200) self.send_header("Access-Control-Allow-Origin", "*") self.send_header("Content-Type", "application/json") self.end_headers() resp = io.BytesIO() resp.write(bytes(json.dumps(response), 'utf-8')) self.wfile.write(resp.getvalue()) def __serve_static_asset(self): self.path = urlparse(self.path).path # get rid of query parameters e.g. `?foo=bar&baz=1` if self.path == '/': self.path = self.__root_dir + '/index.html' elif self.path.startswith('/assets/'): self.path = DirectoryUtils().root_dir + '/assets/' + self.path[len('/assets/'):] else: self.path = self.__root_dir + self.path try: file_to_open = open(self.path, 'rb').read() self.send_response(200) except Exception: self.log_error("") self.log_error(f'Unable to open file at {self.path}. Exception: {traceback.format_exc()}') self.__do_404() return if self.path.endswith('.js'): self.send_header("Content-Type", "text/javascript") elif self.path.endswith('.css'): self.send_header("Content-Type", "text/css") elif self.path.endswith('.svg') or self.path.endswith('.svgz'): self.send_header("Content-Type", "image/svg+xml") self.end_headers() if type(file_to_open) is bytes: self.wfile.write(file_to_open) else: self.wfile.write(bytes(file_to_open, 'utf-8')) return def log_request(self, code='-', size='-'): if isinstance(code, http.server.HTTPStatus): code = code.value self.log_message('[REQUEST] "%s" %s %s', self.requestline, str(code), str(size)) def log_error(self, format, *args): self.__logger.error("%s - - %s" % (self.client_address[0], format % args)) def log_message(self, format, *args): self.__logger.info("%s - - %s" % (self.client_address[0], format % args))
class VideoBroadcaster: END_OF_VIDEO_MAGIC_BYTES = b'PIWALL2_END_OF_VIDEO_MAGIC_BYTES' __VIDEO_URL_TYPE_YOUTUBE = 'video_url_type_youtube' __VIDEO_URL_TYPE_LOCAL_FILE = 'video_url_type_local_file' __AUDIO_FORMAT = 'bestaudio' # Touch this file when video playing is done. # We check for its existence to determine when video playback is over. __VIDEO_PLAYBACK_DONE_FILE = '/tmp/video_playback_done.file' # video_url may be a youtube url or a path to a file on disk # Loading screen may also get shown by the queue process. Sending the signal to show it from # the queue is faster than showing it in the videobroadcaster process. But one may still wish # to show a loading screen when playing videos via the command line. def __init__(self, video_url, log_uuid, show_loading_screen): self.__logger = Logger().set_namespace(self.__class__.__name__) if log_uuid: Logger.set_uuid(log_uuid) else: Logger.set_uuid(Logger.make_uuid()) self.__config_loader = ConfigLoader() self.__video_url = video_url self.__show_loading_screen = show_loading_screen # Store the PGIDs separately, because attempting to get the PGID later via `os.getpgid` can # raise `ProcessLookupError: [Errno 3] No such process` if the process is no longer running self.__video_broadcast_proc_pgid = None self.__download_and_convert_video_proc_pgid = None # Metadata about the video we are using, such as title, resolution, file extension, etc # Access should go through self.get_video_info() to populate it lazily self.__video_info = None # Bind multicast traffic to eth0. Otherwise it might send over wlan0 -- multicast doesn't work well over wifi. # `|| true` to avoid 'RTNETLINK answers: File exists' if the route has already been added. (subprocess.check_output( f"sudo ip route add {MulticastHelper.ADDRESS}/32 dev eth0 || true", shell=True, executable='/usr/bin/bash', stderr=subprocess.STDOUT)) self.__control_message_helper = ControlMessageHelper( ).setup_for_broadcaster() self.__do_housekeeping(for_end_of_video=False) self.__register_signal_handlers() def broadcast(self): attempt = 1 max_attempts = 2 while attempt <= max_attempts: try: self.__broadcast_internal() break except YoutubeDlException as e: if attempt < max_attempts: self.__logger.warning( "Caught exception in VideoBroadcaster.__broadcast_internal: " + traceback.format_exc()) self.__logger.warning( "Updating youtube-dl and retrying broadcast...") self.__update_youtube_dl() if attempt >= max_attempts: raise e finally: self.__do_housekeeping(for_end_of_video=True) attempt += 1 def __broadcast_internal(self): self.__logger.info(f"Starting broadcast for: {self.__video_url}") if self.__show_loading_screen: self.__control_message_helper.send_msg( ControlMessageHelper.TYPE_SHOW_LOADING_SCREEN, {}) """ What's going on here? We invoke youtube-dl (ytdl) three times in the broadcast code: 1) To populate video metadata, including dimensions which allow us to know how much to crop the video 2) To download the proper video format (which generally does not have sound included) and mux it with (3) 3) To download the best audio quality Ytdl takes couple of seconds to be invoked. Luckily, (2) and (3) happen in parallel (see self.__get_ffmpeg_input_clause). But that would still leave us with effectively two groups of ytdl invocations which are happening serially: the group consisting of "1" and the group consisting of "2 and 3". Note that (1) happens in self.get_video_info. By starting a separate process for "2 and 3", we can actually ensure that all three of these invocations happen in parallel. This separate process is started in self.__start_download_and_convert_video_proc. This shaves 2-3 seconds off of video start up time -- although this time saving is partially canceled out by the `time.sleep(2)` we had to add below. This requires that we break up the original single pipeline into two halves. Originally, a single pipeline was responsible for downloading, converting, and broadcasting the video. Now we have two pipelines that we start separately: 1) download_and_convert_video_proc, which downloads and converts the video 2) video_broadcast_proc, which broadcasts the converted video We connect the stdout of (1) to the stdin of (2). In order to run all the ytdl invocations in parallel, we had to break up the original single pipeline into these two halves, because broadcasting the video requires having started the receivers first. And starting the receivers requires knowing how much to crop, which requires knowing the video dimensions. Thus, we need to know the video dimensions before broadcasting the video. Without breaking up the pipeline, we wouldn't be able to enforce that we don't start broadcasting the video before knowing the dimensions. """ download_and_convert_video_proc = self.start_download_and_convert_video_proc( ) self.get_video_info(assert_data_not_yet_loaded=True) self.__start_receivers() """ This `sleep` makes the videos more likely to start in-sync across all the TVs, but I'm not totally sure why. My current theory is that this give the receivers enough time to start before the broadcast command starts sending its data. Another potential solution is making use of delay_buffer in video_broadcast_cmd, although I have abandoned that approach for now: https://gist.github.com/dasl-/9ed9d160384a8dd77382ce6a07c43eb6 Another thing I tried was only sending the data once a few megabytes have been read, in case it was a problem with the first few megabytes of the video being downloaded slowly, but this approach resulted in occasional very brief video artifacts (green screen, etc) within the first 30 seconds or so of playback: https://gist.github.com/dasl-/f3fcc941e276d116320d6fa9e4de25de And another thing I tried is starting the receivers early without any crop args to the invocation of omxplayer. I would only send the crop args later via dbus. This allowed me to get rid of the sleep below. I wasn't 100%, but it may have made things *slightly* less likely to start in sync. Hard to know. Very rarely, you would see the crop change at the very start of the video if it couldn't complete the dbus message before the video started playing. See the approach here: https://gist.github.com/dasl-/db3ce584ba90802ba390ac0f07611dea See data collected on the effectiveness of this sleep: https://gist.github.com/dasl-/e5c05bf89c7a92d43881a2ff978dc889 """ time.sleep(2) video_broadcast_proc = self.__start_video_broadcast_proc( download_and_convert_video_proc) self.__logger.info( "Waiting for download_and_convert_video and video_broadcast procs to end..." ) has_download_and_convert_video_proc_ended = False has_video_broadcast_proc_ended = False while True: # Wait for the download_and_convert_video and video_broadcast procs to end... if not has_download_and_convert_video_proc_ended and download_and_convert_video_proc.poll( ) is not None: has_download_and_convert_video_proc_ended = True if download_and_convert_video_proc.returncode != 0: raise YoutubeDlException( "The download_and_convert_video process exited non-zero: " + f"{download_and_convert_video_proc.returncode}. This could mean an issue with youtube-dl; " + "it may require updating.") self.__logger.info( "The download_and_convert_video proc ended.") if not has_video_broadcast_proc_ended and video_broadcast_proc.poll( ) is not None: has_video_broadcast_proc_ended = True if video_broadcast_proc.returncode != 0: raise Exception( f"The video broadcast process exited non-zero: {video_broadcast_proc.returncode}" ) self.__logger.info("The video_broadcast proc ended.") if has_download_and_convert_video_proc_ended and has_video_broadcast_proc_ended: break time.sleep(0.1) while not os.path.isfile(self.__VIDEO_PLAYBACK_DONE_FILE): time.sleep(0.1) # Wait to ensure video playback is done. Data collected suggests one second is sufficient: # https://docs.google.com/spreadsheets/d/1YzxsD3GPzsIeKYliADN3af7ORys5nXHCRBykSnHaaxk/edit#gid=0 time.sleep(1) self.__logger.info("Video playback is likely over.") """ Process to download video via youtube-dl and convert it to proper format via ffmpeg. Note that we only download the video if the input was a youtube_url. If playing a local file, no download is necessary. """ def start_download_and_convert_video_proc(self, ytdl_video_format=None): if self.__get_video_url_type() == self.__VIDEO_URL_TYPE_LOCAL_FILE: cmd = f"cat {shlex.quote(self.__video_url)}" else: # Mix the best audio with the video and send via multicast # See: https://github.com/dasl-/piwall2/blob/main/docs/best_video_container_format_for_streaming.adoc # See: https://github.com/dasl-/piwall2/blob/main/docs/streaming_high_quality_videos_from_youtube-dl_to_stdout.adoc ffmpeg_input_clause = self.__get_ffmpeg_input_clause( ytdl_video_format) # TODO: can we use mp3 instead of mp2? cmd = ( f"set -o pipefail && export SHELLOPTS && {self.__get_standard_ffmpeg_cmd()} {ffmpeg_input_clause} " + "-c:v copy -c:a mp2 -b:a 192k -f mpegts -") self.__logger.info( f"Running download_and_convert_video_proc command: {cmd}") # Info on start_new_session: https://gist.github.com/dasl-/1379cc91fb8739efa5b9414f35101f5f # Allows killing all processes (subshells, children, grandchildren, etc as a group) download_and_convert_video_proc = subprocess.Popen( cmd, shell=True, executable='/usr/bin/bash', start_new_session=True, stdout=subprocess.PIPE) self.__download_and_convert_video_proc_pgid = os.getpgid( download_and_convert_video_proc.pid) return download_and_convert_video_proc def __start_video_broadcast_proc(self, download_and_convert_video_proc): # See: https://github.com/dasl-/piwall2/blob/main/docs/controlling_video_broadcast_speed.adoc mbuffer_size = round(Receiver.VIDEO_PLAYBACK_MBUFFER_SIZE_BYTES / 2) burst_throttling_clause = ( f'mbuffer -q -l /tmp/mbuffer.out -m {mbuffer_size}b | ' + f'{self.__get_standard_ffmpeg_cmd()} -re -i pipe:0 -c:v copy -c:a copy -f mpegts - >/dev/null ; ' + f'touch {self.__VIDEO_PLAYBACK_DONE_FILE}') broadcasting_clause = ( f"{DirectoryUtils().root_dir}/bin/msend_video " + f'--log-uuid {shlex.quote(Logger.get_uuid())} ' + f'--end-of-video-magic-bytes {self.END_OF_VIDEO_MAGIC_BYTES.decode()}' ) # Mix the best audio with the video and send via multicast # See: https://github.com/dasl-/piwall2/blob/main/docs/best_video_container_format_for_streaming.adoc # # Use `pv` to rate limit how fast we send the video. This is especially important when playing back # local files. Without `pv`, they may send as fast as network bandwidth permits, which would prevent # control messages from being received in a timely manner. Without `pv` here, when playing local files, # we observed that a control message could be sent over the network and received ~10 seconds later -- # a delay because the tubes were clogged. video_broadcast_cmd = ( "set -o pipefail && export SHELLOPTS && " + f"pv --rate-limit 4M | tee >({burst_throttling_clause}) >({broadcasting_clause}) >/dev/null" ) self.__logger.info(f"Running broadcast command: {video_broadcast_cmd}") # Info on start_new_session: https://gist.github.com/dasl-/1379cc91fb8739efa5b9414f35101f5f # Allows killing all processes (subshells, children, grandchildren, etc as a group) video_broadcast_proc = subprocess.Popen( video_broadcast_cmd, shell=True, executable='/usr/bin/bash', start_new_session=True, stdin=download_and_convert_video_proc.stdout) self.__video_broadcast_proc_pgid = os.getpgid(video_broadcast_proc.pid) return video_broadcast_proc def __start_receivers(self): msg = { 'log_uuid': Logger.get_uuid(), 'video_width': self.get_video_info()['width'], 'video_height': self.get_video_info()['height'], } self.__control_message_helper.send_msg( ControlMessageHelper.TYPE_INIT_VIDEO, msg) self.__logger.info( f"Sent {ControlMessageHelper.TYPE_INIT_VIDEO} control message.") def __get_standard_ffmpeg_cmd(self): # unfortunately there's no way to make ffmpeg output its stats progress stuff with line breaks log_opts = '-nostats ' if sys.stderr.isatty(): log_opts = '-stats ' if Logger.get_level() <= Logger.DEBUG: pass # don't change anything, ffmpeg is pretty verbose by default else: log_opts += '-loglevel error' # Note: don't use ffmpeg's `-xerror` flag: # https://gist.github.com/dasl-/1ad012f55f33f14b44393960f66c6b00 return f"ffmpeg -hide_banner {log_opts} " def __get_ffmpeg_input_clause(self, ytdl_video_format): video_url_type = self.__get_video_url_type() if video_url_type == self.__VIDEO_URL_TYPE_YOUTUBE: """ Pipe to mbuffer to avoid video drop outs when youtube-dl temporarily loses its connection and is trying to reconnect: [download] Got server HTTP error: [Errno 104] Connection reset by peer. Retrying (attempt 1 of 10)... [download] Got server HTTP error: [Errno 104] Connection reset by peer. Retrying (attempt 2 of 10)... [download] Got server HTTP error: [Errno 104] Connection reset by peer. Retrying (attempt 3 of 10)... This can happen from time to time when downloading long videos. Youtube-dl should download quickly until it fills the mbuffer. After the mbuffer is filled, ffmpeg will apply backpressure to youtube-dl because of ffmpeg's `-re` flag --retries infinite: using this to avoid scenarios where all of the retries (10 by default) were exhausted on long video downloads. After a while, retries would be necessary to reconnect. The retries would be successful, but the connection errors would happen again a few minutes later. This allows us to keep retrying whenever it is necessary. Use yt-dlp, a fork of youtube-dl that has a workaround (for now) for an issue where youtube has been throttling youtube-dl’s download speed: https://github.com/ytdl-org/youtube-dl/issues/29326#issuecomment-879256177 """ youtube_dl_cmd_template = ( "yt-dlp {0} --retries infinite --format {1} --output - {2} | " + "mbuffer -q -Q -m {3}b") log_opts = '--no-progress' if Logger.get_level() <= Logger.DEBUG: log_opts = '' # show video download progress if not sys.stderr.isatty(): log_opts += ' --newline' if not ytdl_video_format: ytdl_video_format = self.__config_loader.get_youtube_dl_video_format( ) # 50 MB. Based on one video, 1080p avc1 video consumes about 0.36 MB/s. So this should # be enough buffer for ~139s video_buffer_size = 1024 * 1024 * 50 youtube_dl_video_cmd = youtube_dl_cmd_template.format( shlex.quote(self.__video_url), shlex.quote(ytdl_video_format), log_opts, video_buffer_size) # 5 MB. Based on one video, audio consumes about 0.016 MB/s. So this should # be enough buffer for ~312s audio_buffer_size = 1024 * 1024 * 5 youtube_dl_audio_cmd = youtube_dl_cmd_template.format( shlex.quote(self.__video_url), shlex.quote(self.__AUDIO_FORMAT), log_opts, audio_buffer_size) return f"-i <({youtube_dl_video_cmd}) -i <({youtube_dl_audio_cmd})" elif video_url_type == self.__VIDEO_URL_TYPE_LOCAL_FILE: return f"-i {shlex.quote(self.__video_url)} " # Lazily populate video_info from youtube. This takes a couple seconds, as it invokes youtube-dl on the video. # Must return a dict containing the keys: width, height def get_video_info(self, assert_data_not_yet_loaded=False): if self.__video_info: if assert_data_not_yet_loaded: raise Exception( 'Failed asserting that data was not yet loaded') return self.__video_info video_url_type = self.__get_video_url_type() if video_url_type == self.__VIDEO_URL_TYPE_YOUTUBE: self.__logger.info("Downloading and populating video metadata...") ydl_opts = { 'format': self.__config_loader.get_youtube_dl_video_format(), 'logger': Logger().set_namespace('youtube_dl'), 'restrictfilenames': True, # get rid of a warning ytdl gives about special chars in file names } ydl = youtube_dl.YoutubeDL(ydl_opts) # Automatically try to update youtube-dl and retry failed youtube-dl operations when we get a youtube-dl # error. # # The youtube-dl package needs updating periodically when youtube make updates. This is # handled on a cron once a day: # https://github.com/dasl-/piwall2/blob/3aa6dee264102baf2646aab1baebdcae0148b4bc/install/piwall2_cron.sh#L5 # # But we also attempt to update it on the fly here if we get youtube-dl errors when trying to play # a video. # # Example of how this would look in logs: https://gist.github.com/dasl-/09014dca55a2e31bb7d27f1398fd8155 max_attempts = 2 for attempt in range(1, (max_attempts + 1)): try: self.__video_info = ydl.extract_info(self.__video_url, download=False) except Exception as e: caught_or_raising = "Raising" if attempt < max_attempts: caught_or_raising = "Caught" self.__logger.warning( "Problem downloading video info during attempt {} of {}. {} exception: {}" .format(attempt, max_attempts, caught_or_raising, traceback.format_exc())) if attempt < max_attempts: self.__logger.warning( "Attempting to update youtube-dl before retrying download..." ) self.__update_youtube_dl() else: self.__logger.error( "Unable to download video info after {} attempts.". format(max_attempts)) raise e self.__logger.info( "Done downloading and populating video metadata.") self.__logger.info( f"Using: {self.__video_info['vcodec']} / {self.__video_info['ext']}@" + f"{self.__video_info['width']}x{self.__video_info['height']}") elif video_url_type == self.__VIDEO_URL_TYPE_LOCAL_FILE: # TODO: guard against unsupported video formats ffprobe_cmd = ( 'ffprobe -hide_banner -v 0 -of csv=p=0 -select_streams v:0 -show_entries stream=width,height ' + shlex.quote(self.__video_url)) ffprobe_output = (subprocess.check_output( ffprobe_cmd, shell=True, executable='/usr/bin/bash', stderr=subprocess.STDOUT).decode("utf-8")) ffprobe_output = ffprobe_output.split('\n')[0] ffprobe_parts = ffprobe_output.split(',') self.__video_info = { 'width': int(ffprobe_parts[0]), 'height': int(ffprobe_parts[1]), } return self.__video_info def __get_video_url_type(self): if self.__video_url.startswith( 'http://') or self.__video_url.startswith('https://'): return self.__VIDEO_URL_TYPE_YOUTUBE else: return self.__VIDEO_URL_TYPE_LOCAL_FILE def __update_youtube_dl(self): update_youtube_dl_output = (subprocess.check_output( 'sudo ' + DirectoryUtils().root_dir + '/utils/update_youtube-dl.sh', shell=True, executable='/usr/bin/bash', stderr=subprocess.STDOUT).decode("utf-8")) self.__logger.info( "Update youtube-dl output: {}".format(update_youtube_dl_output)) # for_end_of_video: whether we are doing housekeeping before or after playing a video def __do_housekeeping(self, for_end_of_video): if self.__download_and_convert_video_proc_pgid: self.__logger.info( "Killing download and convert video process group (PGID: " + f"{self.__download_and_convert_video_proc_pgid})...") try: os.killpg(self.__download_and_convert_video_proc_pgid, signal.SIGTERM) except Exception: # might raise: `ProcessLookupError: [Errno 3] No such process` pass if self.__video_broadcast_proc_pgid: self.__logger.info( "Killing video broadcast process group (PGID: " + f"{self.__video_broadcast_proc_pgid})...") try: os.killpg(self.__video_broadcast_proc_pgid, signal.SIGTERM) except Exception: # might raise: `ProcessLookupError: [Errno 3] No such process` pass if for_end_of_video: # sending a skip signal at the beginning of a video could skip the loading screen self.__control_message_helper.send_msg( ControlMessageHelper.TYPE_SKIP_VIDEO, {}) try: os.remove(self.__VIDEO_PLAYBACK_DONE_FILE) except Exception: pass self.__video_info = None def __register_signal_handlers(self): signal.signal(signal.SIGINT, self.__signal_handler) signal.signal(signal.SIGHUP, self.__signal_handler) signal.signal(signal.SIGQUIT, self.__signal_handler) signal.signal(signal.SIGABRT, self.__signal_handler) signal.signal(signal.SIGFPE, self.__signal_handler) signal.signal(signal.SIGSEGV, self.__signal_handler) signal.signal(signal.SIGPIPE, self.__signal_handler) signal.signal(signal.SIGTERM, self.__signal_handler) def __signal_handler(self, sig, frame): self.__logger.info(f"Caught signal {sig}, exiting gracefully...") self.__do_housekeeping(for_end_of_video=True) sys.exit(sig)
class Receiver: VIDEO_PLAYBACK_MBUFFER_SIZE_BYTES = 1024 * 1024 * 400 # 400 MB def __init__(self): self.__logger = Logger().set_namespace(self.__class__.__name__) self.__logger.info("Started receiver!") self.__hostname = socket.gethostname() + ".local" # The current crop modes for up to two TVs that may be hooked up to this receiver self.__display_mode = DisplayMode.DISPLAY_MODE_TILE self.__display_mode2 = DisplayMode.DISPLAY_MODE_TILE self.__video_crop_args = None self.__video_crop_args2 = None self.__loading_screen_crop_args = None self.__loading_screen_crop_args2 = None config_loader = ConfigLoader() self.__receiver_config_stanza = config_loader.get_own_receiver_config_stanza() self.__receiver_command_builder = ReceiverCommandBuilder(config_loader, self.__receiver_config_stanza) self.__tv_ids = self.__get_tv_ids_by_tv_num() self.__control_message_helper = ControlMessageHelper().setup_for_receiver() # Store the PGIDs separately, because attempting to get the PGID later via `os.getpgid` can # raise `ProcessLookupError: [Errno 3] No such process` if the process is no longer running self.__is_video_playback_in_progress = False self.__receive_and_play_video_proc = None self.__receive_and_play_video_proc_pgid = None self.__is_loading_screen_playback_in_progress = False self.__loading_screen_proc = None self.__loading_screen_pgid = None # house keeping # Set the video player volume to 50%, but set the hardware volume to 100%. self.__video_player_volume_pct = 50 (VolumeController()).set_vol_pct(100) self.__disable_terminal_output() self.__play_warmup_video() # This must come after the warmup video. When run as a systemd service, omxplayer wants to # start new dbus sessions / processes every time the service is restarted. This means it will # create new dbus files in /tmp when the first video is played after the service is restarted # But the old files will still be in /tmp. So if we initialize the OmxplayerController before # the new dbus files are created by playing the first video since restarting the service, we # will be reading stale dbus info from the files in /tmp. self.__omxplayer_controller = OmxplayerController() def run(self): while True: try: self.__run_internal() except Exception: self.__logger.error('Caught exception: {}'.format(traceback.format_exc())) def __run_internal(self): ctrl_msg = None ctrl_msg = self.__control_message_helper.receive_msg() # This blocks until a message is received! self.__logger.debug(f"Received control message {ctrl_msg}.") if self.__is_video_playback_in_progress: if self.__receive_and_play_video_proc and self.__receive_and_play_video_proc.poll() is not None: self.__logger.info("Ending video playback because receive_and_play_video_proc is no longer running...") self.__stop_video_playback_if_playing(stop_loading_screen_playback = True) if self.__is_loading_screen_playback_in_progress: if self.__loading_screen_proc and self.__loading_screen_proc.poll() is not None: self.__logger.info("Ending loading screen playback because loading_screen_proc is no longer running...") self.__stop_loading_screen_playback_if_playing(reset_log_uuid = False) msg_type = ctrl_msg[ControlMessageHelper.CTRL_MSG_TYPE_KEY] if msg_type == ControlMessageHelper.TYPE_INIT_VIDEO: self.__stop_video_playback_if_playing(stop_loading_screen_playback = False) self.__receive_and_play_video_proc = self.__receive_and_play_video(ctrl_msg) self.__receive_and_play_video_proc_pgid = os.getpgid(self.__receive_and_play_video_proc.pid) if msg_type == ControlMessageHelper.TYPE_PLAY_VIDEO: if self.__is_video_playback_in_progress: if self.__receiver_config_stanza['is_dual_video_output']: dbus_names = [OmxplayerController.TV1_VIDEO_DBUS_NAME, OmxplayerController.TV2_VIDEO_DBUS_NAME] else: dbus_names = [OmxplayerController.TV1_VIDEO_DBUS_NAME] self.__omxplayer_controller.play(dbus_names) elif msg_type == ControlMessageHelper.TYPE_SKIP_VIDEO: self.__stop_video_playback_if_playing(stop_loading_screen_playback = True) elif msg_type == ControlMessageHelper.TYPE_VOLUME: self.__video_player_volume_pct = ctrl_msg[ControlMessageHelper.CONTENT_KEY] vol_pairs = {} if self.__is_video_playback_in_progress: vol_pairs[OmxplayerController.TV1_VIDEO_DBUS_NAME] = self.__video_player_volume_pct if self.__receiver_config_stanza['is_dual_video_output']: vol_pairs[OmxplayerController.TV2_VIDEO_DBUS_NAME] = self.__video_player_volume_pct if self.__is_loading_screen_playback_in_progress: vol_pairs[OmxplayerController.TV1_LOADING_SCREEN_DBUS_NAME] = self.__video_player_volume_pct if self.__receiver_config_stanza['is_dual_video_output']: vol_pairs[OmxplayerController.TV2_LOADING_SCREEN_DBUS_NAME] = self.__video_player_volume_pct self.__omxplayer_controller.set_vol_pct(vol_pairs) elif msg_type == ControlMessageHelper.TYPE_DISPLAY_MODE: display_mode_by_tv_id = ctrl_msg[ControlMessageHelper.CONTENT_KEY] should_set_tv1 = False should_set_tv2 = False for tv_num, tv_id in self.__tv_ids.items(): if tv_id in display_mode_by_tv_id: display_mode_to_set = display_mode_by_tv_id[tv_id] if display_mode_to_set not in DisplayMode.DISPLAY_MODES: display_mode_to_set = DisplayMode.DISPLAY_MODE_TILE if tv_num == 1: should_set_tv1 = True self.__display_mode = display_mode_to_set else: should_set_tv2 = True self.__display_mode2 = display_mode_to_set crop_pairs = {} if self.__is_video_playback_in_progress: if should_set_tv1 and self.__video_crop_args: crop_pairs[OmxplayerController.TV1_VIDEO_DBUS_NAME] = self.__video_crop_args[self.__display_mode] if should_set_tv2 and self.__receiver_config_stanza['is_dual_video_output'] and self.__video_crop_args2: crop_pairs[OmxplayerController.TV2_VIDEO_DBUS_NAME] = self.__video_crop_args2[self.__display_mode2] if self.__is_loading_screen_playback_in_progress: if should_set_tv1 and self.__loading_screen_crop_args: crop_pairs[OmxplayerController.TV1_LOADING_SCREEN_DBUS_NAME] = self.__loading_screen_crop_args[self.__display_mode] if should_set_tv2 and self.__receiver_config_stanza['is_dual_video_output'] and self.__loading_screen_crop_args2: crop_pairs[OmxplayerController.TV2_LOADING_SCREEN_DBUS_NAME] = self.__loading_screen_crop_args2[self.__display_mode2] if crop_pairs: self.__omxplayer_controller.set_crop(crop_pairs) elif msg_type == ControlMessageHelper.TYPE_SHOW_LOADING_SCREEN: self.__loading_screen_proc = self.__show_loading_screen(ctrl_msg) self.__loading_screen_pgid = os.getpgid(self.__loading_screen_proc.pid) elif msg_type == ControlMessageHelper.TYPE_END_LOADING_SCREEN: self.__stop_loading_screen_playback_if_playing(reset_log_uuid = False) def __receive_and_play_video(self, ctrl_msg): ctrl_msg_content = ctrl_msg[ControlMessageHelper.CONTENT_KEY] Logger.set_uuid(ctrl_msg_content['log_uuid']) cmd, self.__video_crop_args, self.__video_crop_args2 = ( self.__receiver_command_builder.build_receive_and_play_video_command_and_get_crop_args( ctrl_msg_content['log_uuid'], ctrl_msg_content['video_width'], ctrl_msg_content['video_height'], self.__video_player_volume_pct, self.__display_mode, self.__display_mode2 ) ) self.__logger.info(f"Running receive_and_play_video command: {cmd}") self.__is_video_playback_in_progress = True proc = subprocess.Popen( cmd, shell = True, executable = '/usr/bin/bash', start_new_session = True ) return proc def __show_loading_screen(self, ctrl_msg): ctrl_msg_content = ctrl_msg[ControlMessageHelper.CONTENT_KEY] Logger.set_uuid(ctrl_msg_content['log_uuid']) cmd, self.__loading_screen_crop_args, self.__loading_screen_crop_args2 = ( self.__receiver_command_builder.build_loading_screen_command_and_get_crop_args( self.__video_player_volume_pct, self.__display_mode, self.__display_mode2, ctrl_msg_content['loading_screen_data'] ) ) self.__logger.info(f"Showing loading screen with command: {cmd}") self.__is_loading_screen_playback_in_progress = True proc = subprocess.Popen( cmd, shell = True, executable = '/usr/bin/bash', start_new_session = True ) return proc def __stop_video_playback_if_playing(self, stop_loading_screen_playback): if stop_loading_screen_playback: self.__stop_loading_screen_playback_if_playing(reset_log_uuid = False) if not self.__is_video_playback_in_progress: if stop_loading_screen_playback: Logger.set_uuid('') return if self.__receive_and_play_video_proc_pgid: self.__logger.info("Killing receive_and_play_video proc (if it's still running)...") try: os.killpg(self.__receive_and_play_video_proc_pgid, signal.SIGTERM) except Exception: # might raise: `ProcessLookupError: [Errno 3] No such process` pass Logger.set_uuid('') self.__is_video_playback_in_progress = False self.__video_crop_args = None self.__video_crop_args2 = None def __stop_loading_screen_playback_if_playing(self, reset_log_uuid): if not self.__is_loading_screen_playback_in_progress: return if self.__loading_screen_pgid: self.__logger.info("Killing loading_screen proc (if it's still running)...") try: os.killpg(self.__loading_screen_pgid, signal.SIGTERM) except Exception: # might raise: `ProcessLookupError: [Errno 3] No such process` pass if reset_log_uuid: Logger.set_uuid('') self.__is_loading_screen_playback_in_progress = False self.__loading_screen_crop_args = None self.__loading_screen_crop_args2 = None # The first video that is played after a system restart appears to have a lag in starting, # which can affect video synchronization across the receivers. Ensure we have played at # least one video since system startup. This is a short, one-second video. # # Perhaps one thing this warmup video does is start the various dbus processes for the first # time, which can involve some sleeps: # https://github.com/popcornmix/omxplayer/blob/1f1d0ccd65d3a1caa86dc79d2863a8f067c8e3f8/omxplayer#L50-L59 # # When the receiver is run as as a systemd service, the first time a video is played after the service # is restarted, it seems that omxplayer must initialize dbus. Thus, it is important to run the warmup # video whenever the service is restarted. # # This is as opposed to when running the service as a regular user / process -- the dbus stuff stays # initialized until the pi is rebooted. def __play_warmup_video(self): self.__logger.info("Playing receiver warmup video...") warmup_cmd = f'omxplayer --vol 0 {DirectoryUtils().root_dir}/utils/short_black_screen.ts' proc = subprocess.Popen( warmup_cmd, shell = True, executable = '/usr/bin/bash' ) while proc.poll() is None: time.sleep(0.1) if proc.returncode != 0: raise Exception(f"The process for cmd: [{warmup_cmd}] exited non-zero: " + f"{proc.returncode}.") # Display a black image so that terminal text output doesn't show up on the TVs in between videos. # Basically this black image will be on display all the time "underneath" any videos that are playing. def __disable_terminal_output(self): subprocess.check_output( f"sudo fbi -T 1 --noverbose --autozoom {DirectoryUtils().root_dir}/assets/black_screen.jpg", shell = True, executable = '/usr/bin/bash', stderr = subprocess.STDOUT ) atexit.register(self.__enable_terminal_output) def __enable_terminal_output(self): try: subprocess.check_output( "sudo pkill fbi", shell = True, executable = '/usr/bin/bash', stderr = subprocess.STDOUT ) except Exception: pass # Get the tv_ids for this receiver def __get_tv_ids_by_tv_num(self): tv_ids = { 1: Tv(self.__hostname, 1).tv_id } if self.__receiver_config_stanza['is_dual_video_output']: tv_ids[2] = Tv(self.__hostname, 2).tv_id return tv_ids
class Database: __DB_PATH = DirectoryUtils().root_dir + '/piwall2.db' # Zero indexed schema_version (first version is v0). __SCHEMA_VERSION = 2 def __init__(self): self.__logger = Logger().set_namespace(self.__class__.__name__) @staticmethod def database_date_to_unix_time(database_date): return time.mktime(time.strptime(database_date, '%Y-%m-%d %H:%M:%S')) # Schema change how-to: # 1) Update all DB classes with 'virgin' sql (i.e. Playlist().construct(), etc) # 2) Increment self.__SCHEMA_VERSION # 3) Implement self.__update_schema_to_vN for the incremented SCHEMA_VERSION, call this method in # the below for loop. # 4) Run ./install/install.sh def construct(self): self.get_cursor().execute("BEGIN TRANSACTION") try: self.get_cursor().execute("SELECT version FROM schema_version") current_schema_version = int( self.get_cursor().fetchone()['version']) except Exception: current_schema_version = -1 self.__logger.info( "current_schema_version: {}".format(current_schema_version)) if current_schema_version == -1: # construct from scratch self.__logger.info("Constructing database schema from scratch...") self.__construct_schema_version() piwall2.broadcaster.playlist.Playlist().construct() piwall2.broadcaster.settingsdb.SettingsDb().construct() elif current_schema_version < self.__SCHEMA_VERSION: self.__logger.info( f"Database schema is outdated. Updating from version {current_schema_version} to " + f"{self.__SCHEMA_VERSION}.") for i in range(current_schema_version + 1, self.__SCHEMA_VERSION + 1): self.__logger.info( "Running database schema change to update from version {} to {}." .format(i - 1, i)) if i == 1: self.__update_schema_to_v1() elif i == 2: self.__update_schema_to_v2() # When next schema change happens, do something like this: # elif i == 2: # self.__update_schema_to_v2() else: msg = "No update schema method defined for version: {}.".format( i) self.__logger.error(msg) raise Exception(msg) self.get_cursor().execute( "UPDATE schema_version set version = ?", [i]) elif current_schema_version == self.__SCHEMA_VERSION: self.__logger.info("Database schema is already up to date!") return else: msg = ( "Database schema is newer than should be possible. This should never happen. " + "current_schema_version: {}. Tried to update to version: {}.". format(current_schema_version, self.__SCHEMA_VERSION)) self.__logger.error(msg) raise Exception(msg) self.get_cursor().execute("COMMIT") self.__logger.info("Database schema constructed successfully.") def get_cursor(self): cursor = getattr(thread_local, 'database_cursor', None) if cursor is None: # `isolation_level = None` specifies autocommit mode. conn = sqlite3.connect(self.__DB_PATH, isolation_level=None) conn.row_factory = dict_factory cursor = conn.cursor() thread_local.database_cursor = cursor return cursor def __construct_schema_version(self): self.get_cursor().execute("DROP TABLE IF EXISTS schema_version") self.get_cursor().execute( "CREATE TABLE schema_version (version INTEGER)") self.get_cursor().execute( "INSERT INTO schema_version (version) VALUES(?)", [self.__SCHEMA_VERSION]) # Add new table for storing settings def __update_schema_to_v1(self): piwall2.broadcaster.settingsdb.SettingsDb().construct() def __update_schema_to_v2(self): self.get_cursor().execute( "ALTER TABLE playlist_videos ADD COLUMN type VARCHAR(20) DEFAULT 'TYPE_VIDEO'" ) self.get_cursor().execute("DROP INDEX IF EXISTS status_idx") self.get_cursor().execute( "CREATE INDEX status_type_idx ON playlist_videos (status, type ASC, playlist_video_id ASC)" )