# # Aura Engine # # Playout Daemon for autoradio project # # # Copyright (C) 2017-2018 Gottfried Gaisbauer <gottfried.gaisbauer@servus.at> # # This file is part of engine. # # engine is free software: you can redistribute it and/or modify # it under the terms of the GNU General Public License as published by # the Free Software Foundation, either version 3 of the License, or # any later version. # # engine is distributed in the hope that it will be useful, # but WITHOUT ANY WARRANTY; without even the implied warranty of # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the # GNU General Public License for more details. # # You should have received a copy of the GNU General Public License # along with engine. If not, see <http://www.gnu.org/licenses/>. # # Meta __version__ = '0.0.1' __license__ = "GNU General Public License (GPL) Version 3" __version_info__ = (0, 0, 1) __author__ = 'Gottfried Gaisbauer <gottfried.gaisbauer@servus.at>' import time import json import datetime import decimal import traceback import sqlalchemy import logging import threading from operator import attrgetter from modules.base.simpleutil import SimpleUtil from modules.communication.redis.messenger import RedisMessenger from modules.scheduling.calendar import AuraCalendarService from modules.scheduling.fallback_manager import FallbackManager from libraries.database.broadcasts import AuraDatabaseModel, Schedule, Playlist, PlaylistEntry, PlaylistEntryMetaData, SingleEntry, SingleEntryMetaData, TrackService from libraries.exceptions.exception_logger import ExceptionLogger from libraries.enum.auraenumerations import ScheduleEntryType, TimerType, TerminalColors def alchemyencoder(obj): """JSON encoder function for SQLAlchemy special classes.""" if isinstance(obj, datetime.date): return obj.isoformat() elif isinstance(obj, decimal.Decimal): return float(obj) elif isinstance(obj, sqlalchemy.orm.state.InstanceState): return "" elif isinstance(obj, Schedule): return json.dumps([obj._asdict()], default=alchemyencoder) else: return str(obj) # ------------------------------------------------------------------------------------------ # class AuraScheduler(ExceptionLogger, threading.Thread): """ Aura Scheduler Class - Retrieves data from Steering and Tank - Stores and fires events for LiquidSoap Attributes: config (AuraConfig): Holds the Engine Configuration logger: The logger exit_event(threading.Event): Used to exit the thread if requested liquidsoapcommunicator: Stores the connection to LiquidSoap last_successful_fetch (datetime): Stores the last time a fetch from Steering/Tank was successful programme: The current radio programme to be played as defined in the local engine database active_entry(Show, Track): This is a Tuple consisting of the currently played `Show` and `Track` message_timer(Array<threading.Timer>): The message queue of Liquidsoap commands for playlists/tracks to be played """ redismessenger = None job_result = {} config = None logger = None exit_event = None liquidsoapcommunicator = None last_successful_fetch = None programme = None active_entry = None message_timer = [] fallback_manager = None #schedule_entries = None client = None def __init__(self, config): """ Constructor Args: config (AuraConfig): Reads the engine configuration """ self.config = config self.logger = logging.getLogger("AuraEngine") self.init_error_messages() self.init_database() self.fallback_manager = FallbackManager(config, self.logger, self) self.redismessenger = RedisMessenger(config) # init threading threading.Thread.__init__(self) # init messenger.. FIXME probably not needed anymore self.redismessenger.set_channel('scheduler') self.redismessenger.set_section('execjob') #self.redismessenger.send('Scheduler started', '0000', 'success', 'initApp', None, 'appinternal') # Create exit event self.exit_event = threading.Event() self.start() def run(self): """ Called when thread is started via `start()`. It does following: 1. `self.fetch_new_programme()` periodically from the API depending on the `fetching_frequency` defined in the engine configuration. 2. Loads the latest programme from the database and sets the instance state `self.programme` with current schedules. 3. Queues all playlists of the programm, other than the playlist currently to be played (This is triggered by Liquidsoap itself). """ while not self.exit_event.is_set(): seconds_to_wait = int(self.config.get("fetching_frequency")) next_time = datetime.datetime.now() + datetime.timedelta(seconds=seconds_to_wait) self.logger.info("Fetch new programmes every %ss. Next fetching in %ss." % (str(seconds_to_wait), str(next_time))) self.fetch_new_programme() self.queue_programme() self.print_message_queue() self.exit_event.wait(seconds_to_wait) # # PUBLIC METHODS # def get_active_entry(self): """ Retrieves the current `PlaylistEntry` which should be played as per programme. Publically called via `LiquidSoapCommunicator`. Important note: This method also updates the state variable `active_entry`. Returns: (PlaylistEntry): The track which is (or should) currently being played """ now_unix = time.mktime(datetime.datetime.now().timetuple()) # Load programme if necessary if not self.programme: self.logger.info("Next track requested: Need to load programme from database first.") self.load_programme_from_db() # Check for scheduled playlist current_schedule, current_playlist = self.get_active_playlist() if not current_playlist: if not current_schedule: self.logger.critical("There's no active playlist nor schedule. It's probably time to play some fallback...") else: self.logger.warning("There's no active playlist for a current schedule. Most likely the playlist finished before the end of the schedule.") return None time_start = SimpleUtil.fmt_time(current_playlist.start_unix) time_end = SimpleUtil.fmt_time(current_playlist.start_unix+current_playlist.duration) time_now = SimpleUtil.fmt_time(now_unix) self.logger.info("Current Playlist (%d:%d) for show '%s' scheduled to be played at %s until %s (Now: %s)" % (current_playlist.playlist_id, current_playlist.artificial_id, current_playlist.show_name, time_start, time_end, time_now)) # Iterate over playlist entries and store the current one time_marker = current_playlist.start_unix current_entry = None for entry in current_playlist.entries: self.logger.info(entry) if entry.start_unix < now_unix < entry.start_unix + entry.duration: current_entry = entry break time_marker += entry.duration if current_entry: time_start = SimpleUtil.fmt_time(current_entry.start_unix) time_end = SimpleUtil.fmt_time(current_entry.start_unix+current_entry.duration) time_now = SimpleUtil.fmt_time(now_unix) self.logger.info("Track '%s' is expected playing from %s to %s (Now: %s)" % (current_entry.filename, time_start, time_end, time_now)) if not self.active_entry: self.logger.warn("Activate track '%s' and [>> FFWD] to current point in time" % (current_entry.filename)) elif self.active_entry.filename != current_entry.filename: self.logger.critical("--- SOMETHING UNEXPECTED IS PLAYING: %s --vs-- %s" % (self.active_entry.filename, current_entry.filename)) self.active_entry = current_entry return (current_entry) else: # Nothing playing ... fallback will kick-in self.logger.warning("There's no entry scheduled for playlist '%s'. Is currently -nothing- or a fallback playing?" % str(current_playlist)) return None # FIXME Review relevance. def get_act_programme_as_string(self): """ Fetches the latest programme and returns it as `String`. Also used by `ServerRedisAdapter`. Return: (String): Programme Raises: (Exception): In case the programme cannot be converted to String """ programme_as_string = "" if self.programme is None or len(self.programme) == 0: self.fetch_new_programme() try: programme_as_string = json.dumps([p._asdict() for p in self.programme], default=alchemyencoder) # FIXME Change to more specific exception except Exception as e: self.logger.error("Cannot transform programme into JSON String. Reason: " + str(e)) traceback.print_exc() return programme_as_string def print_message_queue(self): """ Prints the current message queue i.e. playlists in the queue to be played. """ message_queue = "" messages = sorted(self.message_timer, key=attrgetter('diff')) if not messages: self.logger.warning("There's nothing in the Message Queue!") else: for msg in messages: message_queue += str(msg)+"\n" self.logger.info("Message Queue: \n" + message_queue) # ------------------------------------------------------------------------------------------ # def set_next_file_for(self, playlistname): self.logger.critical("HAVE TO <SET> NEXT FILE FOR: " + playlistname) self.logger.critical(str(self.get_active_entry())) if playlistname == "station": file = "/home/david/Code/aura/engine2/testing/content/ernie_mayne_sugar.mp3" elif playlistname == "timeslot": file = "/home/david/Code/aura/engine2/testing/content/ernie_mayne_sugar.mp3" elif playlistname == "show": file = "/home/david/Code/aura/engine2/testing/content/ernie_mayne_sugar.mp3" else: file = "" self.logger.critical("Should set next fallback file for " + playlistname + ", but this playlist is unknown!") self.logger.info("Set next fallback file for " + playlistname + ": " + file) self.redismessenger.set_next_file_for(playlistname, file) return file def get_next_file_for(self, fallbackname): """ Evaluates the next **fallback files/playlists** to be played for a given fallback-type. Valid fallback-types are: * timeslot * show * station Args: fallbackname (String): The name of the fallback-type Returns: (String): Absolute path to the file to be played as a fallback. """ file = self.fallback_manager.get_fallback_for(fallbackname) if file: self.logger.info("Got next file '%s' (type: %s)" % (file, fallbackname)) #set_next_file_thread = SetNextFile(fallbackname, show) #set_next_file_thread.start() #self.redismessenger.set_next_file_for(playlistname, file) return file def update_track_service(self, entry): """ Inserts the given, currently playing `PlaylistEntry` to the track-service. Called by LiquidSoapCommunicator when a new playlist item is going to be activated. Args: entry (PlaylistEntry): The item which is currently playing """ if not entry.duration: self.logger.critical("Entry %s has no duration! This may cause malfunction of some engine services." % (str(entry))) trackservice = TrackService(entry) trackservice.store(add=True, commit=True) entry.trackservice_id = trackservice.id entry.store(add=False, commit=True) self.logger.info("Stored track-service entry %s" % trackservice) def adapt_trackservice_title(self, filename, artist, title): """ Updates the track-service entry with the info from a fallback track/playlist. """ # FIXME scheduled_entry = self.get_active_entry() entry = SingleEntry() meta = SingleEntryMetaData() # Validate artist and title if not title: title = self.config.get("fallback_title_not_available") # Create Entry entry.filename = filename entry.duration = self.fallback_manager.get_track_duration(filename) if not entry.duration: self.logger.critical("Entry %s has no duration! This may cause malfunction of some engine services." % (str(entry))) # Create track service log for local station fallback (type=4) trackservice = TrackService(entry, 4) trackservice.store(add=True, commit=True) entry.store(add=True, commit=True) # Create Meta meta.artist = artist meta.album = "" meta.title = title meta.single_entry_id = entry.id meta.store(add=True, commit=True) # Reference each other entry.meta_data_id = meta.id entry.trackservice_id = trackservice.id entry.store(add=False, commit=True) msg = "Track Service active track '%s' updated with fallback source '%s - %s'!" % (scheduled_entry, artist, title) self.logger.info(msg) return msg # # PRIVATE METHODS # def get_active_playlist(self): """ Retrieves the schedule and playlist currently to be played as per schedule. If the current point in time has no playlist assigned, only the matching schedule is returned. Returns: (Schedule, Playlist): The current schedule and playlist tuple. """ now_unix = time.mktime(datetime.datetime.now().timetuple()) current_schedule = None current_playlist = None # Iterate over all shows and playlists and find the one to be played right now if self.programme: for schedule in self.programme: if schedule.start_unix < now_unix < schedule.end_unix: current_schedule = schedule for playlist in schedule.playlist: if playlist.start_unix < now_unix < playlist.end_unix: current_playlist = playlist break break return (current_schedule, current_playlist) def get_next_playlists(self): """ Retrieves the playlists to be played after the current one. Returns: ([Playlist]): The next playlists """ now_unix = time.mktime(datetime.datetime.now().timetuple()) next_playlists = [] for schedule in self.programme: if schedule.end_unix > now_unix: for playlist in schedule.playlist: if playlist.start_unix > now_unix: next_playlists.append(playlist) return next_playlists def get_next_entry(self): """ Retrieves the playlist entry to be played next. Returns: (Playlist): The next playlist track """ next_entry = None current_schedule, current_playlist = self.get_active_playlist() if not self.active_entry: self.logger.warn("For some reason there is no active playlist entry set... Fetching it now!") self.get_active_entry() if not self.active_entry: self.logger.warn("Looks like nothing is currently scheduled...") return None # Check if there is a next entry in the current playlist for i, entry in enumerate(self.active_entry.playlist.entries): if entry is self.active_entry: if i+1 < len(self.active_entry.playlist.entries): next_entry = self.active_entry.playlist.entries[i+1] break # It might be in the next playlist... if not next_entry: next_playlist = None found_current = False # Iterate over all schedule and playlists and find the one to be played next for schedule in self.programme: for playlist in schedule.playlist: if playlist is current_playlist: found_current = True elif found_current: next_playlist = playlist break if next_playlist: next_entry = next_playlist.entries[0] if not next_entry: self.logger.fatal("There is no next playlist-entry in the programme!") return next_entry def queue_programme(self): """ Queues the current programme (playlists as per schedule) by creating timed commands to Liquidsoap to enable the individual tracks of playlists. """ active_schedule, active_playlist = self.get_active_playlist() playlists = self.get_next_playlists() s = "\n\n PLAYING NOW:" s += "\n┌──────────────────────────────────────────────────────────────────────────────────────────────────────" if active_schedule: s += "\n│ Playing schedule %s " % active_schedule if active_playlist: s += "\n│ └── Playlist %s " % active_playlist active_entry = active_playlist.current_entry # Finished entries for entry in active_playlist.entries: if active_entry == entry: break else: s += "\n│ └── Entry %s " % SimpleUtil.strike(str(entry)) # Entry currently being played if active_entry: s += "\n│ └── Entry %s " % (TerminalColors.GREEN.value+"PLAYING > "+str(active_entry)+TerminalColors.ENDC.value) # Open entries for current playlist rest_of_playlist = active_entry.get_next_entries() s += self.queue_playlist_entries(rest_of_playlist) else: s += "\n│ └── %s No Playlist active. Did it finish before the end of the schedule? %s" % (TerminalColors.ORANGE.value, TerminalColors.ENDC.value) else: s += "\n│ Nothing. " s += "\n└──────────────────────────────────────────────────────────────────────────────────────────────────────" s += "\n PLAYING NEXT:" s += "\n┌──────────────────────────────────────────────────────────────────────────────────────────────────────" if not playlists: s += "\n│ Nothing. " else: for next_playlist in playlists: s += "\n│ Queued schedule %s " % next_playlist.schedule s += "\n│ └── Playlist %s " % next_playlist if next_playlist.end_unix > next_playlist.schedule.end_unix: s += "\n│ %s ↑↑↑ Playlist #%s ends after Schedule #%s!%s " % (TerminalColors.RED.value, next_playlist.playlist_id, next_playlist.schedule.schedule_id, TerminalColors.ENDC.value) s += self.queue_playlist_entries(next_playlist.entries) s += "\n└──────────────────────────────────────────────────────────────────────────────────────────────────────\n\n" self.logger.info(s) def queue_playlist_entries(self, entries): """ Creates Liquidsoap player commands for all playlist items to be executed at the scheduled time. Args: entries([PlaylistEntry]): The playlist entries to be scheduled for playout Returns: (String): Formatted string to display playlist entries in log """ msg = "" for entry in entries: # Function to be called by timer def func(entry): self.logger.info("=== Executing timed LQS command: activate('%s') ===" % entry) self.liquidsoapcommunicator.activate(entry) planned_timer = self.is_something_planned_at_time(entry.start_unix) now_unix = SimpleUtil.timestamp() diff = entry.start_unix - now_unix msg += "\n│ └── Entry %s " % entry if planned_timer: # Check if the playlist_id's are different if planned_timer.entry.entry_id != entry.entry_id: # If not, stop and remove the old timer, create a new one self.stop_timer(planned_timer) entry.switchtimer = self.create_timer(diff, func, [entry], switcher=True) else: # If the playlists do not differ => reuse the old timer and do nothing self.logger.info("Playlist Entry %s is already scheduled - No new timer created!" % entry) else: # If nothing is planned at given time, create a new timer entry.switchtimer = self.create_timer(diff, func, [entry], switcher=True) return msg def fetch_new_programme(self): """ Fetch the latest programme from `AuraCalendarService` which stores it to the database. After that, the programme is in turn loaded from the database and stored in `self.programme`. """ # Fetch programme from API endpoints self.logger.info("Trying to fetch new programe from API endpoints...") acs = AuraCalendarService(self.config) queue = acs.get_queue() acs.start() # start fetching thread response = queue.get() # wait for the end self.logger.info("... Programme fetch via API done!") # Reset last successful fetch state lsf = self.last_successful_fetch self.last_successful_fetch = None if response is None: self.logger.warning("Trying to load programme from Engine Database, because AuraCalendarService returned an empty response.") elif type(response) is list: self.programme = response if self.programme is not None and len(self.programme) > 0: self.last_successful_fetch = datetime.datetime.now() self.logger.info("+++ Successfully fetched current programme from API +++") if len(self.programme) == 0: self.logger.critical("Programme fetched from Steering/Tank has no entries!") elif response.startswith("fetching_aborted"): self.logger.warning("Trying to load programme from database, because fetching was being aborted from AuraCalendarService! Reason: " + response[16:]) else: self.logger.warning("Trying to load programme from database, because i got an unknown response from AuraCalendarService: " + response) # Always load latest programme from the database self.last_successful_fetch = lsf self.load_programme_from_db() self.logger.info("Finished loading current programme from database (%s schedules)" % str(len(self.programme))) for schedule in self.programme: self.logger.debug("\tSchedule %s with Playlist %s" % (str(schedule), str(schedule.playlist))) def load_programme_from_db(self): """ Loads the programme from Engine's database and enables them via `self.enable_entries(..)`. After that, the current message queue is printed to the console. """ self.programme = Schedule.select_act_programme() if not self.programme: self.logger.critical("Could not load programme from database. We are in big trouble my friend!") return # FIXME Still needed? def enable_entries(self, playlist): """ Iterates over all playlist entries and assigs their start time. Additionally timers for fadings are created. Args: playlist(Playlist): The playlist to be scheduled for playout """ now_unix = time.mktime(datetime.datetime.now().timetuple()) time_marker = playlist.start_unix # Old entry for fading out # FIXME retrieve active entry from previous playlist old_entry = None for entry in playlist.entries: diff=3 entry.start_unix = time_marker self.enable_timer(diff, entry, old_entry) old_entry = entry # time_marker += 1 # FIXME ??? # # Since we also get entries from the past, filter these out # if time_marker > now_unix: # # when do we have to start? # diff = time_marker - now_unix # diff = 3 # FIXME test # entry.start_unix = time_marker # # enable the three timer # self.enable_timer(diff, entry, old_entry) # old_entry = entry # ------------------------------------------------------------------------------------------ # def enable_timer(self, diff, entry, old_entry): """ Create threads to send track-activation messages to LiquidSoap. Those tracks can be delayed by `diff` seconds. Args: diff (Integer): seconds after tracks should be activated """ self.logger.critical("ENABLING SWITCHTIMER FOR " + str(entry)) entry.switchtimer = self.add_or_update_timer(diff, self.liquidsoapcommunicator.activate, [entry]) # FIXME Fade In/Out logic: Not sure if that's functional #self.enable_fading(diff, entry, old_entry) # ------------------------------------------------------------------------------------------ # def enable_fading(self, diff, new_entry, old_entry): # fading times fade_out_time = float(self.config.get("fade_out_time")) # enable fading when entry types are different if old_entry is not None: if old_entry.type != new_entry.type: #self.add_or_update_timer(diff, self.liquidsoapcommunicator.fade_out, [old_entry]) old_entry.fadeouttimer = self.create_timer(diff-fade_out_time, self.liquidsoapcommunicator.fade_out, [old_entry], fadeout=True) self.logger.critical("ENABLING FADEOUTTIMER FOR " + str(old_entry)) # same for fadein except old_entry can be None else: #self.add_or_update_timer(diff, self.liquidsoapcommunicator.fade_in, [new_entry]) new_entry.fadeintimer = self.create_timer(diff, self.liquidsoapcommunicator.fade_in, [new_entry], fadein=True) self.logger.critical("ENABLING FADEINTIMER FOR " + str(new_entry)) # ------------------------------------------------------------------------------------------ # def add_or_update_timer(self, diff, func, parameters): timer = None entry = parameters[0] planned_timer = self.is_something_planned_at_time(entry.start_unix) # if something is planned on entry.entry_start #FIXME #if 1==0: if planned_timer: planned_entry = planned_timer.entry # check if the playlist_id's are different if planned_entry.playlist.playlist_id != entry.playlist.playlist_id: # if not stop the old timer and remove it from the list self.stop_timer(planned_timer) # and create a new one timer = self.create_timer(diff, func, parameters, switcher=True) # if the playlist id's do not differ => reuse the old timer and do nothing, they are the same # if nothing is planned at given time, create a new timer else: timer = self.create_timer(diff, func, parameters, switcher=True) if timer is None: return planned_timer return timer # ------------------------------------------------------------------------------------------ # def stop_timer(self, timer): # stop timer timer.cancel() if timer.entry.fadeintimer is not None: timer.entry.fadeintimer.cancel() self.message_timer.remove(timer.entry.fadeintimer) if timer.entry.fadeouttimer is not None: timer.entry.fadeouttimer.cancel() self.message_timer.remove(timer.entry.fadeouttimer) # and remove it from message queue self.message_timer.remove(timer) self.logger.critical("REMOVED TIMER for " + str(timer.entry)) # ------------------------------------------------------------------------------------------ # def create_timer(self, diff, func, parameters, fadein=False, fadeout=False, switcher=False): if not fadein and not fadeout and not switcher or fadein and fadeout or fadein and switcher or fadeout and switcher: raise Exception("You have to call me with either fadein=true, fadeout=true or switcher=True") t = CallFunctionTimer(diff, func, parameters, fadein, fadeout, switcher) self.message_timer.append(t) t.start() return t # ------------------------------------------------------------------------------------------ # def is_something_planned_at_time(self, given_time): for t in self.message_timer: if t.entry.start_unix == given_time: return t return False def init_error_messages(self): """ Load error messages """ error_file = self.config.get("install_dir") + "/errormessages/scheduler_error.js" f = open(error_file) self.error_data = json.load(f) f.close() def init_database(self): """ Initializes the database. Raises: sqlalchemy.exc.ProgrammingError: In case the DB model is invalid """ if self.config.get("recreate_db") is not None: AuraDatabaseModel.recreate_db(systemexit=True) # Check if tables exists, if not create them try: Playlist.select_all() except sqlalchemy.exc.ProgrammingError as e: errcode = e.orig.args[0] if errcode == 1146: # Error for no such table x = AuraDatabaseModel() x.recreate_db() else: raise def stop(self): """ Called when thread is stopped. """ self.exit_event.set() # ------------------------------------------------------------------------------------------ # # class SetNextFile(threading.Thread): # fallbackname = None # show = None # def __init__(self, fallbackname, show): # threading.Thread.__init__(self) # self.fallbackname = fallbackname # self.show = show # def run(self): # if self.fallbackname == "show": # self.detect_next_file_for(self.show.showfallback) # elif self.fallbackname == "timeslow": # self.detect_next_file_for(self.show.timeslotfallback) # elif self.fallbackname == "station": # self.detect_next_file_for(self.show.stationfallback) # def detect_next_file_for(self, playlist): # return "" # #if playlist.startswith("pool"): # # self.find_next_file_in_pool(playlist) # #def find_next_file_in_pool(self, pool): # # return "" # ------------------------------------------------------------------------------------------ # class CallFunctionTimer(threading.Timer): logger = None param = None entry = None diff = None fadein = False fadeout = False switcher = False def __init__(self, diff, func, param, fadein=False, fadeout=False, switcher=False): self.logger = logging.getLogger("AuraEngine") self.logger.debug("CallFunctionTimer: Executing LiquidSoap command '%s' in %s seconds..." % (str(func.__name__), str(diff))) threading.Timer.__init__(self, diff, func, param) # TODO Review usage of the fading-attributes: if not fadein and not fadeout and not switcher or fadein and fadeout or fadein and switcher or fadeout and switcher: raise Exception("You have to create me with either fadein=true, fadeout=true or switcher=True") self.diff = diff self.func = func self.param = param self.entry = param[0] self.fadein = fadein self.fadeout = fadeout self.switcher = switcher # ------------------------------------------------------------------------------------------ # def __str__(self): if self.fadein: return "CallFunctionTimer starting in " + str(self.diff) + "s fading in source '" + str(self.entry) elif self.fadeout: return "CallFunctionTimer starting in " + str(self.diff) + "s fading out source '" + str(self.entry) elif self.switcher: return "CallFunctionTimer starting in " + str(self.diff) + "s switching to source '" + str(self.entry) else: return "CORRUPTED CallFunctionTimer around! How can that be?"